Eliminate elog()'s hardwired limit on length of an error message.

This change seems necessary in conjunction with long queries, and it
cleans up some bogosity in connection with long EXPLAIN texts anyway.
Note that current libpq will accept any length error message (at least
until it runs out of memory); prior versions have a limit of 8K, but
will cleanly discard excess error text, so there shouldn't be any
big compatibility problems with old clients.

src/backend/commands/explain.c

@@ -4,7 +4,7 @@
  *
  * Copyright (c) 1994-5, Regents of the University of California
  *
- *	  $Id: explain.c,v 1.46 1999/08/31 01:28:28 tgl Exp $
+ *	  $Id: explain.c,v 1.47 1999/09/11 19:06:36 tgl Exp $
  *
  */
 
@@ -28,7 +28,6 @@ typedef struct ExplainState
 } ExplainState;
 
 static char *Explain_PlanToString(Plan *plan, ExplainState *es);
-static void printLongNotice(const char *header, const char *message);
 static void ExplainOneQuery(Query *query, bool verbose, CommandDest dest);
 
 /* Convert a null string pointer into "<>" */
@@ -110,7 +109,7 @@ ExplainOneQuery(Query *query, bool verbose, CommandDest dest)
 		s = nodeToString(plan);
 		if (s)
 		{
-			printLongNotice("QUERY DUMP:\n\n", s);
+			elog(NOTICE, "QUERY DUMP:\n\n%s", s);
 			pfree(s);
 		}
 	}
@@ -120,7 +119,7 @@ ExplainOneQuery(Query *query, bool verbose, CommandDest dest)
 		s = Explain_PlanToString(plan, es);
 		if (s)
 		{
-			printLongNotice("QUERY PLAN:\n\n", s);
+			elog(NOTICE, "QUERY PLAN:\n\n%s", s);
 			pfree(s);
 		}
 	}
@@ -332,7 +331,6 @@ explain_outNode(StringInfo str, Plan *plan, int indent, ExplainState *es)
 		}
 		es->rtable = saved_rtable;
 	}
-	return;
 }
 
 static char *
@@ -346,22 +344,3 @@ Explain_PlanToString(Plan *plan, ExplainState *es)
 		explain_outNode(&str, plan, 0, es);
 	return str.data;
 }
-
-/*
- * Print a message that might exceed the size of the elog message buffer.
- * This is a crock ... there shouldn't be an upper limit to what you can elog().
- */
-static void
-printLongNotice(const char *header, const char *message)
-{
-	int			len = strlen(message);
-
-	elog(NOTICE, "%.20s%.*s", header, ELOG_MAXLEN - 64, message);
-	len -= ELOG_MAXLEN - 64;
-	while (len > 0)
-	{
-		message += ELOG_MAXLEN - 64;
-		elog(NOTICE, "%.*s", ELOG_MAXLEN - 64, message);
-		len -= ELOG_MAXLEN - 64;
-	}
-}

src/backend/utils/error/elog.c

@@ -7,10 +7,13 @@
  *
  *
  * IDENTIFICATION
- *	  $Header: /cvsroot/pgsql/src/backend/utils/error/elog.c,v 1.47 1999/07/17 20:18:03 momjian Exp $
+ *	  $Header: /cvsroot/pgsql/src/backend/utils/error/elog.c,v 1.48 1999/09/11 19:06:31 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
+
+#include "postgres.h"
+
 #include <time.h>
 #include <fcntl.h>
 #ifndef O_RDONLY
@@ -20,8 +23,6 @@
 #include <errno.h>
 #include <unistd.h>
 #include <signal.h>
-
-#include "postgres.h"
 #ifdef USE_SYSLOG
 #include <syslog.h>
 #endif
@@ -33,6 +34,10 @@
 #include "tcop/tcopprot.h"
 #include "utils/trace.h"
 
