Allow printf-style padding specifications in log_line_prefix.

David Rowley, after a suggestion from Heikki Linnakangas.  Reviewed by
Albe Laurenz, and further edited by me.

Author: robertmhaas

doc/src/sgml/config.sgml

@@ -3941,8 +3941,14 @@ local0.*    /var/log/postgresql
          that are replaced with status information as outlined below.
          Unrecognized escapes are ignored. Other
          characters are copied straight to the log line. Some escapes are
-         only recognized by session processes, and are ignored by
-         background processes such as the main server process.
+         only recognized by session processes, and will be treated as empty by
+         background processes such as the main server process. Status
+         information may be aligned either left or right by specifying a
+         numeric literal after the % and before the option. A negative
+         value will cause the status information to be padded on the
+         right with spaces to give it a minimum width, whereas a positive
+         value will pad on the left. Padding can be useful to aid human
+         readability in log files.
          This parameter can only be set in the <filename>postgresql.conf</>
          file or on the server command line. The default is an empty string.
 

src/backend/utils/error/elog.c

@@ -167,6 +167,7 @@ static char formatted_log_time[FORMATTED_TS_LEN];
 	} while (0)
 
 
+static const char *process_log_prefix_padding(const char *p, int *padding);
 static void log_line_prefix(StringInfo buf, ErrorData *edata);
 static void send_message_to_server_log(ErrorData *edata);
 static void send_message_to_frontend(ErrorData *edata);
@@ -2119,6 +2120,42 @@ setup_formatted_start_time(void)
 				pg_localtime(&stamp_time, log_timezone));
 }
 
+/*
+ * process_log_prefix_padding --- helper function for processing the format
+ * string in log_line_prefix
+ *
+ * Note: This function returns NULL if it finds something which
+ * it deems invalid in the format string.
+ */
+static const char *
+process_log_prefix_padding(const char *p, int *ppadding)
+{
+	int	paddingsign = 1;
+	int	padding = 0;
+
+	if (*p == '-')
+	{
+		p++;
+
+		if (*p == '\0')		/* Did the buf end in %- ? */
+			return NULL;
+		paddingsign = -1;
+	}
+	
+
+	/* generate an int version of the numerical string */
+	while (*p >= '0' && *p <= '9')
+		padding = padding * 10 + (*p++ - '0');
+
+	/* format is invalid if it ends with the padding number */
+	if (*p == '\0')
+		return NULL;
+
+	padding *= paddingsign;
+	*ppadding = padding;
+	return p;
+}
+
 /*
  * Format tag info for log lines; append to the provided buffer.
  */
@@ -2130,9 +2167,8 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 
 	/* has counter been reset in current process? */
 	static int	log_my_pid = 0;
-
-	int			format_len;
-	int			i;
+	int			padding;
+	const char *p;	
 
 	/*
 	 * This is one of the few places where we'd rather not inherit a static
@@ -2151,23 +2187,48 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 	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++)
+	for (p = Log_line_prefix; *p != '\0'; p++)
 	{
-		if (Log_line_prefix[i] != '%')
+		if (*p != '%')
 		{
 			/* literal char, just copy */
-			appendStringInfoChar(buf, Log_line_prefix[i]);
+			appendStringInfoChar(buf, *p);
 			continue;
 		}
-		/* go to char after '%' */
-		i++;
-		if (i >= format_len)
+
+		/* must be a '%', so skip to the next char */
+		p++;
+		if (*p == '\0')
 			break;				/* format error - ignore it */
+		else if (*p == '%')
+		{
+			/* string contains %% */
+			appendStringInfoChar(buf, '%');
+			continue;
+		}
+
+
+		/*
+		 * Process any formatting which may exist after the '%'.  Note that
+		 * process_log_prefix_padding moves p past the padding number if it
+		 * exists.
+		 *
+		 * Note: Since only '-', '0' to '9' are valid formatting characters
+		 * we can do a quick check here to pre-check for formatting. If the
+		 * char is not formatting then we can skip a useless function call.
+		 *
+		 * Further note: At least on some platforms, passing %*s rather than
+		 * %s to appendStringInfo() is substantially slower, so many of the
+		 * cases below avoid doing that unless non-zero padding is in fact
+		 * specified.
+		 */
+		if (*p > '9')
+			padding = 0;
+		else if ((p = process_log_prefix_padding(p, &padding)) == NULL)
+			break;
 
 		/* process the option */
-		switch (Log_line_prefix[i])
+		switch (*p)
 		{
 			case 'a':
 				if (MyProcPort)
@@ -2176,8 +2237,15 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 
 					if (appname == NULL || *appname == '\0')
 						appname = _("[unknown]");
-					appendStringInfoString(buf, appname);
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding, appname);
+					else
+						appendStringInfoString(buf, appname);
 				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
+
 				break;
 			case 'u':
 				if (MyProcPort)
@@ -2186,8 +2254,14 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 
 					if (username == NULL || *username == '\0')
 						username = _("[unknown]");
-					appendStringInfoString(buf, username);
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding, username);
+					else
+						appendStringInfoString(buf, username);
 				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
 				break;
 			case 'd':
 				if (MyProcPort)
@@ -2196,21 +2270,44 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 
 					if (dbname == NULL || *dbname == '\0')
 						dbname = _("[unknown]");
-					appendStringInfoString(buf, dbname);
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding, dbname);
+					else
+						appendStringInfoString(buf, dbname);
 				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
 				break;
 			case 'c':
-				appendStringInfo(buf, "%lx.%x", (long) (MyStartTime), MyProcPid);
+				if (padding != 0)
+				{
+					char strfbuf[128];
+					snprintf(strfbuf, sizeof(strfbuf) - 1, "%lx.%x", 
+						(long) (MyStartTime), MyProcPid);
+					appendStringInfo(buf, "%*s", padding, strfbuf);
+				}
+				else
+					appendStringInfo(buf, "%lx.%x", (long) (MyStartTime), MyProcPid);
 				break;
 			case 'p':
