revised patch attached, including docco. I think this attends to all the comments I received.


cheers

andrew


Index: doc/src/sgml/runtime.sgml
===================================================================
RCS file: /projects/cvsroot/pgsql-server/doc/src/sgml/runtime.sgml,v
retrieving revision 1.199
diff -c -w -r1.199 runtime.sgml
*** doc/src/sgml/runtime.sgml   10 Aug 2003 01:20:34 -0000      1.199
--- doc/src/sgml/runtime.sgml   13 Aug 2003 20:59:13 -0000
***************
*** 1801,1806 ****
--- 1801,1820 ----
  
  
       <varlistentry>
+       <term><varname>LOG_SESSION_END</varname> (<type>boolean</type>)</term>
+       <listitem>
+        <para>
+        This outputs a line to the server logs similar to LOG_CONNECTIONS 
+        but at the end of a session, and including the duration of the 
+        session.This is off by default. This option can only be set at 
+        server start or in the <filename>postgresql.conf</filename> 
+        configuration file.
+        </para>
+       </listitem>
+      </varlistentry>
+ 
+ 
+      <varlistentry>
        <term><varname>LOG_DURATION</varname> (<type>boolean</type>)</term>
        <listitem>
         <para>
***************
*** 1825,1830 ****
--- 1839,1876 ----
          the process ID.
         </para>
        </listitem>
+      </varlistentry>
+ 
+      <varlistentry>
+       <term><varname>LOG_LINE_FORMAT</varname> (<type>string</type>)</term>
+       <listitem>
+        <para>
+        Prefixes each message in the server log file or syslog with extra 
+        information as specidied in the string. The default is an empty 
+        string. The following sequences in the string are translated: 
+        <literal>'%U'</literal> is replace with the username, 
+        <literal>'%D'</literal> is replaced by the database name, 
+        and <literal>'%%'</literal> is replaced by <literal>'%'</literal>. 
+        All other characters are copied literally to the log. For example,
+ <programlisting>
+ log_line_format = '&lt;%U%%%D&gt; '
+ </programlisting>
+        will produce output like this:
+ <programlisting>
+ &lt;myuser%mydb&gt; LOG:  query: create table foo(blah text);
+ </programlisting>
+        </para>
+       <para>
+        If <varname>LOG_PID</varname> or <varname>LOG_TIMESTAMP</varname> 
+        are turned on the output from <varname>LOG_LINE_FORMAT</varname>
+        will follow those items but precede any other output on the line.
+       </para>
+       <para>
+        This option can only be set at server start or in the
+         <filename>postgresql.conf</filename> configuration file.
+       </para>
+         
+        </listitem>
       </varlistentry>
  
       <varlistentry>
Index: src/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
*** src/backend/commands/vacuum.c       4 Aug 2003 02:39:58 -0000       1.259
--- src/backend/commands/vacuum.c       13 Aug 2003 20:59:14 -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: src/backend/postmaster/postmaster.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/postmaster/postmaster.c,v
retrieving revision 1.341
diff -c -w -r1.341 postmaster.c
*** src/backend/postmaster/postmaster.c 12 Aug 2003 18:23:20 -0000      1.341
--- src/backend/postmaster/postmaster.c 13 Aug 2003 20:59:15 -0000
***************
*** 1000,1009 ****
        int                     nSockets;
        struct timeval now,
                                later;
-       struct timezone tz;
        int                     i;
  
!       gettimeofday(&now, &tz);
  
        nSockets = initMasks(&readmask);
  
--- 1000,1008 ----
        int                     nSockets;
        struct timeval now,
                                later;
        int                     i;
  
!       gettimeofday(&now, NULL);
  
        nSockets = initMasks(&readmask);
  
