Allow printf-style padding specifications in log_line_prefix.
authorRobert Haas
Thu, 26 Sep 2013 21:54:20 +0000 (17:54 -0400)
committerRobert Haas
Thu, 26 Sep 2013 21:56:31 +0000 (17:56 -0400)
David Rowley, after a suggestion from Heikki Linnakangas.  Reviewed by
Albe Laurenz, and further edited by me.

doc/src/sgml/config.sgml
src/backend/utils/error/elog.c

index 370aa09ee7c3f750f7ea5a76f18fc54b86f8e984..697cf401374758e47eb174a3f22b451b20e0f272 100644 (file)
@@ -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 postgresql.conf
          file or on the server command line. The default is an empty string.
 
index a415b907b6af930443cc5f7eab38025da1da3f6e..eb62ff5054cceaeb34399272a841d73fc4527f4a 100644 (file)
@@ -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 */