From 74ffc77279d092eb9e31c5e13a015173fca7addb Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Fri, 19 Mar 2004 02:23:59 +0000 Subject: [PATCH] Code review for log_line_prefix patch. Cooperate with StringInfo instead of fighting it, avoid hard-wired (and wrong) assumption about max length of prefix, cause %l to actually work as documented, don't compute data we may not need. --- src/backend/utils/error/elog.c | 267 +++++++++++++++-------------- src/backend/utils/misc/ps_status.c | 13 +- src/include/libpq/libpq-be.h | 12 +- 3 files changed, 151 insertions(+), 141 deletions(-) diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index f62bcd8ff3..e826e6d99e 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -37,7 +37,7 @@ * * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.128 2004/03/15 15:56:23 momjian Exp $ + * $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.129 2004/03/19 02:23:59 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -69,7 +69,7 @@ ErrorContextCallback *error_context_stack = NULL; /* GUC parameters */ PGErrorVerbosity Log_error_verbosity = PGERROR_VERBOSE; -char *Log_line_prefix = ""; /* format for extra log line info */ +char *Log_line_prefix = NULL; /* format for extra log line info */ #ifdef HAVE_SYSLOG /* @@ -136,13 +136,14 @@ static int recursion_depth = 0; /* to detect actual recursion */ } while (0) +static void log_line_prefix(StringInfo buf); static void send_message_to_server_log(ErrorData *edata); static void send_message_to_frontend(ErrorData *edata); static char *expand_fmt_string(const char *fmt, ErrorData *edata); static const char *useful_strerror(int errnum); static const char *error_severity(int elevel); static void append_with_tabs(StringInfo buf, const char *str); -static const char *log_line_prefix(void); + /* * errstart --- begin an error-reporting cycle @@ -1019,135 +1020,139 @@ write_syslog(int level, const char *line) #endif /* HAVE_SYSLOG */ /* - * Format tag info for log lines + * Format tag info for log lines; append to the provided buffer. */ -static const char * -log_line_prefix(void) +static void +log_line_prefix(StringInfo buf) { + /* static counter for line numbers */ + static long log_line_number = 0; + /* has counter been reset in current process? */ + static int log_my_pid = 0; - /* 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_prefix); - int result_len = 2*NAMEDATALEN + format_len +120 ; + int format_len; + int i; - if (result == NULL) - result = malloc(result_len); - result[0] = '\0'; - - if (format_len > 0) + /* + * This is one of the few places where we'd rather not inherit a + * static variable's value from the postmaster. But since we will, + * reset it when MyProcPid changes. + */ + if (log_my_pid != MyProcPid) { - int i,j; - char * dbname = NULL; - char * username = NULL; - time_t stamp_time; - log_line_number++; - if (MyProcPort != NULL) + log_line_number = 0; + log_my_pid = MyProcPid; + } + log_line_number++; + + 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++) + { + if (Log_line_prefix[i] != '%') { - dbname = MyProcPort->database_name; - username = MyProcPort->user_name; - if (dbname == NULL || *dbname == '\0') - dbname = gettext("[unknown]"); - if (username == NULL || *username == '\0') - username = gettext("[unknown]"); + /* literal char, just copy */ + appendStringInfoChar(buf, Log_line_prefix[i]); + continue; + } + /* go to char after '%' */ + i++; + if (i >= format_len) + { + /* format error - ignore it */ + break; } - /* - * 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++) + /* process the option */ + switch (Log_line_prefix[i]) { - if(Log_line_prefix[i] != '%') - { - /* literal char, just copy */ - result[j]=Log_line_prefix[i]; - j++; - result[j] = '\0'; - continue; - } - else if (i == format_len - 1) - { - /* format error - skip it */ - continue; - } + case 'u': + if (MyProcPort) + { + const char *username = MyProcPort->user_name; - /* go to char after '%' */ - i++; + if (username == NULL || *username == '\0') + username = gettext("[unknown]"); + appendStringInfo(buf, "%s", username); + } + break; + case 'd': + if (MyProcPort) + { + const char *dbname = MyProcPort->database_name; - /* in postmaster and friends, skip non-applicable options, - * stop if %x is seen - */ - if (MyProcPort == NULL) - { - if (Log_line_prefix[i] == 'x') - break; - if (strchr("udcsir",Log_line_prefix[i]) != NULL) - continue; - } + if (dbname == NULL || *dbname == '\0') + dbname = gettext("[unknown]"); + appendStringInfo(buf, "%s", dbname); + } + break; + case 'c': + if (MyProcPort) + { + appendStringInfo(buf, "%lx.%lx", + (long)(MyProcPort->session_start.tv_sec), + (long)MyProcPid); + } + break; + case 'p': + appendStringInfo(buf, "%ld", (long)MyProcPid); + break; + case 'l': + appendStringInfo(buf, "%ld", log_line_number); + break; + case 't': + { + time_t stamp_time = time(NULL); + char strfbuf[32]; - /* process the option */ - switch (Log_line_prefix[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", + strftime(strfbuf, sizeof(strfbuf), "%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 'r': - j += snprintf(result+j,result_len-j,"%s", - MyProcPort->remote_host); + appendStringInfoString(buf, strfbuf); + } + break; + case 's': + if (MyProcPort) + { + time_t stamp_time = MyProcPort->session_start.tv_sec; + char strfbuf[32]; + + strftime(strfbuf, sizeof(strfbuf), "%Y-%m-%d %H:%M:%S", + localtime(&stamp_time)); + appendStringInfoString(buf, strfbuf); + } + break; + case 'i': + if (MyProcPort) + { + appendStringInfo(buf, "%s", MyProcPort->commandTag); + } + break; + case 'r': + if (MyProcPort) + { + appendStringInfo(buf, "%s", MyProcPort->remote_host); if (strlen(MyProcPort->remote_port) > 0) - j += snprintf(result+j,result_len-j,"(%s)", - MyProcPort->remote_port); - break; - case 'x': - /* non-postmaster case - just ignore */ - break; - case '%': - result[j] = '%'; - j++; - result[j] = '\0'; - break; - default: - /* format error - skip it */ - break; - } + appendStringInfo(buf, "(%s)", + MyProcPort->remote_port); + } + break; + case 'x': + /* in postmaster and friends, stop if %x is seen */ + /* in a backend, just ignore */ + if (MyProcPort == NULL) + i = format_len; + break; + case '%': + appendStringInfoChar(buf, '%'); + break; + default: + /* format error - ignore it */ + break; } } - return result; } @@ -1161,8 +1166,8 @@ send_message_to_server_log(ErrorData *edata) initStringInfo(&buf); - appendStringInfo(&buf, "%s%s: ", - log_line_prefix(), error_severity(edata->elevel)); + log_line_prefix(&buf); + appendStringInfo(&buf, "%s: ", error_severity(edata->elevel)); if (Log_error_verbosity >= PGERROR_VERBOSE) { @@ -1195,21 +1200,21 @@ send_message_to_server_log(ErrorData *edata) { if (edata->detail) { - appendStringInfoString(&buf, log_line_prefix() ); + log_line_prefix(&buf); appendStringInfoString(&buf, gettext("DETAIL: ")); append_with_tabs(&buf, edata->detail); appendStringInfoChar(&buf, '\n'); } if (edata->hint) { - appendStringInfoString(&buf, log_line_prefix() ); + log_line_prefix(&buf); appendStringInfoString(&buf, gettext("HINT: ")); append_with_tabs(&buf, edata->hint); appendStringInfoChar(&buf, '\n'); } if (edata->context) { - appendStringInfoString(&buf, log_line_prefix() ); + log_line_prefix(&buf); appendStringInfoString(&buf, gettext("CONTEXT: ")); append_with_tabs(&buf, edata->context); appendStringInfoChar(&buf, '\n'); @@ -1218,14 +1223,18 @@ send_message_to_server_log(ErrorData *edata) { /* assume no newlines in funcname or filename... */ if (edata->funcname && edata->filename) - appendStringInfo(&buf, gettext("%sLOCATION: %s, %s:%d\n"), - log_line_prefix(), + { + log_line_prefix(&buf); + appendStringInfo(&buf, gettext("LOCATION: %s, %s:%d\n"), edata->funcname, edata->filename, edata->lineno); + } else if (edata->filename) - appendStringInfo(&buf, gettext("%sLOCATION: %s:%d\n"), - log_line_prefix(), + { + log_line_prefix(&buf); + appendStringInfo(&buf, gettext("LOCATION: %s:%d\n"), edata->filename, edata->lineno); + } } } @@ -1234,7 +1243,7 @@ send_message_to_server_log(ErrorData *edata) */ if (edata->elevel >= log_min_error_statement && debug_query_string != NULL) { - appendStringInfoString(&buf, log_line_prefix() ); + log_line_prefix(&buf); appendStringInfoString(&buf, gettext("STATEMENT: ")); append_with_tabs(&buf, debug_query_string); appendStringInfoChar(&buf, '\n'); @@ -1284,11 +1293,7 @@ send_message_to_server_log(ErrorData *edata) /* Write to stderr, if enabled */ if (Use_syslog <= 1 || whereToSendOutput == Debug) { - /* - * Timestamp and PID are only used for stderr output --- we assume - * the syslog daemon will supply them for us in the other case. - */ - fprintf(stderr, "%s",buf.data); + fprintf(stderr, "%s", buf.data); } pfree(buf.data); diff --git a/src/backend/utils/misc/ps_status.c b/src/backend/utils/misc/ps_status.c index 770882cc8e..aa3f2fe199 100644 --- a/src/backend/utils/misc/ps_status.c +++ b/src/backend/utils/misc/ps_status.c @@ -5,7 +5,7 @@ * to contain some useful information. Mechanism differs wildly across * platforms. * - * $PostgreSQL: pgsql/src/backend/utils/misc/ps_status.c,v 1.18 2004/03/09 04:43:07 momjian Exp $ + * $PostgreSQL: pgsql/src/backend/utils/misc/ps_status.c,v 1.19 2004/03/19 02:23:59 tgl Exp $ * * Copyright (c) 2000-2003, PostgreSQL Global Development Group * various details abducted from various places @@ -277,16 +277,15 @@ init_ps_display(const char *username, const char *dbname, void set_ps_display(const char *activity) { + /* save tag for possible use by elog.c */ + if (MyProcPort) + MyProcPort->commandTag = activity; + +#ifndef PS_USE_NONE /* no ps display for stand-alone backend */ if (!IsUnderPostmaster) return; - /* save it for logging context */ - if (MyProcPort) - MyProcPort->commandTag = (char *) activity; - -#ifndef PS_USE_NONE - #ifdef PS_USE_CLOBBER_ARGV /* If ps_buffer is a pointer, it might still be null */ if (!ps_buffer) diff --git a/src/include/libpq/libpq-be.h b/src/include/libpq/libpq-be.h index a077913a11..3200042dae 100644 --- a/src/include/libpq/libpq-be.h +++ b/src/include/libpq/libpq-be.h @@ -11,7 +11,7 @@ * Portions Copyright (c) 1996-2003, PostgreSQL Global Development Group * Portions Copyright (c) 1994, Regents of the University of California * - * $PostgreSQL: pgsql/src/include/libpq/libpq-be.h,v 1.42 2004/03/09 04:43:07 momjian Exp $ + * $PostgreSQL: pgsql/src/include/libpq/libpq-be.h,v 1.43 2004/03/19 02:23:59 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -50,8 +50,6 @@ typedef struct Port 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 */ /* @@ -73,6 +71,14 @@ typedef struct Port char md5Salt[4]; /* Password salt */ char cryptSalt[2]; /* Password salt */ + /* + * Information that really has no business at all being in struct Port, + * but since it gets used by elog.c in the same way as database_name + * and other members of this struct, we may as well keep it here. + */ + const char *commandTag; /* current command tag */ + struct timeval session_start; /* for session duration logging */ + /* * SSL structures */