***************
*** 1085,1091 ****
                 */
                while (random_seed == 0)
                {
!                       gettimeofday(&later, &tz);
  
                        /*
                         * We are not sure how much precision is in tv_usec, so we
--- 1084,1090 ----
                 */
                while (random_seed == 0)
                {
!                       gettimeofday(&later, NULL);
  
                        /*
                         * We are not sure how much precision is in tv_usec, so we
***************
*** 2320,2326 ****
        int                     i;
        int                     status;
        struct timeval now;
-       struct timezone tz;
        char            remote_host[NI_MAXHOST];
        char            remote_port[NI_MAXSERV];
  
--- 2319,2324 ----
***************
*** 2342,2350 ****
        /* 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();
  
--- 2340,2345 ----
***************
*** 2416,2421 ****
--- 2411,2423 ----
                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).
         */
***************
*** 2456,2462 ****
         * start a new random sequence in the random() library function.
         */
        random_seed = 0;
!       gettimeofday(&now, &tz);
        srandom((unsigned int) now.tv_usec);
  
        /* ----------------
--- 2458,2464 ----
         * start a new random sequence in the random() library function.
         */
        random_seed = 0;
!       gettimeofday(&now, NULL);
        srandom((unsigned int) now.tv_usec);
  
        /* ----------------
***************
*** 2539,2544 ****
--- 2541,2554 ----
        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: src/backend/tcop/postgres.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/tcop/postgres.c,v
retrieving revision 1.359
diff -c -w -r1.359 postgres.c
*** src/backend/tcop/postgres.c 12 Aug 2003 18:52:38 -0000      1.359
--- src/backend/tcop/postgres.c 13 Aug 2003 20:59:15 -0000
***************
*** 85,90 ****
--- 85,93 ----
  bool          Warn_restart_ready = false;
  bool          InError = false;
  
+ /* flag for logging end of session */
+ bool        Log_session_end = false;
+ 
  /*
   * Flags for expensive function optimization -- JMH 3/9/92
   */
***************
*** 150,155 ****
--- 153,159 ----
  static void finish_xact_command(void);
  static void SigHupHandler(SIGNAL_ARGS);
  static void FloatExceptionHandler(SIGNAL_ARGS);
+ static void log_session_end(void);
  
  
  /* ----------------------------------------------------------------
***************
*** 2426,2432 ****
--- 2430,2439 ----
         * other output options.
         */
        if (debug_flag >= 1)
+       {
                SetConfigOption("log_connections", "true", debug_context, gucsource);
+               SetConfigOption("log_session_end", "true", debug_context, gucsource);
+       }
        if (debug_flag >= 2)
                SetConfigOption("log_statement", "true", debug_context, gucsource);
        if (debug_flag >= 3)
***************
*** 2455,2460 ****
--- 2462,2472 ----
                        gucopts = lnext(gucopts);
                        SetConfigOption(name, value, PGC_BACKEND, PGC_S_CLIENT);
                }
+          /*
+               * set up handler to log session end.
+               */
+               if (IsUnderPostmaster && Log_session_end)
+                       on_proc_exit(log_session_end,0);
        }
  
        /*
***************
*** 3195,3198 ****
--- 3207,3269 ----
                         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];
+       char remote_host[7 + NI_MAXHOST];
+       char remote_port[7 + NI_MAXSERV];
+       
+       snprintf(uname, sizeof(uname)," user=%s",port->user_name);
+       snprintf(dbname, sizeof(dbname)," database=%s",port->database_name);
+       snprintf(remote_host,sizeof(remote_host)," host=%s",
+                        port->remote_host);
+       /* prevent redundant or empty reporting of port */
+       if (!LogSourcePort && strlen(port->remote_port))
+               snprintf(remote_port,sizeof(remote_port)," port=%s",port->remote_port);
+       else
+               remote_port[0] = '\0';
+ 
+ 
+       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;
+ 
+       /* if time has gone backwards for some reason say so, or print time */
+ 
+       if (end.tv_sec < 0)
+               snprintf(session_time,sizeof(session_time),"negative!");
+       else
+               /* for stricter accuracy here we could round - this is close enough */
+               snprintf(session_time, sizeof(session_time),"%d:%02d:%02d.%02ld",
+                        hours, minutes, seconds, end.tv_usec/10000);
+       
+       ereport(
+               LOG,
+               (errmsg("session end: duration: %s%s%s%s%s",
+                       session_time,uname,dbname,remote_host,remote_port)));
+ 
  }
