Tom Lane wrote:
> Andrew Dunstan <[EMAIL PROTECTED]> writes:
> > Tom Lane wrote:
> >> Well, if we want to cram all that stuff in there, how shall we do it?
> >> It seems wrong to put all those lines into one text field, but I'm
> >> not sure I want to add six more text fields to the CSV format
> >> either. Thoughts?
>
> > Really? Six? In any case, would that be so bad? It would mean six extra
> > commas per line in the log file, and nothing much in the log table
> > unless there were content in those fields.
>
> Yeah --- the lines output in the plain-stderr case that are not covered
> in the other are
>
> DETAIL
> HINT
> QUERY (this is an internally-generated query that failed)
> CONTEXT (think "stack trace")
> LOCATION (reference to code file/line reporting the error)
> STATEMENT (user query that led to the error)
Here is a patch to do this. It emits all of these as separate columns,
which are output empty if they are not present. Of course, the commas
are emitted all the time.
I changed some other things. For example, the original code puts
"[unknown]" when the username or database name is unknown. I think this
is pointless; an empty field is fine. I noticed that "unknown" VXIDs
and TransactionIds are printed as xx/-1 and 0 respectively. Should we
just leave the columns empty?
The error location (file and function name, and line number) are only
reported if log_error_verbosity is set, just like the main logs. The
commas are emitted anyway. It is emitted as a single field. So it is
a single column which looks like
"transformColumnRef, /pgsql/source/00head/src/backend/parser/parse_expr.c:420"
I very much doubt that it is worth separating that any further, but if
anyone disagrees, this is the time to change it.
I tried importing the resulting file into Gnumeric, and after some
fooling around to make it use commas as separators instead of colons (it
"autodetects" the separators and seems to consider colons best for these
files for some reason), it works fine, including multiline context
fields. It does look a bit weird though, because they are not multiline
in the spreadsheet but instead it shows the funny square reserved for
non-printable chars with the [0A] byte in it.
I imported it with COPY WITH CSV and it looks fine in psql; multiline
context is displayed correctly.
Another change I did was to change a "%.*s" to "%*s". The "precision"
marker seems useless AFAICT.
> One issue here is that CONTEXT is potentially multiple lines. I'm not
> sure that there is much we can do about that, especially not at the last
> minute. If we had some time to rewrite internal APIs it might be fun to
> think about emitting that as array of text not just text, but I fear
> it's much too late to consider that now.
In psql it looks like this. The first message is that I forgot to use
the CSV option to COPY the first time. The second message is that I
renamed a file from under CHECKPOINT to see what it looked like to not
have usernames, etc. The third is a nested plpgsql function call to
show multiline context.
alvherre=# select message, context from postgres_log where context is not null;
-[ RECORD 1
]-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
message | la sintaxis de entrada no es válida para tipo timestamp with time
zone: «2007-12-10 09:43:32.473
CLST,"alvherre","alvherre",475d33a0.3c78,[local],15480,3,"CREATE
TABLE",2007-12-10 09:40:00 CLST,1/4,387,NOTICE,00000,"CREATE TABLE / PRIMARY
KEY creará el índice implícito «postgres_log_pkey» para la tabla
«postgres_log»",,,,,,,,»
context | COPY postgres_log, línea 1, columna log_time: «2007-12-10
09:43:32.473 CLST,"alvherre","alvherre",475d33a0.3c78,[local],15480,3,"CREATE
TABLE",2007...»
-[ RECORD 2
]-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
message | no se pudo abrir la relación 1663/16384/16391: No existe el fichero o
el directorio
context | escribiendo el bloque 0 de la relación 1663/16384/16391
-[ RECORD 3
]-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
message | no existe la columna «foo»
context | PL/pgSQL function "foo" line 1 at SQL statement
: sentencia SQL: «select foo()»
: PL/pgSQL function "bar" line 1 at SQL statement
: sentencia SQL: «select bar()»
: PL/pgSQL function "baz" line 1 at SQL statement
The internal_query thing (notice how "cursor_pos" is only reported if
not zero):
alvherre=# select message, context, internal_query, internal_pos, query,
cursor_pos from postgres_log where internal_query is not null;
-[ RECORD 1 ]--+------------------------------------------------
message | no existe la columna «foo»
context | PL/pgSQL function "foo" line 1 at SQL statement
: sentencia SQL: «select foo()»
: PL/pgSQL function "bar" line 1 at SQL statement
: sentencia SQL: «select bar()»
: PL/pgSQL function "baz" line 1 at SQL statement
internal_query | select foo
internal_pos | 8
query | select baz();
cursor_pos |
--
Alvaro Herrera http://www.amazon.com/gp/registry/5ZYLFMCVHXC
"I personally became interested in Linux while I was dating an English major
who wouldn't know an operating system if it walked up and bit him."
(Val Henson)
Index: doc/src/sgml/config.sgml
===================================================================
RCS file: /home/alvherre/Code/cvs/pgsql/doc/src/sgml/config.sgml,v
retrieving revision 1.158
diff -c -p -r1.158 config.sgml
*** doc/src/sgml/config.sgml 28 Nov 2007 15:42:30 -0000 1.158
--- doc/src/sgml/config.sgml 10 Dec 2007 13:18:42 -0000
*************** local0.* /var/log/postgresql
*** 3169,3175 ****
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.
Here is a sample table definition for storing CSV-format log output:
<programlisting>
--- 3169,3180 ----
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,
! error message detail, hint, the internal query that led to the error
! if any, the error position thereof, the user query that led to the
! error if any, the error position thereof, and the location of the
! error in the PostgreSQL source code (this field is only emitted
! if <varname>log_error_verbosity</> is set to <literal>verbose</>).
Here is a sample table definition for storing CSV-format log output:
<programlisting>
*************** CREATE TABLE postgres_log
*** 3189,3194 ****
--- 3194,3207 ----
error_severity text,
sql_state_code text,
message text,
+ detail text,
+ context text,
+ hint text,
+ internal_query text,
+ internal_pos integer,
+ query text,
+ cursor_pos integer,
+ location text,
PRIMARY KEY (session_id, process_line_num)
);
</programlisting>
Index: src/backend/utils/error/elog.c
===================================================================
RCS file: /home/alvherre/Code/cvs/pgsql/src/backend/utils/error/elog.c,v
retrieving revision 1.198
diff -c -p -r1.198 elog.c
*** src/backend/utils/error/elog.c 15 Nov 2007 21:14:40 -0000 1.198
--- src/backend/utils/error/elog.c 10 Dec 2007 12:49:51 -0000
*************** static const char *error_severity(int el
*** 134,140 ****
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);
/*
--- 134,139 ----
*************** log_line_prefix(StringInfo buf)
*** 1616,1629 ****
/*
* append a CSV'd version of a string to a StringInfo
* We use the PostgreSQL defaults for CSV, i.e. quote = escape = '"'
*/
-
static inline void
appendCSVLiteral(StringInfo buf, const char *data)
{
const char *p = data;
char c;
appendStringInfoCharMacro(buf, '"');
while ((c = *p++) != '\0')
{
--- 1615,1632 ----
/*
* 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')
{
*************** appendCSVLiteral(StringInfo buf, const c
*** 1642,1649 ****
static void
write_csvlog(ErrorData *edata)
{
- StringInfoData msgbuf;
StringInfoData buf;
/* static counter for line numbers */
static long log_line_number = 0;
--- 1645,1652 ----
static void
write_csvlog(ErrorData *edata)
{
StringInfoData buf;
+ bool print_stmt = false;
/* static counter for line numbers */
static long log_line_number = 0;
*************** write_csvlog(ErrorData *edata)
*** 1664,1670 ****
}
log_line_number++;
- initStringInfo(&msgbuf);
initStringInfo(&buf);
/*
--- 1667,1672 ----
*************** write_csvlog(ErrorData *edata)
*** 1715,1740 ****
/* username */
if (MyProcPort)
! {
! const char *username = MyProcPort->user_name;
!
! if (username == NULL || *username == '\0')
! username = _("[unknown]");
!
! appendCSVLiteral(&buf, username);
! }
appendStringInfoChar(&buf, ',');
/* databasename */
if (MyProcPort)
! {
! const char *dbname = MyProcPort->database_name;
!
! if (dbname == NULL || *dbname == '\0')
! dbname = _("[unknown]");
!
! appendCSVLiteral(&buf, dbname);
! }
appendStringInfoChar(&buf, ',');
/* session id */
--- 1717,1728 ----
/* username */
if (MyProcPort)
! appendCSVLiteral(&buf, MyProcPort->user_name);
appendStringInfoChar(&buf, ',');
/* databasename */
if (MyProcPort)
! appendCSVLiteral(&buf, MyProcPort->database_name);
appendStringInfoChar(&buf, ',');
/* session id */
*************** write_csvlog(ErrorData *edata)
*** 1762,1774 ****
/* PS display */
if (MyProcPort)
{
const char *psdisp;
int displen;
psdisp = get_ps_display(&displen);
! appendStringInfo(&msgbuf, "%.*s", displen, psdisp);
appendCSVLiteral(&buf, msgbuf.data);
! resetStringInfo(&msgbuf);
}
appendStringInfoChar(&buf, ',');
--- 1750,1766 ----
/* 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);
!
! pfree(msgbuf.data);
}
appendStringInfoChar(&buf, ',');
*************** write_csvlog(ErrorData *edata)
*** 1796,1808 ****
appendStringInfoChar(&buf, ',');
/* Error severity */
! appendStringInfo(&buf, "%s,", error_severity(edata->elevel));
/* SQL state code */
! appendStringInfo(&buf, "%s,", unpack_sql_state(edata->sqlerrcode));
! /* Error message and cursor position if any */
! get_csv_error_message(&buf, edata);
appendStringInfoChar(&buf, '\n');
--- 1788,1863 ----
appendStringInfoChar(&buf, ',');
/* Error severity */
! appendStringInfo(&buf, "%s", error_severity(edata->elevel));
! appendStringInfoChar(&buf, ',');
/* SQL state code */
! appendStringInfo(&buf, "%s", unpack_sql_state(edata->sqlerrcode));
! appendStringInfoChar(&buf, ',');
!
! /* errmessage */
! appendCSVLiteral(&buf, edata->message);
! appendStringInfoCharMacro(&buf, ',');
!
! /* errdetail */
! appendCSVLiteral(&buf, edata->detail);
! appendStringInfoCharMacro(&buf, ',');
!
! /* errcontext -- XXX maybe multiline -- need to do something about that? */
! appendCSVLiteral(&buf, edata->context);
! appendStringInfoCharMacro(&buf, ',');
!
! /* errhint */
! appendCSVLiteral(&buf, edata->hint);
! appendStringInfoCharMacro(&buf, ',');
!
! /* internal query */
! appendCSVLiteral(&buf, edata->internalquery);
! appendStringInfoCharMacro(&buf, ',');
!
! /* if printed internal query, print internal pos too */
! if (edata->internalpos > 0 && edata->internalquery != NULL)
! appendStringInfo(&buf, "%d", edata->internalpos);
! appendStringInfoCharMacro(&buf, ',');
!
! /* the user query is 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)
! {
! /* assume no newlines in funcname or filename... */
! if (edata->funcname && edata->filename)
! {
! StringInfoData msgbuf;
!
! initStringInfo(&msgbuf);
! appendStringInfo(&msgbuf, "%s, %s:%d",
! edata->funcname, edata->filename,
! edata->lineno);
! appendCSVLiteral(&buf, msgbuf.data);
! pfree(msgbuf.data);
! }
! else if (edata->filename)
! {
! StringInfoData msgbuf;
!
! initStringInfo(&msgbuf);
! appendStringInfo(&msgbuf, "%s:%d",
! edata->filename, edata->lineno);
! appendCSVLiteral(&buf, msgbuf.data);
! pfree(msgbuf.data);
! }
! }
appendStringInfoChar(&buf, '\n');
*************** write_csvlog(ErrorData *edata)
*** 1812,1851 ****
else
write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
- pfree(msgbuf.data);
pfree(buf.data);
}
/*
- * 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;
-
- appendStringInfoCharMacro(buf, '"');
-
- while ((c = *msg++) != '\0')
- {
- if (c == '"')
- appendStringInfoCharMacro(buf, '"');
- appendStringInfoCharMacro(buf, c);
- }
-
- if (edata->cursorpos > 0)
- appendStringInfo(buf, _(" at character %d"),
- edata->cursorpos);
- else if (edata->internalpos > 0)
- appendStringInfo(buf, _(" at character %d"),
- edata->internalpos);
-
- appendStringInfoCharMacro(buf, '"');
- }
-
- /*
* Unpack MAKE_SQLSTATE code. Note that this returns a pointer to a
* static buffer.
*/
--- 1867,1876 ----
---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings
