The attached patch does 3 things:
. logs connection ends if log_connections = true
. provides a new option "log_line_format" which allows addition of extra information on a log line before the keyword. Currently supported are user name and database name, but it is easily extensible. The string is in the flavor of a printf format, where "%U" means user name, "%D" means database name, "%%" means "%" and anything else means itself, literally.
. minor code cleanup for consistency in calling gettimeofday().
cheers
andrew
Index: backend/commands/vacuum.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/commands/vacuum.c,v
retrieving revision 1.259
diff -c -w -r1.259 vacuum.c
*** backend/commands/vacuum.c 4 Aug 2003 02:39:58 -0000 1.259
--- backend/commands/vacuum.c 9 Aug 2003 21:17:11 -0000
***************
*** 3109,3118 ****
void
vac_init_rusage(VacRUsage *ru0)
{
- struct timezone tz;
-
getrusage(RUSAGE_SELF, &ru0->ru);
! gettimeofday(&ru0->tv, &tz);
}
/*
--- 3109,3116 ----
void
vac_init_rusage(VacRUsage *ru0)
{
getrusage(RUSAGE_SELF, &ru0->ru);
! gettimeofday(&ru0->tv, NULL);
}
/*
Index: backend/postmaster/postmaster.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/postmaster/postmaster.c,v
retrieving revision 1.340
diff -c -w -r1.340 postmaster.c
*** backend/postmaster/postmaster.c 4 Aug 2003 02:40:02 -0000 1.340
--- backend/postmaster/postmaster.c 9 Aug 2003 21:17:13 -0000
***************
*** 995,1004 ****
int nSockets;
struct timeval now,
later;
- struct timezone tz;
int i;
! gettimeofday(&now, &tz);
nSockets = initMasks(&readmask);
--- 995,1003 ----
int nSockets;
struct timeval now,
later;
int i;
! gettimeofday(&now, NULL);
nSockets = initMasks(&readmask);
***************
*** 1080,1086 ****
*/
while (random_seed == 0)
{
! gettimeofday(&later, &tz);
/*
* We are not sure how much precision is in tv_usec, so we
--- 1079,1085 ----
*/
while (random_seed == 0)
{
! gettimeofday(&later, NULL);
/*
* We are not sure how much precision is in tv_usec, so we
***************
*** 2302,2308 ****
int i;
int status;
struct timeval now;
- struct timezone tz;
char remote_host[NI_MAXHOST];
char remote_port[NI_MAXSERV];
--- 2301,2306 ----
***************
*** 2324,2332 ****
/* Close the postmaster's other sockets */
ClosePostmasterPorts(true);
- /* Save port etc. for ps status */
- MyProcPort = port;
-
/* Reset MyProcPid to new backend's pid */
MyProcPid = getpid();
--- 2322,2327 ----
***************
*** 2398,2403 ****
--- 2393,2405 ----
elog(FATAL, "could not set timer for authorization timeout");
/*
+ * Save port etc. for ps status
+ * do this after we log connections or auth failures so that we don't use
+ * the format line before the details are filled in
+ */
+ MyProcPort = port;
+
+ /*
* Receive the startup packet (which might turn out to be a cancel
* request packet).
*/
***************
*** 2438,2444 ****
* start a new random sequence in the random() library function.
*/
random_seed = 0;
! gettimeofday(&now, &tz);
srandom((unsigned int) now.tv_usec);
/* ----------------
--- 2440,2446 ----
* start a new random sequence in the random() library function.
*/
random_seed = 0;
! gettimeofday(&now, NULL);
srandom((unsigned int) now.tv_usec);
/* ----------------
***************
*** 2521,2526 ****
--- 2523,2536 ----
MemoryContextSwitchTo(TopMemoryContext);
MemoryContextDelete(PostmasterContext);
PostmasterContext = NULL;
+
+ /*
+ * set up remaining members of port stucture while in the
+ * TopMemoryContext
+ */
+ port->remote_host = pstrdup(remote_host);
+ port->remote_port = pstrdup(remote_port);
+ gettimeofday(&(port->session_start),NULL);
/*
* Debug: print arguments being passed to backend
Index: backend/tcop/postgres.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/tcop/postgres.c,v
retrieving revision 1.357
diff -c -w -r1.357 postgres.c
*** backend/tcop/postgres.c 6 Aug 2003 17:46:45 -0000 1.357
--- backend/tcop/postgres.c 9 Aug 2003 21:17:13 -0000
***************
*** 68,73 ****
--- 68,74 ----
extern int optind;
extern char *optarg;
+ extern bool Log_connections;
/* ----------------
* global variables
***************
*** 150,155 ****
--- 151,157 ----
static void finish_xact_command(void);
static void SigHupHandler(SIGNAL_ARGS);
static void FloatExceptionHandler(SIGNAL_ARGS);
+ static void log_session_end(void);
/* ----------------------------------------------------------------
***************
*** 2453,2458 ****
--- 2455,2465 ----
gucopts = lnext(gucopts);
SetConfigOption(name, value, PGC_BACKEND, PGC_S_CLIENT);
}
+ /*
+ * set up handler to log session end.
+ */
+ if (IsUnderPostmaster && Log_connections)
+ on_proc_exit(log_session_end,0);
}
/*
***************
*** 3190,3193 ****
--- 3197,3243 ----
errdetail("%s", str.data)));
pfree(str.data);
+ }
+
+
+ /*
+ * on_proc_exit handler to log end of session
+ */
+ static void
+ log_session_end(void)
+ {
+ Port * port = MyProcPort;
+ struct timeval end;
+ int hours, minutes, seconds;
+
+ char session_time[20];
+ char uname[6+NAMEDATALEN];
+ char dbname[10+NAMEDATALEN];
+
+ snprintf(uname, sizeof(uname)," user=%s",port->user_name);
+ snprintf(dbname, sizeof(dbname)," database=%s",port->database_name);
+
+
+ gettimeofday(&end,NULL);
+ if (end.tv_usec < port->session_start.tv_usec)
+ {
+ end.tv_sec--;
+ end.tv_usec += 1000000;
+ }
+ end.tv_sec -= port->session_start.tv_sec;
+ end.tv_usec -= port->session_start.tv_usec;
+
+ hours = end.tv_sec / 3600;
+ end.tv_sec %= 3600;
+ minutes = end.tv_sec / 60;
+ seconds = end.tv_sec % 60;
+
+ snprintf(session_time, sizeof(session_time),"%d:%02d:%02d.%02ld",
+ hours, minutes, seconds,
+ end.tv_usec/10000);
+
+ ereport(LOG,
+ (errmsg("session ended: duration: %s%s%s",
+ session_time,uname,dbname)));
+
}
Index: backend/utils/adt/nabstime.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/adt/nabstime.c,v
retrieving revision 1.113
diff -c -w -r1.113 nabstime.c
*** backend/utils/adt/nabstime.c 4 Aug 2003 02:40:05 -0000 1.113
--- backend/utils/adt/nabstime.c 9 Aug 2003 21:17:13 -0000
***************
*** 1745,1757 ****
timeofday(PG_FUNCTION_ARGS)
{
struct timeval tp;
- struct timezone tpz;
char templ[100];
char buf[100];
text *result;
int len;
! gettimeofday(&tp, &tpz);
strftime(templ, sizeof(templ), "%a %b %d %H:%M:%S.%%06d %Y %Z",
localtime((time_t *) &tp.tv_sec));
snprintf(buf, sizeof(buf), templ, tp.tv_usec);
--- 1745,1756 ----
timeofday(PG_FUNCTION_ARGS)
{
struct timeval tp;
char templ[100];
char buf[100];
text *result;
int len;
! gettimeofday(&tp, NULL);
strftime(templ, sizeof(templ), "%a %b %d %H:%M:%S.%%06d %Y %Z",
localtime((time_t *) &tp.tv_sec));
snprintf(buf, sizeof(buf), templ, tp.tv_usec);
Index: backend/utils/error/elog.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/error/elog.c,v
retrieving revision 1.119
diff -c -w -r1.119 elog.c
*** backend/utils/error/elog.c 8 Aug 2003 21:42:11 -0000 1.119
--- backend/utils/error/elog.c 9 Aug 2003 21:17:14 -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_format_str = ""; /* format for extra log line info */
#ifdef HAVE_SYSLOG
/*
***************
*** 145,150 ****
--- 146,152 ----
static const char *error_severity(int elevel);
static const char *print_timestamp(void);
static const char *print_pid(void);
+ static const char *log_line_extra(void);
/*
***************
*** 1019,1024 ****
--- 1021,1089 ----
}
#endif /* HAVE_SYSLOG */
+ /*
+ * Formatted extra info for log if option is set and we have a data,
+ * or empty string otherwise.
+ */
+ static const char *
+ log_line_extra(void)
+ {
+ /* space for option string + 2 identifiers */
+ /* Note: if more identifers are built in this will have to increase */
+ static char *result = NULL;
+ int flen = strlen(Log_line_format_str);
+ int i,j;
+ int tlen = 2*NAMEDATALEN + flen +3 ;
+ if (result == NULL)
+ result = malloc(tlen);
+ result[0] = '\0';
+
+ if (flen > 0 && MyProcPort)
+ {
+ char * dbname = MyProcPort->database_name;
+ char * username = MyProcPort->user_name;
+ if (dbname == NULL)
+ dbname="";
+ if (username == NULL)
+ username = "";
+ j = 0;
+ for (i = 0; i < flen && j < tlen-1; i++)
+ {
+ if(Log_line_format_str[i] != '%')
+ {
+ result[j]=Log_line_format_str[i];
+ j++;
+ result[j] = '\0';
+ continue;
+ }
+ else if (i == flen - 1)
+ {
+ /* format error - just skip it */
+ continue;
+ }
+ i++;
+ switch (Log_line_format_str[i])
+ {
+ case 'U':
+ j += snprintf(result+j,tlen-j,"%s",username);
+ break;
+ case 'D':
+ j += snprintf(result+j,tlen-j,"%s",dbname);
+ break;
+ case '%':
+ result[j] = '%';
+ j++;
+ result[j] = '\0';
+ break;
+ default:
+ /* format error - skip it */
+ break;
+ }
+ }
+ }
+ return result;
+ }
+
/*
* Write error report to server's log
***************
*** 1028,1036 ****
{
StringInfoData buf;
initStringInfo(&buf);
! appendStringInfo(&buf, "%s: ", error_severity(edata->elevel));
if (Log_error_verbosity >= PGERROR_VERBOSE)
{
--- 1093,1105 ----
{
StringInfoData buf;
+ const char *extra_info = log_line_extra();
+
initStringInfo(&buf);
! appendStringInfo(&buf, "%s%s: ",
! extra_info,
! error_severity(edata->elevel));
if (Log_error_verbosity >= PGERROR_VERBOSE)
{
***************
*** 1062,1080 ****
if (Log_error_verbosity >= PGERROR_DEFAULT)
{
if (edata->detail)
! appendStringInfo(&buf, gettext("DETAIL: %s\n"),
edata->detail);
if (edata->hint)
! appendStringInfo(&buf, gettext("HINT: %s\n"), edata->hint);
if (edata->context)
! appendStringInfo(&buf, gettext("CONTEXT: %s\n"),
edata->context);
if (Log_error_verbosity >= PGERROR_VERBOSE)
{
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);
}
}
--- 1131,1157 ----
if (Log_error_verbosity >= PGERROR_DEFAULT)
{
if (edata->detail)
! appendStringInfo(&buf, gettext("%sDETAIL: %s\n"),
! extra_info,
! edata->detail);
if (edata->hint)
! appendStringInfo(&buf, gettext("%sHINT: %s\n"),
! extra_info,
! edata->hint);
if (edata->context)
! appendStringInfo(&buf, gettext("%sCONTEXT: %s\n"),
! extra_info,
! edata->context);
if (Log_error_verbosity >= PGERROR_VERBOSE)
{
if (edata->funcname && edata->filename)
! appendStringInfo(&buf, gettext("%sLOCATION: %s,
%s:%d\n"),
! extra_info,
edata->funcname,
edata->filename,
edata->lineno);
else if (edata->filename)
! appendStringInfo(&buf, gettext("%sLOCATION: %s:%d\n"),
! extra_info,
edata->filename,
edata->lineno);
}
}
***************
*** 1086,1092 ****
* improve?
*/
if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
! appendStringInfo(&buf, gettext("STATEMENT: %s\n"),
debug_query_string);
--- 1163,1170 ----
* improve?
*/
if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
! appendStringInfo(&buf, gettext("%sSTATEMENT: %s\n"),
! extra_info,
debug_query_string);
Index: backend/utils/misc/guc.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.148
diff -c -w -r1.148 guc.c
*** backend/utils/misc/guc.c 4 Aug 2003 23:59:39 -0000 1.148
--- backend/utils/misc/guc.c 9 Aug 2003 21:17:15 -0000
***************
*** 1334,1339 ****
--- 1334,1348 ----
},
&log_min_error_statement_str,
"panic", assign_min_error_statement, NULL
+ },
+
+ {
+ {"log_line_format", PGC_SIGHUP, LOGGING_WHAT,
+ gettext_noop("Controls extra information on each log line"),
+ gettext_noop("if blank no extra info is logged")
+ },
+ &Log_line_format_str,
+ "", NULL, NULL
},
{
Index: backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file:
/projects/cvsroot/pgsql-server/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.87
diff -c -w -r1.87 postgresql.conf.sample
*** backend/utils/misc/postgresql.conf.sample 29 Jul 2003 00:03:18 -0000 1.87
--- backend/utils/misc/postgresql.conf.sample 9 Aug 2003 21:17:15 -0000
***************
*** 173,178 ****
--- 173,179 ----
#log_connections = false
#log_duration = false
#log_pid = false
+ #log_line_format = '<%U~%D>' # %U=username %D=databasename %%=%
#log_statement = false
#log_timestamp = false
#log_hostname = false
Index: include/libpq/libpq-be.h
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/include/libpq/libpq-be.h,v
retrieving revision 1.37
diff -c -w -r1.37 libpq-be.h
*** include/libpq/libpq-be.h 4 Aug 2003 02:40:13 -0000 1.37
--- include/libpq/libpq-be.h 9 Aug 2003 21:17:15 -0000
***************
*** 42,47 ****
--- 42,50 ----
ProtocolVersion proto; /* FE/BE protocol version */
SockAddr laddr; /* local addr (postmaster) */
SockAddr raddr; /* remote addr (client) */
+ char *remote_host; /* name (or ip addr) of remote host */
+ char *remote_port; /* text rep of remote port */
+ struct timeval session_start; /* for session duration logging */
/*
* Information that needs to be saved from the startup packet and
Index: include/utils/elog.h
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/include/utils/elog.h,v
retrieving revision 1.63
diff -c -w -r1.63 elog.h
*** include/utils/elog.h 8 Aug 2003 21:42:55 -0000 1.63
--- include/utils/elog.h 9 Aug 2003 21:17:15 -0000
***************
*** 171,176 ****
--- 171,177 ----
extern PGErrorVerbosity Log_error_verbosity;
extern bool Log_timestamp;
extern bool Log_pid;
+ extern char *Log_line_format_str;
#ifdef HAVE_SYSLOG
extern int Use_syslog;
---------------------------(end of broadcast)--------------------------- TIP 1: subscribe and unsubscribe commands go to [EMAIL PROTECTED]