Index: src/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
*** src/backend/utils/adt/nabstime.c    4 Aug 2003 02:40:05 -0000       1.113
--- src/backend/utils/adt/nabstime.c    13 Aug 2003 20:59:16 -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: src/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
*** src/backend/utils/error/elog.c      8 Aug 2003 21:42:11 -0000       1.119
--- src/backend/utils/error/elog.c      13 Aug 2003 20:59:16 -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,1099 ----
  }
  #endif   /* HAVE_SYSLOG */
  
+ /*
+  * Formatted extra info for log if option is set and we have data,
+  * or empty string otherwise.
+  */
+ static const char * 
+ log_line_extra(void)
+ {
+       /* space for option string + 2 identifiers */
+       /* Note: if more identifiers are built in this will have to increase */
+       static char *result = NULL;
+       int format_len = strlen(Log_line_format_str);
+       int result_len = 2*NAMEDATALEN + format_len +3 ;
+       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;
+               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_format_str[i] != '%')
+                       {
+                               /* literal char, just copy */
+                               result[j]=Log_line_format_str[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_format_str[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 '%': 
+                                       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)
        {
--- 1103,1115 ----
  {
        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);
                }
        }
--- 1141,1167 ----
        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);
  
  
--- 1173,1180 ----
         * improve?
         */
        if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
!               appendStringInfo(&buf, gettext("%sSTATEMENT:  %s\n"),
!                                                extra_info,
                                                 debug_query_string);
  
  
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /projects/cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.149
diff -c -w -r1.149 guc.c
*** src/backend/utils/misc/guc.c        11 Aug 2003 23:04:49 -0000      1.149
--- src/backend/utils/misc/guc.c        13 Aug 2003 20:59:17 -0000
***************
*** 66,71 ****
--- 66,72 ----
  
  /* XXX these should appear in other modules' header files */
  extern bool Log_connections;
+ extern bool Log_session_end;
  extern int    PreAuthDelay;
  extern int    AuthenticationTimeout;
  extern int    CheckPointTimeout;
***************
*** 488,493 ****
--- 489,502 ----
                false, NULL, NULL
        },
        {
+               {"log_session_end", PGC_BACKEND, LOGGING_WHAT,
+                       gettext_noop("Logs end of a session, including duration"),
+                       NULL
+               },
+               &Log_session_end,
+               false, NULL, NULL
+       },
+       {
                {"log_timestamp", PGC_SIGHUP, LOGGING_WHAT,
                        gettext_noop("Prefixes server log messages with a time stamp"),
                        NULL
***************
*** 1334,1339 ****
--- 1343,1357 ----
                },
                &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: src/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
*** src/backend/utils/misc/postgresql.conf.sample       29 Jul 2003 00:03:18 -0000     
 1.87
--- src/backend/utils/misc/postgresql.conf.sample       13 Aug 2003 20:59:17 -0000
***************
*** 171,178 ****
--- 171,180 ----
  #debug_print_plan = false
  #debug_pretty_print = false
  #log_connections = false
+ #log_session_end = false
  #log_duration = false
  #log_pid = false
+ #log_line_format = ''     # e.g. '<%U%%%D> ' - %U=username %D=databasename %%=%
  #log_statement = false
  #log_timestamp = false
  #log_hostname = false
Index: src/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
*** src/include/libpq/libpq-be.h        4 Aug 2003 02:40:13 -0000       1.37
--- src/include/libpq/libpq-be.h        13 Aug 2003 20:59:17 -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: src/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
*** src/include/utils/elog.h    8 Aug 2003 21:42:55 -0000       1.63
--- src/include/utils/elog.h    13 Aug 2003 20:59:17 -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 9: the planner will ignore your desire to choose an index scan if your
      joining column's datatypes do not match

Reply via email to