-				appendStringInfo(buf, "%d", MyProcPid);
+				if (padding != 0)
+					appendStringInfo(buf, "%*d", padding, MyProcPid);
+				else
+					appendStringInfo(buf, "%d", MyProcPid);
 				break;
 			case 'l':
-				appendStringInfo(buf, "%ld", log_line_number);
+				if (padding != 0)
+					appendStringInfo(buf, "%*ld", padding, log_line_number);
+				else
+					appendStringInfo(buf, "%ld", log_line_number);
 				break;
 			case 'm':
 				setup_formatted_log_time();
-				appendStringInfoString(buf, formatted_log_time);
+				if (padding != 0)
+					appendStringInfo(buf, "%*s", padding, formatted_log_time);
+				else
+					appendStringInfoString(buf, formatted_log_time);
 				break;
 			case 't':
 				{
@@ -2220,13 +2317,19 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 					pg_strftime(strfbuf, sizeof(strfbuf),
 								"%Y-%m-%d %H:%M:%S %Z",
 								pg_localtime(&stamp_time, log_timezone));
-					appendStringInfoString(buf, strfbuf);
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding, strfbuf);
+					else
+						appendStringInfoString(buf, strfbuf);
 				}
 				break;
 			case 's':
 				if (formatted_start_time[0] == '\0')
 					setup_formatted_start_time();
-				appendStringInfoString(buf, formatted_start_time);
+				if (padding != 0)
+					appendStringInfo(buf, "%*s", padding, formatted_start_time);
+				else
+					appendStringInfoString(buf, formatted_start_time);
 				break;
 			case 'i':
 				if (MyProcPort)
@@ -2235,43 +2338,105 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 					int			displen;
 
 					psdisp = get_ps_display(&displen);
-					appendBinaryStringInfo(buf, psdisp, displen);
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding, psdisp);
+					else
+						appendBinaryStringInfo(buf, psdisp, displen);
+
 				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
 				break;
 			case 'r':
 				if (MyProcPort && MyProcPort->remote_host)
 				{
-					appendStringInfoString(buf, MyProcPort->remote_host);
-					if (MyProcPort->remote_port &&
-						MyProcPort->remote_port[0] != '\0')
-						appendStringInfo(buf, "(%s)",
-										 MyProcPort->remote_port);
+					if (padding != 0) 
+					{
+						if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
+						{
+ 							/* 
+							 * This option is slightly special as the port number
+		 					 * may be appended onto the end. Here we need to build
+							 * 1 string which contains the remote_host and optionally
+							 * the remote_port (if set) so we can properly align the
+							 * string.
+							 */
+
+							char *hostport;
+							int alloclen = strlen(MyProcPort->remote_host) +
+								 strlen(MyProcPort->remote_port) + 3; 
+							hostport = palloc(alloclen);
+							sprintf(hostport, "%s(%s)", MyProcPort->remote_host, MyProcPort->remote_port);
+							appendStringInfo(buf, "%*s", padding, hostport);
+							pfree(hostport);
+						}
+						else
+							appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host);
+						
+					}
+					else
+					{
+						/* padding is 0, so we don't need a temp buffer */
+						appendStringInfoString(buf, MyProcPort->remote_host);
+						if (MyProcPort->remote_port &&
+							MyProcPort->remote_port[0] != '\0')
+							appendStringInfo(buf, "(%s)", 
+								MyProcPort->remote_port);
+					}
+
 				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
 				break;
 			case 'h':
-				if (MyProcPort && MyProcPort->remote_host)
-					appendStringInfoString(buf, MyProcPort->remote_host);
+				if (MyProcPort && MyProcPort->remote_host) 
+				{
+					if (padding != 0)
+						appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host);
+					else
+						appendStringInfoString(buf, MyProcPort->remote_host);
+				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
 				break;
 			case 'q':
 				/* in postmaster and friends, stop if %q is seen */
 				/* in a backend, just ignore */
 				if (MyProcPort == NULL)
-					i = format_len;
+					return;
 				break;
 			case 'v':
 				/* keep VXID format in sync with lockfuncs.c */
 				if (MyProc != NULL && MyProc->backendId != InvalidBackendId)
-					appendStringInfo(buf, "%d/%u",
-									 MyProc->backendId, MyProc->lxid);
+				{
+					if (padding != 0)
+					{
+						char strfbuf[128];
+						snprintf(strfbuf, sizeof(strfbuf) - 1, "%d/%u",
+							MyProc->backendId, MyProc->lxid);
+						appendStringInfo(buf, "%*s", padding, strfbuf);
+					}
+					else
+						appendStringInfo(buf, "%d/%u", MyProc->backendId, MyProc->lxid);
+				}
+				else if (padding != 0)
+					appendStringInfoSpaces(buf,
+										   padding > 0 ? padding : -padding);
 				break;
 			case 'x':
-				appendStringInfo(buf, "%u", GetTopTransactionIdIfAny());
+				if (padding != 0)
+					appendStringInfo(buf, "%*u", padding, GetTopTransactionIdIfAny());
+				else
+					appendStringInfo(buf, "%u", GetTopTransactionIdIfAny());
 				break;
 			case 'e':
-				appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode));
-				break;
-			case '%':
-				appendStringInfoChar(buf, '%');
+				if (padding != 0)
+					appendStringInfo(buf, "%*s", padding, unpack_sql_state(edata->sqlerrcode));
+				else
+					appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode));
 				break;
 			default:
 				/* format error - ignore it */