Timestamp in log for prepared queries

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

Timestamp in log for prepared queries

elein
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:48 PDT-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
[hidden email]

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
       choose an index scan if your joining column's datatypes do not
       match