Re: logging enhancements, minor code cleanup

Thanks. Responses interspersed below.

cheers

andrew

Neil Conway wrote:

>On Sat, Aug 09, 2003 at 07:22:56PM -0400, Andrew Dunstan wrote:
>
>
>>The attached patch does 3 things:
>>
>>. logs connection ends if log_connections = true
>>
>>
>
>Should this be a separate GUC variable? Personally, I'd rather not have
>my log files bloated with info on both the beginning *and* the end of
>each connection.
>
>

Sure. Very easy. Nobody suggested it when I floated the idea of logging
session end on the hackers list, but it's a simple change. How does
'log_session_end' sound? Or else we could make log_connections have
levels - 0 = none, 1 = start, 2 = start + end. What's the concensus?

>
>
>>. provides a new option "log_line_format" which allows addition of extra
>>information on a log line before the keyword.
>>
>>
>
>This patch should also update the documentation.
>

I'll submit a doc patch when the code is accepted. That's what I did
with the pg_hba.conf CIDR stuff and nobody objected. I think this is a
good way to operate, since I might make changes (for example, as a
result of your response), and would rather do the docs once.

>
>Some minor stylistic comments follow...
>
>
>
>>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
>>+ 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;
>>
>>
>
>Can you add an assertion that end.tv_sec >= port->session_start.tv_sec before
>this line, please?
>
>

Sure. Presumably to catch the situation where the machine's time is
changed (backwards) during the session - an event with fairly low
probability.

>
>
>>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
>>***************
>>*** 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.
>>+ */
>>
>>
>
>This comment is a little awkward: "we have a data"?
>
>

Typo. will fix.

>
>
>>+ 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 */
>>
>>
>
>"Identifier" is incorrectly spelled.
>
>

Typo again. will fix.

>
>
>>+ static char *result = NULL;
>>
>>
>
>Why is this static? IMHO it would be much cleaner to just return a palloc'ed
>string.
>
>

print_timestamp() and print_pid() in the same file use static buffers
which they return, so I just copied the style more or less, making
allowance for the fact I don't know the reasonable size at compile time.
It doesn't seem very efficient to palloc the string over and over
instead of once per backend. Wouldn't I then have to pfree it at a
remote spot in the code so as not to have a memory leak? That strikes me
as much more error prone.

>
>
>>+ int flen = strlen(Log_line_format_str);
>>+ int i,j;
>>+ int tlen = 2*NAMEDATALEN + flen +3 ;
>>
>>
>
>Can we choose some more helpful variable names than "flen" and
>"tlen", please? Also, you can move the declaration of i & j to
>the scope of the if statement.
>
>

Sure. Will do.

>
>
>>+ {
>>+ char * dbname = MyProcPort->database_name;
>>+ char * username = MyProcPort->user_name;
>>+ if (dbname == NULL)
>>+ dbname="";
>>+ if (username == NULL)
>>+ username = "";
>>
>>
>
>Could either of these ever be NULL?
>
>
I don't know. Maybe not. This was by way of defensive programming.

>
>
>>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 %%=%
>>
>>
>
>Shouldn't the commented-out line have the default value? (which is "", right?)
>
>

Yes, default is "". I'll move the example to the comment, if you like.