Extend the format of CSV logs to include the additional information supplied
authorAlvaro Herrera <alvherre@alvh.no-ip.org>
Tue, 11 Dec 2007 15:19:05 +0000 (15:19 +0000)
committerAlvaro Herrera <alvherre@alvh.no-ip.org>
Tue, 11 Dec 2007 15:19:05 +0000 (15:19 +0000)
with the logged event.  CSV logs are now a first-class citizen along plain
text logs in that they carry much of the same information.

Per complaint from depesz on bug #3799.

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

index a2f95b209c6d6d66445785d0ef6aba564a4cf600..4188c5ca7764f64d7b3a52d6db05e1c0d0d36c13 100644 (file)
@@ -1,4 +1,4 @@
-<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.158 2007/11/28 15:42:30 petere Exp $ -->
+<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.159 2007/12/11 15:19:05 alvherre Exp $ -->
 
 <chapter Id="runtime-config">
   <title>Server Configuration</title>
@@ -3169,7 +3169,13 @@ local0.*    /var/log/postgresql
         with these columns: timestamp with milliseconds, user name, database
         name, session ID, host:port number, process ID, per-process line
         number, command tag, session start time, virtual transaction ID,
-        regular transaction id, error severity, SQL state code, error message.
+        regular transaction id, error severity, SQL state code, error message,
+        error message detail, hint, internal query that led to the error (if
+        any), character count of the error position thereof, error context,
+        user query that led to the error (if any and enabled by
+        <varname>log_min_error_statement</>), character count of the error
+        position thereof, location of the error in the PostgreSQL source code
+        (if <varname>log_error_verbosity</> is set to <literal>verbose</>).
         Here is a sample table definition for storing CSV-format log output:
 
 <programlisting>
@@ -3189,6 +3195,14 @@ CREATE TABLE postgres_log
   error_severity text,
   sql_state_code text,
   message text,
+  detail text,
+  hint text,
+  internal_query text,
+  internal_query_pos integer,
+  context text,
+  query text,
+  query_pos integer,
+  location text,
   PRIMARY KEY (session_id, process_line_num)
 );
 </programlisting>
index bb010162ba442b83947ff542bc9f112f72039f80..57bd3b5036fe1739ab27c39e5a2bd99be9e95e75 100644 (file)
@@ -42,7 +42,7 @@
  *
  *
  * IDENTIFICATION
- *       $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.198 2007/11/15 21:14:40 momjian Exp $
+ *       $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.199 2007/12/11 15:19:05 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -134,7 +134,6 @@ static const char *error_severity(int elevel);
 static void append_with_tabs(StringInfo buf, const char *str);
 static bool is_log_level_output(int elevel, int log_min_level);
 static void write_pipe_chunks(char *data, int len, int dest);
-static void get_csv_error_message(StringInfo buf, ErrorData *edata);
 static void write_csvlog(ErrorData *edata);
 
 /*
@@ -1612,18 +1611,21 @@ log_line_prefix(StringInfo buf)
        }
 }
 
-
 /*
  * append a CSV'd version of a string to a StringInfo
  * We use the PostgreSQL defaults for CSV, i.e. quote = escape = '"'
+ * If it's NULL, append nothing.
  */
