Thread: Logging problems in PostgreSQL 7.2devel

I have postmaster configured to use syslog. Despite this, these messages appear on the terminal from which I start it:
2001-09-03 23:44:37 [26371]  DEBUG:  recycled transaction log file 0000000000000044

There are many of those.

Here are the relevant lines from the configuration:
[pgtest@possum pgtest]$ egrep -v '(^#|^$)' /var/share/pgtest/postgresql/pgsql/data/postgresql.conf
tcpip_socket = true
show_source_port = true
shared_buffers = 1024      # 2*max_connections, min 16
wal_files = 4 # range 0-64
wal_sync_method = fsync   # fsync or fdatasync or open_sync or open_datasync
wal_debug = 0             # range 0-16
log_connections = true
log_timestamp = true
log_pid = true
debug_level = 0 # range 0-16
debug_assertions = true
syslog = 2 # range 0-2
[pgtest@possum pgtest]$


Additionally there are many (supposedly suppressed) (apparently) debugging lines printed out on syslog:
Sep  3 20:42:10 possum postgres[26215]: [1] DEBUG:  connection: host=192.168.1.6:32923 user=summer database=sharetrader
Sep  3 20:42:10 possum postgres[26215]: [2] ERROR:  index "ijs0101_stocks_info" does not exist
Sep  3 20:42:47 possum postgres[26229]: [1] DEBUG:  connection: host=192.168.1.6:32924 user=summer database=sharetrader
Sep  3 20:42:47 possum postgres[26229]: [2] ERROR:  index "ijs0102_trades" does not exist
Sep  3 20:42:47 possum postgres[26229]: [3] ERROR:  table "tjs0102_trades" does not exist
Sep  3 20:42:47 possum postgres[26229]: [4] NOTICE:  CREATE TABLE/UNIQUE will create implicit index
'tjs0102_trades_asx_key'for table 'tjs0102_trades' 
Sep  3 20:44:22 possum postgres[26270]: [1] DEBUG:  recycled transaction log file 0000000000000002
Sep  3 20:49:27 possum postgres[26271]: [1] DEBUG:  recycled transaction log file 0000000000000003

John Summerfield <pgtest@os2.ami.com.au> writes:
> I have postmaster configured to use syslog. Despite this, these messages appear on the terminal from which I start
it:
> 2001-09-03 23:44:37 [26371]  DEBUG:  recycled transaction log file 0000000000000044

Very strange.  That shouldn't be happening with the syslog = 2 setting.
Can you trace through elog() with a debugger and see where it's going
wrong?

            regards, tom lane

John Summerfield <pgtest@os2.ami.com.au> writes:
> I have postmaster configured to use syslog. Despite this, these messages appear on the terminal from which I start
it:
> 2001-09-03 23:44:37 [26371]  DEBUG:  recycled transaction log file 0000000000000044

Ah, I see what's causing that.  elog.c does this to decide whether to
write on stderr:

    /* write to terminal */
    if (Use_syslog <= 1 || whereToSendOutput == Debug)
        write(2, msg_buf, strlen(msg_buf));

Now, whereToSendOutput is initially Debug in a postmaster or standalone
backend, and it gets changed to Remote when a normal backend is forked
from the postmaster.  The messages that John is seeing come from routine
checkpoint subprocesses, which are also forked off from the postmaster
--- and whereToSendOutput is never changed in that path.

It strikes me that perhaps we should have whereToSendOutput start out
as None in a postmaster (but it should still be Debug in a standalone
backend or bootstrap run).

Peter, I'm cc'ing you since you've messed with elog message handling
most recently.  Do you have any thoughts about proper behavior here?

            regards, tom lane

On Fri, 7 Sep 2001, Tom Lane wrote:


> John Summerfield <pgtest@os2.ami.com.au> writes:
> > I have postmaster configured to use syslog. Despite this, these messages appear on the terminal from which I start
it:
> > 2001-09-03 23:44:37 [26371]  DEBUG:  recycled transaction log file 0000000000000044
>
> Ah, I see what's causing that.  elog.c does this to decide whether to
> write on stderr:
>
>     /* write to terminal */
>     if (Use_syslog <= 1 || whereToSendOutput == Debug)
>         write(2, msg_buf, strlen(msg_buf));
>
> Now, whereToSendOutput is initially Debug in a postmaster or standalone
> backend, and it gets changed to Remote when a normal backend is forked
> from the postmaster.  The messages that John is seeing come from routine
> checkpoint subprocesses, which are also forked off from the postmaster
> --- and whereToSendOutput is never changed in that path.
>
> It strikes me that perhaps we should have whereToSendOutput start out
> as None in a postmaster (but it should still be Debug in a standalone
> backend or bootstrap run).
>
> Peter, I'm cc'ing you since you've messed with elog message handling
> most recently.  Do you have any thoughts about proper behavior here?

I should also mention these debug messages occur despite my efforts to turn them off.



>