+extern int	errno;
+extern int	sys_nerr;
+
+
 #ifdef USE_SYSLOG
 /*
  * Global option to control the use of syslog(3) for logging:
@@ -51,84 +56,198 @@ static int	Debugfile = -1;
 static int	Err_file = -1;
 static int	ElogDebugIndentLevel = 0;
 
-/*
+/*--------------------
  * elog
- *		Old error logging function.
+ *		Primary error logging function.
+ *
+ * 'lev': error level; indicates recovery action to take, if any.
+ * 'fmt': a printf-style string.
+ * Additional arguments, if any, are formatted per %-escapes in 'fmt'.
+ *
+ * In addition to the usual %-escapes recognized by printf, "%m" in
+ * fmt is replaced by the error message for the current value of errno.
+ *
+ * Note: no newline is needed at the end of the fmt string, since
+ * elog will provide one for the output methods that need it.
+ *
+ * If 'lev' is ERROR or worse, control does not return to the caller.
+ * See elog.h for the error level definitions.
+ *--------------------
  */
 void
-elog(int lev, const char *fmt,...)
+elog(int lev, const char *fmt, ...)
 {
 	va_list		ap;
-	char		buf[ELOG_MAXLEN],
-				line[ELOG_MAXLEN];
-	char	   *bp;
+	/*
+	 * The expanded format and final output message are dynamically
+	 * allocated if necessary, but not if they fit in the "reasonable
+	 * size" buffers shown here.  In extremis, we'd rather depend on
+	 * having a few hundred bytes of stack space than on malloc() still
+	 * working (since memory-clobber errors often take out malloc first).
+	 * Don't make these buffers unreasonably large though, on pain of
+	 * having to chase a bug with no error message.
+	 */
+	char		fmt_fixedbuf[128];
+	char		msg_fixedbuf[256];
+	char	   *fmt_buf = fmt_fixedbuf;
+	char	   *msg_buf = msg_fixedbuf;
+	/* this buffer is only used if errno has a bogus value: */
+	char		errorstr_buf[32];
+	const char *errorstr;
+	const char *prefix;
 	const char *cp;
-	extern int	errno,
-				sys_nerr;
-
+	char	   *bp;
+	int			indent = 0;
+	int			space_needed;
 #ifdef USE_SYSLOG
 	int			log_level;
-
 #endif
-
 	int			len;
-	int			i = 0;
 
-	va_start(ap, fmt);
-	if (lev == DEBUG && Debugfile < 0)
-		return;
+	if (lev <= DEBUG && Debugfile < 0)
+		return;					/* ignore debug msgs if noplace to send */
+
+	/* choose message prefix and indent level */
 	switch (lev)
 	{
 		case NOIND:
-			i = ElogDebugIndentLevel - 1;
-			if (i < 0)
-				i = 0;
-			if (i > 30)
-				i = i % 30;
-			cp = "DEBUG:  ";
+			indent = ElogDebugIndentLevel - 1;
+			if (indent < 0)
+				indent = 0;
+			if (indent > 30)
+				indent = indent % 30;
+			prefix = "DEBUG:  ";
 			break;
 		case DEBUG:
-			i = ElogDebugIndentLevel;
-			if (i < 0)
-				i = 0;
-			if (i > 30)
-				i = i % 30;
-			cp = "DEBUG:  ";
+			indent = ElogDebugIndentLevel;
+			if (indent < 0)
+				indent = 0;
+			if (indent > 30)
+				indent = indent % 30;
+			prefix = "DEBUG:  ";
 			break;
 		case NOTICE:
-			cp = "NOTICE:  ";
+			prefix = "NOTICE:  ";
 			break;
 		case ERROR:
-			cp = "ERROR:  ";
+			prefix = "ERROR:  ";
 			break;
 		default:
-			sprintf(line, "FATAL %d:  ", lev);
-			cp = line;
+			/* temporarily use msg buf for prefix */
+			sprintf(msg_fixedbuf, "FATAL %d:  ", lev);
+			prefix = msg_fixedbuf;
+			break;
+	}
+
+	/* get errno string for %m */
+	if (errno < sys_nerr && errno >= 0)
+		errorstr = strerror(errno);
+	else
+	{
+		sprintf(errorstr_buf, "error %d", errno);
+		errorstr = errorstr_buf;
+	}
+
+	/*
+	 * Set up the expanded format, consisting of the prefix string
+	 * plus input format, with any %m replaced by strerror() string
+	 * (since vsnprintf won't know what to do with %m).  To keep
+	 * space calculation simple, we only allow one %m.
+	 */
+	space_needed = TIMESTAMP_SIZE + strlen(prefix) + indent 
+		+ strlen(fmt) + strlen(errorstr) + 1;
+	if (space_needed > (int) sizeof(fmt_fixedbuf))
+	{
+		fmt_buf = (char *) malloc(space_needed);
+		if (fmt_buf == NULL)
+		{
+			/* We're up against it, convert to fatal out-of-memory error */
+			fmt_buf = fmt_fixedbuf;
+			lev = REALLYFATAL;
+			fmt = "elog: out of memory"; /* this must fit in fmt_fixedbuf! */
+		}
 	}
 #ifdef ELOG_TIMESTAMPS
-	strcpy(buf, tprintf_timestamp());
-	strcat(buf, cp);
+	strcpy(fmt_buf, tprintf_timestamp());
+	strcat(fmt_buf, prefix);
 #else
-	strcpy(buf, cp);
+	strcpy(fmt_buf, prefix);
 #endif
-	bp = buf + strlen(buf);
-	while (i-- > 0)
+	bp = fmt_buf + strlen(fmt_buf);
+	while (indent-- > 0)
 		*bp++ = ' ';
 	for (cp = fmt; *cp; cp++)
-		if (*cp == '%' && *(cp + 1) == 'm')
+	{
+		if (cp[0] == '%' && cp[1] != '\0')
 		{
-			if (errno < sys_nerr && errno >= 0)
-				strcpy(bp, strerror(errno));
+			if (cp[1] == 'm')
+			{
+				/* XXX If there are any %'s in errorstr then vsnprintf
+				 * will do the Wrong Thing; do we need to cope?
+				 * Seems unlikely that % would appear in system errors.
+				 */
+				strcpy(bp, errorstr);
+				/* copy the rest of fmt literally, since we can't
+				 * afford to insert another %m.
+				 */
+				strcat(bp, cp+2);
+				bp += strlen(bp);
+				break;
+			}
 			else
-				sprintf(bp, "error %d", errno);
-			bp += strlen(bp);
-			cp++;
+			{
+				/* copy % and next char --- this avoids trouble with %%m */
+				*bp++ = *cp++;
+				*bp++ = *cp;
+			}
 		}
 		else
 			*bp++ = *cp;
+	}
 	*bp = '\0';
-	vsnprintf(line, ELOG_MAXLEN - 1, buf, ap);
-	va_end(ap);
+
+	/*
+	 * Now generate the actual output text using vsnprintf().
+	 * Be sure to leave space for \n added later as well as trailing null.
+	 */
+	space_needed = sizeof(msg_fixedbuf);
+	for (;;)
+	{
+		int nprinted;
+
+		va_start(ap, fmt);
+		nprinted = vsnprintf(msg_buf, space_needed - 2, fmt_buf, ap);
+		va_end(ap);
+		/*
+		 * Note: some versions of vsnprintf return the number of chars
+		 * actually stored, but at least one returns -1 on failure.
+		 * Be conservative about believing whether the print worked.
+		 */
+		if (nprinted >= 0 && nprinted < space_needed - 3)
+			break;
+		/* It didn't work, try to get a bigger buffer */
+		if (msg_buf != msg_fixedbuf)
+			free(msg_buf);
+		space_needed *= 2;
+		msg_buf = (char *) malloc(space_needed);
+		if (msg_buf == NULL)
+		{
+			/* We're up against it, convert to fatal out-of-memory error */
+            msg_buf = msg_fixedbuf;
+            lev = REALLYFATAL;
+#ifdef ELOG_TIMESTAMPS
+			strcpy(msg_buf, tprintf_timestamp());
+			strcat(msg_buf, "FATAL:  elog: out of memory");
+#else
+			strcpy(msg_buf, "FATAL:  elog: out of memory");
+#endif
+			break;
+		}
+	}
+
+	/*
+	 * Message prepared; send it where it should go
+	 */
 
 #ifdef USE_SYSLOG
 	switch (lev)
@@ -150,14 +269,16 @@ elog(int lev, const char *fmt,...)
 			log_level = LOG_ERR;
 			break;
 	}