-
 static inline void
 appendCSVLiteral(StringInfo buf, const char *data)
 {
        const char *p = data;
        char            c;
 
+       /* avoid confusing an empty string with NULL */
+       if (p == NULL)
+               return;
+
        appendStringInfoCharMacro(buf, '"');
        while ((c = *p++) != '\0')
        {
@@ -1635,15 +1637,14 @@ appendCSVLiteral(StringInfo buf, const char *data)
 }
 
 /*
- * Constructs the error message, depending on the Errordata it gets,
- * in CSV (comma separated values) format. The COPY command
- * can then be used to load the messages into a table.
+ * Constructs the error message, depending on the Errordata it gets, in a CSV
+ * format which is described in doc/src/sgml/config.sgml.
  */
 static void
 write_csvlog(ErrorData *edata)
 {
-       StringInfoData msgbuf;
        StringInfoData buf;
+       bool    print_stmt = false;
 
        /* static counter for line numbers */
        static long log_line_number = 0;
@@ -1664,24 +1665,15 @@ write_csvlog(ErrorData *edata)
        }
        log_line_number++;
 
-       initStringInfo(&msgbuf);
        initStringInfo(&buf);
 
-       /*
-        * The format of the log output in CSV format: timestamp with
-        * milliseconds, username, databasename, session id, host and port number,
-        * process id, process line number, command tag, session start time,
-        * virtual transaction id, regular transaction id, error severity, sql
-        * state code, error message.
-        */
-
-       /* timestamp_with_milliseconds */
 
        /*
-        * Check if the timestamp is already calculated for the syslog message, if
-        * it is, then no need to calculate it again, will use the same, else get
-        * the current timestamp. This is done to put same timestamp in both
-        * syslog and csvlog messages.
+        * timestamp with milliseconds
+        *
+        * Check if the timestamp is already calculated for the syslog message,
+        * and use it if so.  Otherwise, get the current timestamp.  This is done
+        * to put same timestamp in both syslog and csvlog messages.
         */
        if (formatted_log_time[0] == '\0')
        {
@@ -1715,38 +1707,26 @@ write_csvlog(ErrorData *edata)
 
        /* username */
        if (MyProcPort)
-       {
-               const char *username = MyProcPort->user_name;
-
-               if (username == NULL || *username == '\0')
-                       username = _("[unknown]");
-
-               appendCSVLiteral(&buf, username);
-       }
+               appendCSVLiteral(&buf, MyProcPort->user_name);
        appendStringInfoChar(&buf, ',');
 
-       /* databasename */
+       /* database name */
        if (MyProcPort)
-       {
-               const char *dbname = MyProcPort->database_name;
-
-               if (dbname == NULL || *dbname == '\0')
-                       dbname = _("[unknown]");
-
-               appendCSVLiteral(&buf, dbname);
-       }
+               appendCSVLiteral(&buf, MyProcPort->database_name);
        appendStringInfoChar(&buf, ',');
 
        /* session id */
        appendStringInfo(&buf, "%lx.%x", (long) MyStartTime, MyProcPid);
        appendStringInfoChar(&buf, ',');
 
-       /* Remote host and port (is it safe to not quote this?) */
+       /* Remote host and port */
        if (MyProcPort && MyProcPort->remote_host)
        {
+               appendStringInfoChar(&buf, '"');
                appendStringInfo(&buf, "%s", MyProcPort->remote_host);
                if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
                        appendStringInfo(&buf, ":%s", MyProcPort->remote_port);
+               appendStringInfoChar(&buf, '"');
        }
        appendStringInfoChar(&buf, ',');
 
@@ -1762,13 +1742,17 @@ write_csvlog(ErrorData *edata)
        /* PS display */
        if (MyProcPort)
        {
+               StringInfoData msgbuf;
                const char *psdisp;
                int                     displen;
 
+               initStringInfo(&msgbuf);
+
                psdisp = get_ps_display(&displen);
                appendStringInfo(&msgbuf, "%.*s", displen, psdisp);
                appendCSVLiteral(&buf, msgbuf.data);
-               resetStringInfo(&msgbuf);
+       
+               pfree(msgbuf.data);
        }
        appendStringInfoChar(&buf, ',');
 
@@ -1787,7 +1771,7 @@ write_csvlog(ErrorData *edata)
 
        /* Virtual transaction id */
        /* keep VXID format in sync with lockfuncs.c */
-       if (MyProc != NULL)
+       if (MyProc != NULL && MyProc->backendId != InvalidBackendId)
                appendStringInfo(&buf, "%d/%u", MyProc->backendId, MyProc->lxid);
        appendStringInfoChar(&buf, ',');
 
@@ -1796,53 +1780,77 @@ write_csvlog(ErrorData *edata)
        appendStringInfoChar(&buf, ',');
 
        /* Error severity */
-       appendStringInfo(&buf, "%s,", error_severity(edata->elevel));
+       appendStringInfo(&buf, "%s", error_severity(edata->elevel));
+       appendStringInfoChar(&buf, ',');
 
        /* SQL state code */
-       appendStringInfo(&buf, "%s,", unpack_sql_state(edata->sqlerrcode));
+       appendStringInfo(&buf, "%s", unpack_sql_state(edata->sqlerrcode));
+       appendStringInfoChar(&buf, ',');
 
-       /* Error message and cursor position if any */
-       get_csv_error_message(&buf, edata);
+       /* errmessage */
+       appendCSVLiteral(&buf, edata->message);
+       appendStringInfoCharMacro(&buf, ',');
 
-       appendStringInfoChar(&buf, '\n');
+       /* errdetail */
+       appendCSVLiteral(&buf, edata->detail);
+       appendStringInfoCharMacro(&buf, ',');
 
-       /* If in the syslogger process, try to write messages direct to file */
-       if (am_syslogger)
-               write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
-       else
-               write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
+       /* errhint */
+       appendCSVLiteral(&buf, edata->hint);
+       appendStringInfoCharMacro(&buf, ',');
 
-       pfree(msgbuf.data);
-       pfree(buf.data);
-}
+       /* internal query */
+       appendCSVLiteral(&buf, edata->internalquery);
+       appendStringInfoCharMacro(&buf, ',');
 
-/*
- * Appends the buffer with the error message and the cursor position, all
- * CSV escaped.
- */
-static void
-get_csv_error_message(StringInfo buf, ErrorData *edata)
-{
-       char       *msg = edata->message ? edata->message : _("missing error text");
-       char            c;
+       /* if printed internal query, print internal pos too */
+       if (edata->internalpos > 0 && edata->internalquery != NULL)
+               appendStringInfo(&buf, "%d", edata->internalpos);
+       appendStringInfoCharMacro(&buf, ',');
 
-       appendStringInfoCharMacro(buf, '"');
+       /* errcontext */
+       appendCSVLiteral(&buf, edata->context);
+       appendStringInfoCharMacro(&buf, ',');
 
-       while ((c = *msg++) != '\0')
+       /* user query --- only reported if not disabled by the caller */
+       if (is_log_level_output(edata->elevel, log_min_error_statement) &&
+               debug_query_string != NULL &&
+               !edata->hide_stmt)
+               print_stmt = true;
+       if (print_stmt)
+               appendCSVLiteral(&buf, debug_query_string);
+       appendStringInfoCharMacro(&buf, ',');
+       if (print_stmt && edata->cursorpos > 0)
+               appendStringInfo(&buf, "%d", edata->cursorpos);
+       appendStringInfoCharMacro(&buf, ',');
+
+       /* file error location */
+       if (Log_error_verbosity >= PGERROR_VERBOSE)
        {
-               if (c == '"')
-                       appendStringInfoCharMacro(buf, '"');
-               appendStringInfoCharMacro(buf, c);
+               StringInfoData  msgbuf;
+
+               initStringInfo(&msgbuf);
+
+               if (edata->funcname && edata->filename)
+                       appendStringInfo(&msgbuf, "%s, %s:%d",
+                                                        edata->funcname, edata->filename,
+                                                        edata->lineno);
+               else if (edata->filename)
+                       appendStringInfo(&msgbuf, "%s:%d",
+                                                        edata->filename, edata->lineno);
+               appendCSVLiteral(&buf, msgbuf.data);
+               pfree(msgbuf.data);
        }
 
-       if (edata->cursorpos > 0)
-               appendStringInfo(buf, _(" at character %d"),
-                                                edata->cursorpos);
-       else if (edata->internalpos > 0)
-               appendStringInfo(buf, _(" at character %d"),
-                                                edata->internalpos);
+       appendStringInfoChar(&buf, '\n');
 
-       appendStringInfoCharMacro(buf, '"');
+       /* If in the syslogger process, try to write messages direct to file */
+       if (am_syslogger)
+               write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
+       else
+               write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
+
+       pfree(buf.data);
 }
 
 /*