Timestamp in log for prepared queries - Mailing list pgsql-bugs

From elein@varlena.com (elein)
Subject Timestamp in log for prepared queries
Date
Msg-id 20050625015159.GU3596@varlena.com
Whole thread Raw
List pgsql-bugs
This problem shows up in the pglog for systems running
slony, but is not unique to slony necessarily.

The timestamp on queries logged to pglog corresponds
to the time the query was prepared rather than when
the query was run SPI_exec.

With slony, the same prepared statements may be used
for days or weeks or ???

This causes the pglog file to have interleaved within
it slony activity dated days previously along with
current update activity.

I discussed this briefly with Jan who agreed it was
a bug in the pg logging rather than a slony anomally.

In this spot of pglog, you see slony pre-prepared
queries timestamped 06-10 16:18:47 (et al) interleaved with a
connection error timestamped 06-16 16:00.

dev_core-2005-06-10 16:18:47 PDT-LOG:  duration: 21.882 ms  statement: select con_origin, con_received,
max(con_seqno)as con_seqno,     max(con_timestamp) as con_timestamp from "_plaa03_staging".sl_confirm where
con_received<> 2 group by con_origin, con_received 
dev_core-2005-06-10 15:01:20 PDT-LOG:  duration: 96.519 ms  statement: notify "_plaa03_staging_Event"; notify
"_plaa03_staging_Confirm";insert into "_plaa03_staging".sl_event     (ev_origin, ev_seqno, ev_timestamp,  ev_minxid,
ev_maxxid,ev_xip, ev_type     ) values ('2', '51740', '2005-06-16 16:00:40.947355', '3246520', '3627300',
'''3603570'',''3603741'',''3620474'',''3509792'',''3246520'',''3599413'',''3613734''','SYNC'); insert into
"_plaa03_staging".sl_confirm (con_origin, con_received, con_seqno, con_timestamp)    values (2, 1, '51740',
CURRENT_TIMESTAMP);commit transaction; 
dev_core-2005-06-10 16:18:47 PDT-LOG:  duration: 21.911 ms  statement: select con_origin, con_received,
max(con_seqno)as con_seqno,     max(con_timestamp) as con_timestamp from "_plaa03_staging".sl_confirm where
con_received<> 2 group by con_origin, con_received [unknown]-2005-06-16 16:00:48 PDT-LOG:  connection received:
host=[local]port= 
dev_coree-2005-06-16 16:00:48 PDT-LOG:  connection authorized: user=postgres database=dev_coree dev_coree-2005-06-16
16:00:48PDT-FATAL:  database "dev_coree" does not exist 
dev_core-2005-06-10 15:01:20 PDT-LOG:  duration: 3.766 ms  statement: select
"_plaa03_staging".createEvent('_plaa03_staging','SYNC', NULL); 
dev_core-2005-06-10 15:01:20 PDT-LOG:  duration: 81.188 ms  statement: commit transaction;
dev_core-2005-06-10 15:25:15 PDT-LOG:  duration: 22.012 ms  statement: fetch 100 from LOG;
dev_core-2005-06-10 15:01:20 PDT-LOG:  duration: 183.405 ms  statement: select "_plaa03_staging".forwardConfirm(1, 2,
'53126','2005-06-16 16:00:48.620222'); 
dev_core-2005-06-10 16:18:47 PDT-LOG:  duration: 22.126 ms  statement: select con_origin, con_received,
max(con_seqno)as con_seqno,     max(con_timestamp) as con_timestamp from "_plaa03_staging".sl_confirm where
con_received<> 2 group by con_origin, con_received 


elein
elein@varlena.com

pgsql-bugs by date:

Previous
From: Michael Fuhr
Date:
Subject: Re: BUG #1730: insert into x1.tbl select x2.tbl dont work
Next
From: Ruslan A Dautkhanov
Date:
Subject: can't startup PG-8.0.3