-	write_syslog(log_level, line + TIMESTAMP_SIZE);
+	write_syslog(log_level, msg_buf + TIMESTAMP_SIZE);
 #endif
 
-	len = strlen(strcat(line, "\n"));
-	if ((Debugfile > -1) && (UseSyslog <= 1))
-		write(Debugfile, line, len);
-	if (lev == DEBUG || lev == NOIND)
-		return;
+	/* syslog doesn't want a trailing newline, but other destinations do */
+	strcat(msg_buf, "\n");
+
+	len = strlen(msg_buf);
+
+	if (Debugfile >= 0 && UseSyslog <= 1)
+		write(Debugfile, msg_buf, len);
 
 	/*
 	 * If there's an error log file other than our channel to the
@@ -167,33 +288,31 @@ elog(int lev, const char *fmt,...)
 	 * then writing here can cause this backend to exit without warning
 	 * that is, write() does an exit(). In this case, our only hope of
 	 * finding out what's going on is if Err_file was set to some disk
-	 * log.  This is a major pain.
+	 * log.  This is a major pain.  (It's probably also long-dead code...
+	 * does anyone still use ultrix?)
 	 */
-
-	if (Err_file > -1 && Debugfile != Err_file && (UseSyslog <= 1))
+	if (lev > DEBUG && Err_file >= 0 &&
+		Debugfile != Err_file && UseSyslog <= 1)
 	{
-		if (write(Err_file, line, len) < 0)
+		if (write(Err_file, msg_buf, len) < 0)
 		{
-			write(open("/dev/console", O_WRONLY, 0666), line, len);
-			fflush(stdout);
-			fflush(stderr);
-			proc_exit(lev);
+			write(open("/dev/console", O_WRONLY, 0666), msg_buf, len);
+			lev = REALLYFATAL;
 		}
 		fsync(Err_file);
 	}
 
 #ifndef PG_STANDALONE
-	/* Send IPC message to the front-end program */
-	if (IsUnderPostmaster && lev > DEBUG)
+
+	if (lev > DEBUG && IsUnderPostmaster)
 	{
-		/* notices are not errors, handle 'em differently */
+		/* Send IPC message to the front-end program */
 		char		msgtype;
 
 		if (lev == NOTICE)
 			msgtype = 'N';
 		else
 		{
-
 			/*
 			 * Abort any COPY OUT in progress when an error is detected.
 			 * This hack is necessary because of poor design of copy
@@ -203,7 +322,7 @@ elog(int lev, const char *fmt,...)
 			msgtype = 'E';
 		}
 		/* exclude the timestamp from msg sent to frontend */
-		pq_puttextmessage(msgtype, line + TIMESTAMP_SIZE);
+		pq_puttextmessage(msgtype, msg_buf + TIMESTAMP_SIZE);
 
 		/*
 		 * This flush is normally not necessary, since postgres.c will
@@ -211,35 +330,45 @@ elog(int lev, const char *fmt,...)
 		 * But it seems best to leave it here, so that the client has some
 		 * clue what happened if the backend dies before getting back to
 		 * the main loop ... error/notice messages should not be a
-		 * performance- critical path anyway, so an extra flush won't hurt
+		 * performance-critical path anyway, so an extra flush won't hurt
 		 * much ...
 		 */
 		pq_flush();
 	}
-	if (!IsUnderPostmaster)
-	{
 
-		/*
-		 * There is no socket.	One explanation for this is we are running
-		 * as the Postmaster.  So we'll write the message to stderr.
+	if (lev > DEBUG && ! IsUnderPostmaster)
+	{
+		/* We are running as an interactive backend, so just send
+		 * the message to stderr.
 		 */
-		fputs(line, stderr);
+		fputs(msg_buf, stderr);
 	}
+
 #endif	 /* !PG_STANDALONE */
 
+	/* done with the message, release space */
+	if (fmt_buf != fmt_fixedbuf)
+		free(fmt_buf);
+	if (msg_buf != msg_fixedbuf)
+		free(msg_buf);
+
+	/*
+	 * Perform error recovery action as specified by lev.
+	 */
 	if (lev == ERROR)
 	{
-		ProcReleaseSpins(NULL); /* get rid of spinlocks we hold */
-		if (!InError)
+		if (InError)
 		{
-			/* exit to main loop */
-			siglongjmp(Warn_restart, 1);
+			/* error reported during error recovery; don't loop forever */
+			elog(REALLYFATAL, "elog: error during error recovery, giving up!");
 		}
+		/* exit to main loop */
+		ProcReleaseSpins(NULL); /* get rid of spinlocks we hold */
+		siglongjmp(Warn_restart, 1);
 	}
 
 	if (lev == FATAL)
 	{
-
 		/*
 		 * Assume that if we have detected the failure we can exit with a
 		 * normal exit status.	This will prevent the postmaster from
@@ -254,13 +383,20 @@ elog(int lev, const char *fmt,...)
 
 	if (lev > FATAL)
 	{
+		/*
+		 * Serious crash time.  Postmaster will observe nonzero
+		 * process exit status and kill the other backends too.
+		 */
 		fflush(stdout);
 		fflush(stderr);
 		proc_exit(lev);
 	}
+
+	/* We reach here if lev <= NOTICE.  OK to return to caller. */
 }
 
 #ifndef PG_STANDALONE
