Would you add remote hostname and source port so we then have all
connection parameters available for line output.

---------------------------------------------------------------------------

Andrew Dunstan wrote:
> 
> 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]

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  [EMAIL PROTECTED]               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

---------------------------(end of broadcast)---------------------------
TIP 4: Don't 'kill -9' the postmaster

Reply via email to