log_line_info
Attached is a patch for tagging log lines produced by backends. It is
not quite ready for application - this is for people to look over and
play with.
For my testing I used the following settings:
log_connections = true
log_disconnections = true
log_line_info = '%T [%P] %U@%D(%C:%S) %I line:%L '
log_statement = true
log_hostname = true
log_source_port = true
Comments welcome
(Rod Taylor has suggested adding in escapes for remote host and remote
port. This can be done easily enough - I want to call a halt at some
stage and get the basics of this in. Extending it will then be easy).
cheers
andrew
Attachments:
log_line_info.patch2text/plain; name=log_line_info.patch2Download
? GNUmakefile
? config.log
? config.status
? log_line_info.patch
? log_line_info.patch2
? logpatch.txt
? updatelog
? contrib/spi/.deps
? src/Makefile.global
? src/backend/postgres
? src/backend/access/common/.deps
? src/backend/access/gist/.deps
? src/backend/access/hash/.deps
? src/backend/access/heap/.deps
? src/backend/access/index/.deps
? src/backend/access/nbtree/.deps
? src/backend/access/rtree/.deps
? src/backend/access/transam/.deps
? src/backend/bootstrap/.deps
? src/backend/catalog/.deps
? src/backend/catalog/postgres.bki
? src/backend/catalog/postgres.description
? src/backend/commands/.deps
? src/backend/executor/.deps
? src/backend/lib/.deps
? src/backend/libpq/.deps
? src/backend/main/.deps
? src/backend/nodes/.deps
? src/backend/optimizer/geqo/.deps
? src/backend/optimizer/path/.deps
? src/backend/optimizer/plan/.deps
? src/backend/optimizer/prep/.deps
? src/backend/optimizer/util/.deps
? src/backend/parser/.deps
? src/backend/port/.deps
? src/backend/postmaster/.deps
? src/backend/regex/.deps
? src/backend/rewrite/.deps
? src/backend/storage/buffer/.deps
? src/backend/storage/file/.deps
? src/backend/storage/freespace/.deps
? src/backend/storage/ipc/.deps
? src/backend/storage/large_object/.deps
? src/backend/storage/lmgr/.deps
? src/backend/storage/page/.deps
? src/backend/storage/smgr/.deps
? src/backend/tcop/.deps
? src/backend/utils/.deps
? src/backend/utils/adt/.deps
? src/backend/utils/cache/.deps
? src/backend/utils/error/.deps
? src/backend/utils/fmgr/.deps
? src/backend/utils/hash/.deps
? src/backend/utils/init/.deps
? src/backend/utils/mb/.deps
? src/backend/utils/mb/conversion_procs/conversion_create.sql
? src/backend/utils/mb/conversion_procs/ascii_and_mic/.deps
? src/backend/utils/mb/conversion_procs/ascii_and_mic/libascii_and_mic.so.0.0
? src/backend/utils/mb/conversion_procs/cyrillic_and_mic/.deps
? src/backend/utils/mb/conversion_procs/cyrillic_and_mic/libcyrillic_and_mic.so.0.0
? src/backend/utils/mb/conversion_procs/euc_cn_and_mic/.deps
? src/backend/utils/mb/conversion_procs/euc_cn_and_mic/libeuc_cn_and_mic.so.0.0
? src/backend/utils/mb/conversion_procs/euc_jp_and_sjis/.deps
? src/backend/utils/mb/conversion_procs/euc_jp_and_sjis/libeuc_jp_and_sjis.so.0.0
? src/backend/utils/mb/conversion_procs/euc_kr_and_mic/.deps
? src/backend/utils/mb/conversion_procs/euc_kr_and_mic/libeuc_kr_and_mic.so.0.0
? src/backend/utils/mb/conversion_procs/euc_tw_and_big5/.deps
? src/backend/utils/mb/conversion_procs/euc_tw_and_big5/libeuc_tw_and_big5.so.0.0
? src/backend/utils/mb/conversion_procs/latin2_and_win1250/.deps
? src/backend/utils/mb/conversion_procs/latin2_and_win1250/liblatin2_and_win1250.so.0.0
? src/backend/utils/mb/conversion_procs/latin_and_mic/.deps
? src/backend/utils/mb/conversion_procs/latin_and_mic/liblatin_and_mic.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_ascii/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_ascii/libutf8_and_ascii.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_big5/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_big5/libutf8_and_big5.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_cyrillic/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_cyrillic/libutf8_and_cyrillic.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_euc_cn/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_euc_cn/libutf8_and_euc_cn.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_euc_jp/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_euc_jp/libutf8_and_euc_jp.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_euc_kr/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_euc_kr/libutf8_and_euc_kr.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_euc_tw/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_euc_tw/libutf8_and_euc_tw.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_gb18030/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_gb18030/libutf8_and_gb18030.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_gbk/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_gbk/libutf8_and_gbk.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_iso8859/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_iso8859/libutf8_and_iso8859.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_iso8859_1/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_iso8859_1/libutf8_and_iso8859_1.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_johab/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_johab/libutf8_and_johab.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_sjis/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_sjis/libutf8_and_sjis.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_tcvn/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_tcvn/libutf8_and_tcvn.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_uhc/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_uhc/libutf8_and_uhc.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_win1250/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_win1250/libutf8_and_win1250.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_win1256/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_win1256/libutf8_and_win1256.so.0.0
? src/backend/utils/mb/conversion_procs/utf8_and_win874/.deps
? src/backend/utils/mb/conversion_procs/utf8_and_win874/libutf8_and_win874.so.0.0
? src/backend/utils/misc/.deps
? src/backend/utils/mmgr/.deps
? src/backend/utils/sort/.deps
? src/backend/utils/time/.deps
? src/bin/initdb/.deps
? src/bin/initdb/initdb
? src/bin/initlocation/initlocation
? src/bin/ipcclean/ipcclean
? src/bin/pg_config/pg_config
? src/bin/pg_controldata/.deps
? src/bin/pg_controldata/pg_controldata
? src/bin/pg_ctl/pg_ctl
? src/bin/pg_dump/.deps
? src/bin/pg_dump/pg_dump
? src/bin/pg_dump/pg_dumpall
? src/bin/pg_dump/pg_restore
? src/bin/pg_encoding/.deps
? src/bin/pg_encoding/pg_encoding
? src/bin/pg_resetxlog/.deps
? src/bin/pg_resetxlog/pg_resetxlog
? src/bin/psql/.deps
? src/bin/psql/psql
? src/bin/scripts/.deps
? src/bin/scripts/clusterdb
? src/bin/scripts/createdb
? src/bin/scripts/createlang
? src/bin/scripts/createuser
? src/bin/scripts/dropdb
? src/bin/scripts/droplang
? src/bin/scripts/dropuser
? src/bin/scripts/vacuumdb
? src/include/pg_config.h
? src/include/stamp-h
? src/interfaces/ecpg/compatlib/.deps
? src/interfaces/ecpg/compatlib/libecpg_compat.so.1.1
? src/interfaces/ecpg/ecpglib/.deps
? src/interfaces/ecpg/ecpglib/libecpg.so.4.1
? src/interfaces/ecpg/pgtypeslib/.deps
? src/interfaces/ecpg/pgtypeslib/libpgtypes.so.1.1
? src/interfaces/ecpg/preproc/.deps
? src/interfaces/ecpg/preproc/ecpg
? src/interfaces/libpq/.deps
? src/interfaces/libpq/libpq.so.3.2
? src/pl/plpgsql/src/.deps
? src/pl/plpgsql/src/libplpgsql.so.1.0
? src/port/.deps
? src/test/regress/.deps
? src/test/regress/log
? src/test/regress/pg_regress
? src/test/regress/results
? src/test/regress/tmp_check
? src/test/regress/expected/constraints.out
? src/test/regress/expected/copy.out
? src/test/regress/expected/create_function_1.out
? src/test/regress/expected/create_function_2.out
? src/test/regress/expected/misc.out
? src/test/regress/sql/constraints.sql
? src/test/regress/sql/copy.sql
? src/test/regress/sql/create_function_1.sql
? src/test/regress/sql/create_function_2.sql
? src/test/regress/sql/misc.sql
Index: src/backend/postmaster/postmaster.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/postmaster/postmaster.c,v
retrieving revision 1.367
diff -c -r1.367 postmaster.c
*** src/backend/postmaster/postmaster.c 17 Feb 2004 03:54:56 -0000 1.367
--- src/backend/postmaster/postmaster.c 23 Feb 2004 15:04:47 -0000
***************
*** 2434,2439 ****
--- 2434,2440 ----
/* set these to empty in case they are needed before we set them up */
port->remote_host = "";
port->remote_port = "";
+ port->commandTag = "";
/* Save port etc. for ps status */
MyProcPort = port;
Index: src/backend/utils/error/elog.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/error/elog.c,v
retrieving revision 1.126
diff -c -r1.126 elog.c
*** src/backend/utils/error/elog.c 29 Nov 2003 19:52:01 -0000 1.126
--- src/backend/utils/error/elog.c 23 Feb 2004 15:04:47 -0000
***************
*** 72,77 ****
--- 72,78 ----
bool Log_timestamp = false; /* show timestamps in stderr
* output */
bool Log_pid = false; /* show PIDs in stderr output */
+ char *Log_line_info = ""; /* format for extra log line info */
#ifdef HAVE_SYSLOG
/*
***************
*** 146,152 ****
static const char *print_timestamp(void);
static const char *print_pid(void);
static void append_with_tabs(StringInfo buf, const char *str);
!
/*
* errstart --- begin an error-reporting cycle
--- 147,153 ----
static const char *print_timestamp(void);
static const char *print_pid(void);
static void append_with_tabs(StringInfo buf, const char *str);
! static const char *log_line_info(void);
/*
* errstart --- begin an error-reporting cycle
***************
*** 1022,1027 ****
--- 1023,1132 ----
}
#endif /* HAVE_SYSLOG */
+ /*
+ * Formatted tag info for log if option is set and we have data,
+ * or empty string otherwise.
+ */
+ static const char *
+ log_line_info(void)
+ {
+
+ /* static accumulator for line numbers */
+ static int log_line_number = 0;
+
+ /* 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_info);
+ int result_len = 2*NAMEDATALEN + format_len +120 ;
+
+ if (result == NULL)
+ result = malloc(result_len);
+ result[0] = '\0';
+
+ if (format_len > 0 && MyProcPort)
+ {
+ int i,j;
+ char * dbname = MyProcPort->database_name;
+ char * username = MyProcPort->user_name;
+ time_t stamp_time;
+ log_line_number++;
+ if (dbname == NULL)
+ dbname="";
+ if (username == NULL)
+ username = "";
+
+ /*
+ * invariant through each iteration of this loop:
+ * . j is the index of the trailing null on result
+ * . result_len - j is the number of chars we have room for
+ * 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_line_info[i] != '%')
+ {
+ /* literal char, just copy */
+ result[j]=Log_line_info[i];
+ j++;
+ result[j] = '\0';
+ continue;
+ }
+ else if (i == format_len - 1)
+ {
+ /* format error - skip it */
+ continue;
+ }
+ /* go to char after '%', take action accordingly */
+ i++;
+ switch (Log_line_info[i])
+ {
+ case 'U':
+ j += snprintf(result+j,result_len-j,"%s",username);
+ break;
+ case 'D':
+ j += snprintf(result+j,result_len-j,"%s",dbname);
+ break;
+ case 'C':
+ j += snprintf(result+j,result_len-j,"%lx.%lx",
+ (long)(MyProcPort->session_start.tv_sec),
+ (long)MyProcPid);
+ break;
+ case 'P':
+ j += snprintf(result+j,result_len-j,"%ld",(long)MyProcPid);
+ break;
+ case 'L':
+ j += snprintf(result+j,result_len-j,"%d",log_line_number);
+ break;
+ case 'T':
+ stamp_time = time(NULL);
+ j += strftime(result+j, result_len-j, "%Y-%m-%d %H:%M:%S",
+ localtime(&stamp_time));
+ break;
+ case 'S':
+ j += strftime(result+j, result_len-j, "%Y-%m-%d %H:%M:%S",
+ localtime(&(MyProcPort->session_start.tv_sec)));
+ break;
+ case 'I':
+ j += snprintf(result+j,result_len-j,"%s",
+ MyProcPort->commandTag);
+ break;
+ case '%':
+ result[j] = '%';
+ j++;
+ result[j] = '\0';
+ break;
+ default:
+ /* format error - skip it */
+ break;
+ }
+ }
+ }
+ return result;
+ }
+
/*
* Write error report to server's log
***************
*** 1033,1039 ****
initStringInfo(&buf);
! appendStringInfo(&buf, "%s: ", error_severity(edata->elevel));
if (Log_error_verbosity >= PGERROR_VERBOSE)
{
--- 1138,1145 ----
initStringInfo(&buf);
! appendStringInfo(&buf, "%s%s: ",
! log_line_info(), error_severity(edata->elevel));
if (Log_error_verbosity >= PGERROR_VERBOSE)
{
***************
*** 1066,1083 ****
--- 1172,1192 ----
{
if (edata->detail)
{
+ appendStringInfoString(&buf, log_line_info() );
appendStringInfoString(&buf, gettext("DETAIL: "));
append_with_tabs(&buf, edata->detail);
appendStringInfoChar(&buf, '\n');
}
if (edata->hint)
{
+ appendStringInfoString(&buf, log_line_info() );
appendStringInfoString(&buf, gettext("HINT: "));
append_with_tabs(&buf, edata->hint);
appendStringInfoChar(&buf, '\n');
}
if (edata->context)
{
+ appendStringInfoString(&buf, log_line_info() );
appendStringInfoString(&buf, gettext("CONTEXT: "));
append_with_tabs(&buf, edata->context);
appendStringInfoChar(&buf, '\n');
***************
*** 1086,1096 ****
{
/* assume no newlines in funcname or filename... */
if (edata->funcname && edata->filename)
! appendStringInfo(&buf, gettext("LOCATION: %s, %s:%d\n"),
edata->funcname, edata->filename,
edata->lineno);
else if (edata->filename)
! appendStringInfo(&buf, gettext("LOCATION: %s:%d\n"),
edata->filename, edata->lineno);
}
}
--- 1195,1207 ----
{
/* assume no newlines in funcname or filename... */
if (edata->funcname && edata->filename)
! appendStringInfo(&buf, gettext("%sLOCATION: %s, %s:%d\n"),
! log_line_info(),
edata->funcname, edata->filename,
edata->lineno);
else if (edata->filename)
! appendStringInfo(&buf, gettext("%sLOCATION: %s:%d\n"),
! log_line_info(),
edata->filename, edata->lineno);
}
}
***************
*** 1100,1105 ****
--- 1211,1217 ----
*/
if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
{
+ appendStringInfoString(&buf, log_line_info() );
appendStringInfoString(&buf, gettext("STATEMENT: "));
append_with_tabs(&buf, debug_query_string);
appendStringInfoChar(&buf, '\n');
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.187
diff -c -r1.187 guc.c
*** src/backend/utils/misc/guc.c 17 Feb 2004 03:54:57 -0000 1.187
--- src/backend/utils/misc/guc.c 23 Feb 2004 15:04:47 -0000
***************
*** 1496,1501 ****
--- 1496,1511 ----
},
{
+ {"log_line_info", PGC_SIGHUP, LOGGING_WHAT,
+ gettext_noop("Controls extra information on each log line"),
+ gettext_noop("if blank no extra info is logged")
+ },
+ &Log_line_info,
+ "", NULL, NULL
+ },
+
+
+ {
{"DateStyle", PGC_USERSET, CLIENT_CONN_LOCALE,
gettext_noop("Sets the display format for date and time values."),
gettext_noop("Also controls interpretation of ambiguous "
Index: src/backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.106
diff -c -r1.106 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample 17 Feb 2004 03:54:57 -0000 1.106
--- src/backend/utils/misc/postgresql.conf.sample 23 Feb 2004 15:04:48 -0000
***************
*** 185,190 ****
--- 185,195 ----
#log_disconnections = false
#log_duration = false
#log_pid = false
+ #log_line_info = '' # e.g. '<%U%%%D> '
+ # %U=username %D=databasename %C=sessionid
+ # %P=PID %T=timestamp %L=session line number
+ # %S=session start timestamp %I=command tag
+ # %%=%
#log_statement = false
#log_timestamp = false
#log_hostname = false
Index: src/backend/utils/misc/ps_status.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/misc/ps_status.c,v
retrieving revision 1.17
diff -c -r1.17 ps_status.c
*** src/backend/utils/misc/ps_status.c 22 Feb 2004 21:26:55 -0000 1.17
--- src/backend/utils/misc/ps_status.c 23 Feb 2004 15:04:48 -0000
***************
*** 276,285 ****
void
set_ps_display(const char *activity)
{
! #ifndef PS_USE_NONE
/* no ps display for stand-alone backend */
if (!IsUnderPostmaster)
return;
#ifdef PS_USE_CLOBBER_ARGV
/* If ps_buffer is a pointer, it might still be null */
--- 276,291 ----
void
set_ps_display(const char *activity)
{
!
/* no ps display for stand-alone backend */
if (!IsUnderPostmaster)
return;
+
+ /* save it for logging context */
+ if (MyProcPort)
+ MyProcPort->commandTag = activity;
+
+ #ifndef PS_USE_NONE
#ifdef PS_USE_CLOBBER_ARGV
/* If ps_buffer is a pointer, it might still be null */
Index: src/include/miscadmin.h
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/include/miscadmin.h,v
retrieving revision 1.153
diff -c -r1.153 miscadmin.h
*** src/include/miscadmin.h 10 Feb 2004 03:42:45 -0000 1.153
--- src/include/miscadmin.h 23 Feb 2004 15:04:48 -0000
***************
*** 24,29 ****
--- 24,31 ----
#define MISCADMIN_H
+ #include "libpq/libpq-be.h"
+
/*****************************************************************************
* System interrupt and critical section handling
*
Index: src/include/libpq/libpq-be.h
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/include/libpq/libpq-be.h,v
retrieving revision 1.41
diff -c -r1.41 libpq-be.h
*** src/include/libpq/libpq-be.h 21 Feb 2004 06:29:58 -0000 1.41
--- src/include/libpq/libpq-be.h 23 Feb 2004 15:04:48 -0000
***************
*** 50,55 ****
--- 50,56 ----
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 */
Index: src/include/utils/elog.h
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/include/utils/elog.h,v
retrieving revision 1.64
diff -c -r1.64 elog.h
*** src/include/utils/elog.h 29 Nov 2003 22:41:15 -0000 1.64
--- src/include/utils/elog.h 23 Feb 2004 15:04:48 -0000
***************
*** 171,176 ****
--- 171,177 ----
extern PGErrorVerbosity Log_error_verbosity;
extern bool Log_timestamp;
extern bool Log_pid;
+ extern char *Log_line_info;
#ifdef HAVE_SYSLOG
extern int Use_syslog;
I haven't had any other feedback on this patch that I posted. However,
I'm a bit dissatisfied with it for a couple of reasons:
. when a connection is logged we don't yet know the user and database,
because we haven't processed the initial packet yet. That causes %U and
%D to produce empty strings, which looks mildly ugly. I'm inclined in
this case to emit something like "****" or "[unknown]" for these escapes.
. we don't produce any output for postmaster, stats collector etc.
processes. If we really want to get rid of log_pid and log_timestamp
this needs to be dealt with, IMNSHO. We could handle that in a few ways:
- have a separate GUC var (log_line_info_postmaster?) Not much gain
over keeping the existing vars, though
- have a special marker in the string (%X maybe) that says stop
processing for postmaster here.
Example: "%T [%P]:%X %U@%D(%C:%S %I line:%L "
- have a special marker where what follows is the postmaster variant,
defaulting to the beginning if not found.
Examples: "%T [%P]: " (everybody gets timestamp and pid)
"%T [%P]: %U@%D(%C:%S %I line:%L %X%T [%P]:" (same effect
as example under previous point)
- something else I haven't thought of ;-)
Comments welcome
cheers
andrew
Andrew Dunstan wrote:
Show quoted text
Attached is a patch for tagging log lines produced by backends. It is
not quite ready for application - this is for people to look over and
play with.For my testing I used the following settings:
log_connections = true
log_disconnections = true
log_line_info = '%T [%P] %U@%D(%C:%S) %I line:%L '
log_statement = true
log_hostname = true
log_source_port = trueComments welcome
(Rod Taylor has suggested adding in escapes for remote host and remote
port. This can be done easily enough - I want to call a halt at some
stage and get the basics of this in. Extending it will then be easy).
Andrew Dunstan wrote:
Attached is a patch for tagging log lines produced by backends. It is
not quite ready for application - this is for people to look over and
play with.For my testing I used the following settings:
log_connections = true
log_disconnections = true
log_line_info = '%T [%P] %U@%D(%C:%S) %I line:%L '
log_statement = true
log_hostname = true
log_source_port = trueComments welcome
(Rod Taylor has suggested adding in escapes for remote host and remote port. This can be done easily enough - I want to call a halt at some stage and get the basics of this in. Extending it will then be easy). #log_disconnections = false #log_duration = false #log_pid = false + #log_line_info = '' # e.g. '<%U%%%D> ' + # %U=username %D=databasename %C=sessionid + # %P=PID %T=timestamp %L=session line number + # %S=session start timestamp %I=command tag + # %%=% #log_statement = false
Nice. Only two comments --- does this mean we should remove log_pid?
Seems it is now duplicate functionality. Is that the only duplication?
Also, I don't see any documention changes in the patch, but I assume you
will work on that before final.
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 359-1001
+ If your life is a hard drive, | 13 Roberts Road
+ Christ can be your backup. | Newtown Square, Pennsylvania 19073Bruce Momjian wrote:
Andrew Dunstan wrote:
Attached is a patch for tagging log lines produced by backends. It is
not quite ready for application - this is for people to look over and
play with.For my testing I used the following settings:
log_connections = true
log_disconnections = true
log_line_info = '%T [%P] %U@%D(%C:%S) %I line:%L '
log_statement = true
log_hostname = true
log_source_port = trueComments welcome
(Rod Taylor has suggested adding in escapes for remote host and remote port. This can be done easily enough - I want to call a halt at some stage and get the basics of this in. Extending it will then be easy). #log_disconnections = false #log_duration = false #log_pid = false + #log_line_info = '' # e.g. '<%U%%%D> ' + # %U=username %D=databasename %C=sessionid + # %P=PID %T=timestamp %L=session line number + # %S=session start timestamp %I=command tag + # %%=% #log_statement = falseNice. Only two comments --- does this mean we should remove log_pid?
Seems it is now duplicate functionality. Is that the only duplication?
Also, I don't see any documention changes in the patch, but I assume you
will work on that before final.
I will do docs. We could sensibly get rid of log_pid and log_timestamp
with my latest patch. I would also suggest getting rid of
log_source_port, since there really isn't any reason *not* to log the
source port. Do you want me to make those changes in my patch? Or I can
leave them for now and we can get rid of them when everyone is happy.
cheers
andrew
Andrew Dunstan wrote:
Nice. Only two comments --- does this mean we should remove log_pid?
Seems it is now duplicate functionality. Is that the only duplication?
Also, I don't see any documention changes in the patch, but I assume you
will work on that before final.I will do docs. We could sensibly get rid of log_pid and log_timestamp
with my latest patch. I would also suggest getting rid of
log_source_port, since there really isn't any reason *not* to log the
source port. Do you want me to make those changes in my patch? Or I can
leave them for now and we can get rid of them when everyone is happy.
I agree, but let's make it a separate patch.
Oh, I think we still need log_timestamp for postmaster-generated lines,
no? What does log_line_info output for postmaster-generated logs?
Also, should we call the option just log_line? Is that clearer, or
log_line_prefix?
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 359-1001
+ If your life is a hard drive, | 13 Roberts Road
+ Christ can be your backup. | Newtown Square, Pennsylvania 19073Bruce Momjian wrote:
Andrew Dunstan wrote:
Nice. Only two comments --- does this mean we should remove log_pid?
Seems it is now duplicate functionality. Is that the only duplication?
Also, I don't see any documention changes in the patch, but I assume you
will work on that before final.I will do docs. We could sensibly get rid of log_pid and log_timestamp
with my latest patch. I would also suggest getting rid of
log_source_port, since there really isn't any reason *not* to log the
source port. Do you want me to make those changes in my patch? Or I can
leave them for now and we can get rid of them when everyone is happy.I agree, but let's make it a separate patch.
Oh, I think we still need log_timestamp for postmaster-generated lines,
no? What does log_line_info output for postmaster-generated logs?
I have fixed the postmaster lines issue. There is a new escape %X that
says "postmaster and friends stop here".
Example, with log_timestamp = false and log_pid = false and
log_line_info = '%T [%P] %X %U@%D(%C:%S) %R %I line:%L ' :
2004-02-28 20:24:49 [11154] LOG: database system was shut down at
2004-02-28 20:24:20 EST
2004-02-28 20:24:49 [11154] LOG: checkpoint record is at 0/9D1874
2004-02-28 20:24:49 [11154] LOG: redo record is at 0/9D1874; undo
record is at 0/0; shutdown TRUE
2004-02-28 20:24:49 [11154] LOG: next transaction ID: 467; next OID: 17145
2004-02-28 20:24:49 [11154] LOG: database system is ready
2004-02-28 20:25:30 [11158]
[unknown]@[unknown](40413f8a.2b96:2004-02-28 20:25:30) line:1 LOG:
connection received: host=alphonso port=45621
2004-02-28 20:25:30 [11158] andrew@blurflx(40413f8a.2b96:2004-02-28
20:25:30) alphonso:45621 authentication line:2 LOG: connection
authorized: user=andrew database=blurflx
2004-02-28 20:25:34 [11158] andrew@blurflx(40413f8a.2b96:2004-02-28
20:25:30) alphonso:45621 idle line:3 LOG: statement: SELECT n.nspname
as "Schema",
c.relname as "Name",
CASE c.relkind WHEN 'r' THEN 'table' WHEN 'v' THEN 'view' WHEN
'i' THEN 'index' WHEN 'S' THEN 'sequence' WHEN 's' THEN 'special' END as
"Type",
u.usename as "Owner",
c2.relname as "Table"
FROM pg_catalog.pg_class c
JOIN pg_catalog.pg_index i ON i.indexrelid = c.oid
JOIN pg_catalog.pg_class c2 ON i.indrelid = c2.oid
LEFT JOIN pg_catalog.pg_user u ON u.usesysid = c.relowner
LEFT JOIN pg_catalog.pg_namespace n ON n.oid = c.relnamespace
WHERE c.relkind IN ('i','')
AND n.nspname NOT IN ('pg_catalog', 'pg_toast')
AND pg_catalog.pg_table_is_visible(c.oid)
ORDER BY 1,2;
2004-02-28 20:25:38 [11158] andrew@blurflx(40413f8a.2b96:2004-02-28
20:25:30) alphonso:45621 idle line:4 LOG: disconnection: session time:
0:00:08.50 user=andrew database=blurflx host=alphonso:45621
2004-02-28 20:25:44 [11149] LOG: received smart shutdown request
2004-02-28 20:25:44 [11170] LOG: shutting down
2004-02-28 20:25:46 [11170] LOG: database system is shut down
Also, should we call the option just log_line? Is that clearer, or
log_line_prefix?
I floated the name log_line_info a while back and noone objected. I
don't think "log_line" is any clearer - quite the contrary IMNSHO.
cheers
andrew
Andrew Dunstan wrote:
I will do docs. We could sensibly get rid of log_pid and
log_timestamp with my latest patch. I would also suggest getting rid
of log_source_port, since there really isn't any reason *not* to log
the source port.
There is the very definite possibility that people don't care.
Andrew Dunstan wrote:
Attached is a patch for tagging log lines produced by backends. It is
not quite ready for application - this is for people to look over and
play with.For my testing I used the following settings:
log_connections = true
log_disconnections = true
log_line_info = '%T [%P] %U@%D(%C:%S) %I line:%L '
log_statement = true
log_hostname = true
log_source_port = trueComments welcome
I'm wondering, why did you choose to use capital letters, when normally
the % codes are lower-case letters when possible? I think lower-case
letters are easier to read.
Peter Eisentraut wrote:
Andrew Dunstan wrote:
Attached is a patch for tagging log lines produced by backends. It is
not quite ready for application - this is for people to look over and
play with.For my testing I used the following settings:
log_connections = true
log_disconnections = true
log_line_info = '%T [%P] %U@%D(%C:%S) %I line:%L '
log_statement = true
log_hostname = true
log_source_port = trueComments welcome
I'm wondering, why did you choose to use capital letters, when normally
the % codes are lower-case letters when possible? I think lower-case
letters are easier to read.
I did it to differentiate them from standard printf escapes. I don't
feel strongly about it, though. I'm currently prepping a final patch and
docs, so I'd be grateful for an early consensus on this.
cheers
andrew
Peter Eisentraut wrote:
Andrew Dunstan wrote:
I will do docs. We could sensibly get rid of log_pid and
log_timestamp with my latest patch. I would also suggest getting rid
of log_source_port, since there really isn't any reason *not* to log
the source port.There is the very definite possibility that people don't care.
The only thing I can see where it actually makes a difference is in the
ps display (and it is currently a bit broken anyway, as it uses
"host:port" there, which won't work nicely with IP6 addresses).
Connection and disconnection logging currently always log the source
port, regardless of the setting.
If you think the ability to have it in or out of the ps display is
important enough, we can certainly leave it in - either way I will fix it.
cheers
andrew
Andrew Dunstan wrote:
I haven't had any other feedback on this patch that I posted. However,
I'm a bit dissatisfied with it for a couple of reasons:. when a connection is logged we don't yet know the user and database,
because we haven't processed the initial packet yet. That causes %U and
%D to produce empty strings, which looks mildly ugly. I'm inclined in
this case to emit something like "****" or "[unknown]" for these escapes.. we don't produce any output for postmaster, stats collector etc.
processes. If we really want to get rid of log_pid and log_timestamp
this needs to be dealt with, IMNSHO. We could handle that in a few ways:
- have a separate GUC var (log_line_info_postmaster?) Not much gain
over keeping the existing vars, though
- have a special marker in the string (%X maybe) that says stop
processing for postmaster here.
Example: "%T [%P]:%X %U@%D(%C:%S %I line:%L "
- have a special marker where what follows is the postmaster variant,
defaulting to the beginning if not found.
Examples: "%T [%P]: " (everybody gets timestamp and pid)
"%T [%P]: %U@%D(%C:%S %I line:%L %X%T [%P]:" (same effect
as example under previous point)
- something else I haven't thought of ;-)
Seems the cleanest would be to just print nothing for items that have no
meaning for the postmaster.
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 359-1001
+ If your life is a hard drive, | 13 Roberts Road
+ Christ can be your backup. | Newtown Square, Pennsylvania 19073Bruce Momjian said:
Andrew Dunstan wrote:
I haven't had any other feedback on this patch that I posted. However,
I'm a bit dissatisfied with it for a couple of reasons:. when a connection is logged we don't yet know the user and database,
because we haven't processed the initial packet yet. That causes %U
and %D to produce empty strings, which looks mildly ugly. I'm
inclined in this case to emit something like "****" or "[unknown]"
for these escapes.. we don't produce any output for postmaster, stats collector etc.
processes. If we really want to get rid of log_pid and log_timestamp
this needs to be dealt with, IMNSHO. We could handle that in a few
ways:
- have a separate GUC var (log_line_info_postmaster?) Not much gain
over keeping the existing vars, though
- have a special marker in the string (%X maybe) that says stop
processing for postmaster here.
Example: "%T [%P]:%X %U@%D(%C:%S %I line:%L "
- have a special marker where what follows is the postmaster
variant,
defaulting to the beginning if not found.
Examples: "%T [%P]: " (everybody gets timestamp and pid)
"%T [%P]: %U@%D(%C:%S %I line:%L %X%T [%P]:" (same
effect
as example under previous point)
- something else I haven't thought of ;-)Seems the cleanest would be to just print nothing for items that have
no meaning for the postmaster.
Not quite clean enough - I also want to be able to supress irrelevant
literal characters. See the actual patch sent in on Feb 29th at
http://archives.postgresql.org/pgsql-patches/2004-02/msg00266.php where I
used the first variant I suggested above.
cheers
andrew
Andrew Dunstan wrote:
defaulting to the beginning if not found.
Examples: "%T [%P]: " (everybody gets timestamp and pid)
"%T [%P]: %U@%D(%C:%S %I line:%L %X%T [%P]:" (same
effect
as example under previous point)
- something else I haven't thought of ;-)Seems the cleanest would be to just print nothing for items that have
no meaning for the postmaster.Not quite clean enough - I also want to be able to supress irrelevant
literal characters. See the actual patch sent in on Feb 29th at
http://archives.postgresql.org/pgsql-patches/2004-02/msg00266.php where I
used the first variant I suggested above.
Yes, I understand there is no way to know if the literal characters are
supposed to print for postmaster message, but is seems easier to just
print them than to do the more complicated options you propose. One
idea would be to suppress whitespace or perhaps special characters
_after_ an option that is skipped --- not perfect, but this is only log
output. Of course, if you do <%option>, you get the leading < but not
the >. Maybe just go with suppressing trailing whitespace of a skipped
option is best.
Also, I think you should switch to lowercase like Peter suggested. You
aren't supporting any of the printf() letters, so you might as well use
lowercase.
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 359-1001
+ If your life is a hard drive, | 13 Roberts Road
+ Christ can be your backup. | Newtown Square, Pennsylvania 19073