+
 int
 DebugFileOpen(void)
 {

src/backend/utils/misc/trace.c

@@ -2,22 +2,21 @@
  *
  * trace.c
  *
- *	  Conditional trace ans logging functions.
+ *	  Conditional trace and logging functions.
  *
  *	  Massimo Dal Zotto <dz@cs.unitn.it>
  *
  *-------------------------------------------------------------------------
  */
 
+#include "postgres.h"
+
 #include <unistd.h>
 #include <signal.h>
 #include <sys/time.h>
 #include <sys/types.h>
 #include <sys/stat.h>
 #include <fcntl.h>
-
-#include "postgres.h"
-
 #ifdef USE_SYSLOG
 #include <syslog.h>
 #endif
@@ -25,6 +24,13 @@
 #include "miscadmin.h"
 #include "utils/trace.h"
 
+/*
+ * We could support trace messages of indefinite length, as elog() does,
+ * but it's probably not worth the trouble.  Instead limit trace message
+ * length to this.
+ */
+#define TRACEMSG_MAXLEN		1024
+
 #ifdef USE_SYSLOG
 /*
  * Global option to control the use of syslog(3) for logging:
@@ -87,15 +93,14 @@ int
 tprintf(int flag, const char *fmt,...)
 {
 	va_list		ap;
-	char		line[ELOG_MAXLEN + TIMESTAMP_SIZE + 1];
-
+	char		line[TRACEMSG_MAXLEN + TIMESTAMP_SIZE + 1];
 #ifdef USE_SYSLOG
 	int			log_level;
 #endif
 
 	if ((flag == TRACE_ALL) || (pg_options[TRACE_ALL] > 0))
 	{
-		/* uconditional trace or trace all option set */
+		/* unconditional trace or trace all option set */
 	}
 	else if (pg_options[TRACE_ALL] == 0)
 	{
@@ -105,11 +110,11 @@ tprintf(int flag, const char *fmt,...)
 	else if (pg_options[TRACE_ALL] < 0)
 		return 0;
 
-	va_start(ap, fmt);
 #ifdef ELOG_TIMESTAMPS
 	strcpy(line, tprintf_timestamp());
 #endif
-	vsnprintf(line + TIMESTAMP_SIZE, ELOG_MAXLEN, fmt, ap);
+	va_start(ap, fmt);
+	vsnprintf(line + TIMESTAMP_SIZE, TRACEMSG_MAXLEN, fmt, ap);
 	va_end(ap);
 
 #ifdef USE_SYSLOG
@@ -134,13 +139,13 @@ int
 tprintf1(const char *fmt,...)
 {
 	va_list		ap;
-	char		line[ELOG_MAXLEN + TIMESTAMP_SIZE + 1];
+	char		line[TRACEMSG_MAXLEN + TIMESTAMP_SIZE + 1];
 
-	va_start(ap, fmt);
 #ifdef ELOG_TIMESTAMPS
 	strcpy(line, tprintf_timestamp());
 #endif
-	vsnprintf(line + TIMESTAMP_SIZE, ELOG_MAXLEN, fmt, ap);
+	va_start(ap, fmt);
+	vsnprintf(line + TIMESTAMP_SIZE, TRACEMSG_MAXLEN, fmt, ap);
 	va_end(ap);
 
 #ifdef USE_SYSLOG
@@ -164,13 +169,13 @@ int
 eprintf(const char *fmt,...)
 {
 	va_list		ap;
-	char		line[ELOG_MAXLEN + TIMESTAMP_SIZE + 1];
+	char		line[TRACEMSG_MAXLEN + TIMESTAMP_SIZE + 1];
 
-	va_start(ap, fmt);
 #ifdef ELOG_TIMESTAMPS
 	strcpy(line, tprintf_timestamp());
 #endif
-	vsnprintf(line + TIMESTAMP_SIZE, ELOG_MAXLEN, fmt, ap);
+	va_start(ap, fmt);
+	vsnprintf(line + TIMESTAMP_SIZE, TRACEMSG_MAXLEN, fmt, ap);
 	va_end(ap);
 
 #ifdef USE_SYSLOG

src/include/utils/elog.h

@@ -6,7 +6,7 @@
  *
  * Copyright (c) 1994, Regents of the University of California
  *
- * $Id: elog.h,v 1.11 1999/07/13 21:17:42 momjian Exp $
+ * $Id: elog.h,v 1.12 1999/09/11 19:06:25 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -14,36 +14,16 @@
 #define ELOG_H
 
 #define NOTICE	0				/* random info - no special action */
-#define ERROR	-1				/* user error - return to known state */
-#define FATAL	1				/* Fatal error - abort process */
-#define DEBUG	-2				/* debug message */
-#define NOIND	-3				/* debug message, don't indent as far */
-
-#ifdef NOT_USED
-#define PTIME	0x100			/* prepend time to message */
-#define POS		0x200			/* prepend source position to message */
-#define USERMSG 0x400			/* send message to user */
-#define TERM	0x800			/* send message to terminal */
-#define DBLOG	0x1000			/* put message in per db log */
-#define SLOG	0x2000			/* put message in system log */
-#define ABORTX	0x4000			/* abort process after logging */
-#endif
-
-/* Increase this to be able to use postmaster -d 3 with complex
- * view definitions (which are transformed to very, very large INSERT statements
- * and if -d 3 is used the query string of these statements is printed using
- * vsprintf which expects enough memory reserved! */
-#define ELOG_MAXLEN 12288
+#define ERROR	(-1)			/* user error - return to known state */
+#define FATAL	1				/* fatal error - abort process */
+#define REALLYFATAL	2			/* take down the other backends with me */
+#define DEBUG	(-2)			/* debug message */
+#define NOIND	(-3)			/* debug message, don't indent as far */
 
-
-/* uncomment the following if you want your elog's to be timestamped */
-/* #define ELOG_TIMESTAMPS */
-
-extern void elog(int lev, const char *fmt,...);
+extern void elog(int lev, const char *fmt, ...);
 
 #ifndef PG_STANDALONE
-int			DebugFileOpen(void);
-
+extern int	DebugFileOpen(void);
 #endif
 
 #endif	 /* ELOG_H */