Code review for log_line_prefix patch. Cooperate with StringInfo instead

of fighting it, avoid hard-wired (and wrong) assumption about max length
of prefix, cause %l to actually work as documented, don't compute data
we may not need.

src/backend/utils/error/elog.c

@@ -37,7 +37,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.128 2004/03/15 15:56:23 momjian Exp $
+ *	  $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.129 2004/03/19 02:23:59 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -69,7 +69,7 @@ ErrorContextCallback *error_context_stack = NULL;
 
 /* GUC parameters */
 PGErrorVerbosity Log_error_verbosity = PGERROR_VERBOSE;
-char       *Log_line_prefix = ""; /* format for extra log line info */
+char       *Log_line_prefix = NULL; /* format for extra log line info */
 
 #ifdef HAVE_SYSLOG
 /*
@@ -136,13 +136,14 @@ static int	recursion_depth = 0;	/* to detect actual recursion */
 	} while (0)
 
 
+static void log_line_prefix(StringInfo buf);
 static void send_message_to_server_log(ErrorData *edata);
 static void send_message_to_frontend(ErrorData *edata);
 static char *expand_fmt_string(const char *fmt, ErrorData *edata);
 static const char *useful_strerror(int errnum);
 static const char *error_severity(int elevel);
 static void append_with_tabs(StringInfo buf, const char *str);
-static const char *log_line_prefix(void);
+
 
 /*
  * errstart --- begin an error-reporting cycle
@@ -1019,136 +1020,140 @@ write_syslog(int level, const char *line)
 #endif   /* HAVE_SYSLOG */
 
 /*
- * Format tag info for log lines 
+ * Format tag info for log lines; append to the provided buffer.
  */
-static const char * 
+static void
-log_line_prefix(void)
+log_line_prefix(StringInfo buf)
 {
+	/* static counter for line numbers */
+	static long log_line_number = 0;
+	/* has counter been reset in current process? */
+	static int	log_my_pid = 0;
 
-	/* static accumulator for line numbers */
+	int format_len;
-	static int log_line_number = 0;
+	int i;
- 
-	/* space for option string + one of each option, plus some room to spare */
-	/* Note: if more identifiers are built in this will have to increase */
-	static char *result = NULL;
-	int format_len = strlen(Log_line_prefix);
-	int result_len = 2*NAMEDATALEN + format_len +120 ;
-
-	if (result == NULL)
-		result = malloc(result_len);
-	result[0] = '\0';
-
-	if (format_len > 0)
-	{
-		int i,j;
-		char * dbname = NULL;
-		char * username = NULL;
-		time_t stamp_time;
-		log_line_number++;
-		if (MyProcPort != NULL)
-		{
-			dbname  = MyProcPort->database_name;
-			username = MyProcPort->user_name;
-			if (dbname == NULL || *dbname == '\0')
-				dbname = gettext("[unknown]");
-			if (username == NULL || *username == '\0')
-				username = gettext("[unknown]");
-		}
 
 	/*
-		 * invariant through each iteration of this loop:
+	 * This is one of the few places where we'd rather not inherit a
-		 *  . j is the index of the trailing null on result
+	 * static variable's value from the postmaster.  But since we will,
-		 *  . result_len - j is the number of chars we have room for
+	 * reset it when MyProcPid changes.
-		 *    including the trailing null
-		 *  . there is room to write at least one more non-null char plus the
-		 *    trailing null
 	 */
-		for (i = 0, j=0; i < format_len && j < result_len-1; i++)
+	if (log_my_pid != MyProcPid)
+	{
+		log_line_number = 0;
+		log_my_pid = MyProcPid;
+	}
+	log_line_number++;
+
+	if (Log_line_prefix == NULL)
+		return;					/* in case guc hasn't run yet */
+
+	format_len = strlen(Log_line_prefix);
+
+	for (i = 0; i < format_len; i++)
 	{
 		if (Log_line_prefix[i] != '%')
 		{
 			/* literal char, just copy */
-				result[j]=Log_line_prefix[i];
+			appendStringInfoChar(buf, Log_line_prefix[i]);
-				j++;
-				result[j] = '\0';
 			continue;
 		}
-			else if (i == format_len - 1)
-			{
-				/* format error - skip it */
-				continue;
-			}
-
 		/* go to char after '%' */
 		i++;
-
+		if (i >= format_len)
-			/* in postmaster and friends, skip non-applicable options,
-			 * stop if %x is seen
-			 */
-			if (MyProcPort == NULL)
 		{
-				if (Log_line_prefix[i] == 'x')
+			/* format error - ignore it */
 			break;
-				if (strchr("udcsir",Log_line_prefix[i]) != NULL)
-					continue;
 		}
 
 		/* process the option */
 		switch (Log_line_prefix[i])
 		{
 			case 'u':
-					j += snprintf(result+j,result_len-j,"%s",username);
+				if (MyProcPort)
+				{
+					const char *username = MyProcPort->user_name;
+
+					if (username == NULL || *username == '\0')
+						username = gettext("[unknown]");
+					appendStringInfo(buf, "%s", username);
+				}
 				break;
 			case 'd': 
-					j += snprintf(result+j,result_len-j,"%s",dbname);
+				if (MyProcPort)
+				{
+					const char *dbname = MyProcPort->database_name;
+
+					if (dbname == NULL || *dbname == '\0')
+						dbname = gettext("[unknown]");
+					appendStringInfo(buf, "%s", dbname);
+				}
 				break;
 			case 'c':
-					j += snprintf(result+j,result_len-j,"%lx.%lx",
+				if (MyProcPort)
+				{
+					appendStringInfo(buf, "%lx.%lx",
 									 (long)(MyProcPort->session_start.tv_sec),
 									 (long)MyProcPid);
+				}
 				break;
 			case 'p':
-					j += snprintf(result+j,result_len-j,"%ld",(long)MyProcPid);
+				appendStringInfo(buf, "%ld", (long)MyProcPid);
 				break;
 			case 'l':
-					j += snprintf(result+j,result_len-j,"%d",log_line_number);
+				appendStringInfo(buf, "%ld", log_line_number);
 				break;
 			case 't':
-					stamp_time = time(NULL);
+				{
-					j += strftime(result+j, result_len-j, "%Y-%m-%d %H:%M:%S",
+					time_t stamp_time = time(NULL);
+					char strfbuf[32];
+
+					strftime(strfbuf, sizeof(strfbuf), "%Y-%m-%d %H:%M:%S",
 							 localtime(&stamp_time));
+					appendStringInfoString(buf, strfbuf);
+				}
 				break;
 			case 's':
-					j += strftime(result+j, result_len-j, "%Y-%m-%d %H:%M:%S",
+				if (MyProcPort)
-							 localtime(&(MyProcPort->session_start.tv_sec)));
+				{
+					time_t stamp_time = MyProcPort->session_start.tv_sec;
+					char strfbuf[32];
+
+					strftime(strfbuf, sizeof(strfbuf), "%Y-%m-%d %H:%M:%S",
+							 localtime(&stamp_time));
+					appendStringInfoString(buf, strfbuf);
+				}
 				break;
 			case 'i':
-					j += snprintf(result+j,result_len-j,"%s",
+				if (MyProcPort)
-								  MyProcPort->commandTag);
+				{
+					appendStringInfo(buf, "%s", MyProcPort->commandTag);
+				}
 				break;
 			case 'r':
-					j += snprintf(result+j,result_len-j,"%s",
+				if (MyProcPort)
-								  MyProcPort->remote_host);
+				{
+					appendStringInfo(buf, "%s", MyProcPort->remote_host);
 					if (strlen(MyProcPort->remote_port) > 0)
-						j += snprintf(result+j,result_len-j,"(%s)",
+						appendStringInfo(buf, "(%s)",
 										 MyProcPort->remote_port);
+				}
 				break;
 			case 'x': 
-					/* non-postmaster case - just ignore */
+				/* in postmaster and friends, stop if %x is seen */
+				/* in a backend, just ignore */
+				if (MyProcPort == NULL)
+					i = format_len;
 				break;
 			case '%': 
-					result[j] = '%';
+				appendStringInfoChar(buf, '%');
-					j++;
-					result[j] = '\0';
 				break;
 			default:
-					/* format error - skip it */
+				/* format error - ignore it */
 				break;
 		}
 	}
 }
-	return result;
-}
 
 
 /*
@@ -1161,8 +1166,8 @@ send_message_to_server_log(ErrorData *edata)
 
 	initStringInfo(&buf);
 
-	appendStringInfo(&buf, "%s%s:  ", 
+	log_line_prefix(&buf);
-					 log_line_prefix(), error_severity(edata->elevel));
+	appendStringInfo(&buf, "%s:  ", error_severity(edata->elevel));
 
 	if (Log_error_verbosity >= PGERROR_VERBOSE)
 	{
@@ -1195,21 +1200,21 @@ send_message_to_server_log(ErrorData *edata)
 	{
 		if (edata->detail)
 		{
-			appendStringInfoString(&buf, log_line_prefix() );
+			log_line_prefix(&buf);
 			appendStringInfoString(&buf, gettext("DETAIL:  "));
 			append_with_tabs(&buf, edata->detail);
 			appendStringInfoChar(&buf, '\n');
 		}
 		if (edata->hint)
 		{
-			appendStringInfoString(&buf, log_line_prefix() );
+			log_line_prefix(&buf);
 			appendStringInfoString(&buf, gettext("HINT:  "));
 			append_with_tabs(&buf, edata->hint);
 			appendStringInfoChar(&buf, '\n');
 		}
 		if (edata->context)
 		{
-			appendStringInfoString(&buf, log_line_prefix() );
+			log_line_prefix(&buf);
 			appendStringInfoString(&buf, gettext("CONTEXT:  "));
 			append_with_tabs(&buf, edata->context);
 			appendStringInfoChar(&buf, '\n');
@@ -1218,23 +1223,27 @@ send_message_to_server_log(ErrorData *edata)
 		{
 			/* assume no newlines in funcname or filename... */
 			if (edata->funcname && edata->filename)
-				appendStringInfo(&buf, gettext("%sLOCATION:  %s, %s:%d\n"),
+			{
-								 log_line_prefix(),
+				log_line_prefix(&buf);
+				appendStringInfo(&buf, gettext("LOCATION:  %s, %s:%d\n"),
 								 edata->funcname, edata->filename,
 								 edata->lineno);
+			}
 			else if (edata->filename)
-				appendStringInfo(&buf, gettext("%sLOCATION:  %s:%d\n"),
+			{
-								 log_line_prefix(),
+				log_line_prefix(&buf);
+				appendStringInfo(&buf, gettext("LOCATION:  %s:%d\n"),
 								 edata->filename, edata->lineno);
 			}
 		}
+	}
 
 	/*
 	 * If the user wants the query that generated this error logged, do it.
 	 */
 	if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
 	{
-		appendStringInfoString(&buf, log_line_prefix() );
+		log_line_prefix(&buf);
 		appendStringInfoString(&buf, gettext("STATEMENT:  "));
 		append_with_tabs(&buf, debug_query_string);
 		appendStringInfoChar(&buf, '\n');
@@ -1284,10 +1293,6 @@ send_message_to_server_log(ErrorData *edata)
 	/* Write to stderr, if enabled */
 	if (Use_syslog <= 1 || whereToSendOutput == Debug)
 	{
-		/*
-		 * Timestamp and PID are only used for stderr output --- we assume
-		 * the syslog daemon will supply them for us in the other case.
-		 */
 		fprintf(stderr, "%s", buf.data);
 	}
 

src/backend/utils/misc/ps_status.c

@@ -5,7 +5,7 @@
  * to contain some useful information. Mechanism differs wildly across
  * platforms.
  *
- * $PostgreSQL: pgsql/src/backend/utils/misc/ps_status.c,v 1.18 2004/03/09 04:43:07 momjian Exp $
+ * $PostgreSQL: pgsql/src/backend/utils/misc/ps_status.c,v 1.19 2004/03/19 02:23:59 tgl Exp $
  *
  * Copyright (c) 2000-2003, PostgreSQL Global Development Group
  * various details abducted from various places
@@ -277,16 +277,15 @@ init_ps_display(const char *username, const char *dbname,
 void
 set_ps_display(const char *activity)
 {
+	/* save tag for possible use by elog.c */
+	if (MyProcPort)
+		MyProcPort->commandTag = activity;
+
+#ifndef PS_USE_NONE
 	/* no ps display for stand-alone backend */
 	if (!IsUnderPostmaster)
 		return;
 
-	/* save it for logging context */
-	if (MyProcPort)
-		MyProcPort->commandTag = (char *) activity;
-
-#ifndef PS_USE_NONE
-
 #ifdef PS_USE_CLOBBER_ARGV
 	/* If ps_buffer is a pointer, it might still be null */
 	if (!ps_buffer)

src/include/libpq/libpq-be.h

@@ -11,7 +11,7 @@
  * Portions Copyright (c) 1996-2003, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/libpq/libpq-be.h,v 1.42 2004/03/09 04:43:07 momjian Exp $
+ * $PostgreSQL: pgsql/src/include/libpq/libpq-be.h,v 1.43 2004/03/19 02:23:59 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -50,8 +50,6 @@ typedef struct Port
 	SockAddr	raddr;			/* remote addr (client) */
 	char        *remote_host;   /* name (or ip addr) of remote host */
 	char        *remote_port;   /* text rep of remote port */
-	char        *commandTag;    /* command tag for display in log lines */
-	struct timeval  session_start;  /* for session duration logging */
 	CAC_state	canAcceptConnections;	/* postmaster connection status */
 
 	/*
@@ -73,6 +71,14 @@ typedef struct Port
 	char		md5Salt[4];		/* Password salt */
 	char		cryptSalt[2];	/* Password salt */
 
+	/*
+	 * Information that really has no business at all being in struct Port,
+	 * but since it gets used by elog.c in the same way as database_name
+	 * and other members of this struct, we may as well keep it here.
+	 */
+	const char *commandTag;			/* current command tag */
+	struct timeval session_start;	/* for session duration logging */
+
 	/*
 	 * SSL structures
 	 */