How to get back 7.0.x log format

Hannu Krosing <hannu@tm.ee> writes:

I hope I'm wrong but I just noticed that since 7.0.x the
postgresql log format has changed to much worse -
It now misses such important things as process id ,
transaction id, timestamp and query id.

Have you turned on the appropriate flags in postgresql.conf?

regards, tom lane

Tom Lane wrote:

Hannu Krosing <hannu@tm.ee> writes:

I hope I'm wrong but I just noticed that since 7.0.x the
postgresql log format has changed to much worse -
It now misses such important things as process id ,
transaction id, timestamp and query id.

Have you turned on the appropriate flags in postgresql.conf?

Thanks, found most of them now !

I had turned on _all_ debug_* flags that I found there but somehow
missed the log_* ones ;(

Now all I am missing is some timing statistics -
* how long did planning/optimizing take
* how long did execution take

I guess I will be able to extract most that info when I enabe all of the
following

debug_print_query = true
debug_print_parse = true
debug_print_rewritten = true
debug_print_plan = true

But I will probably still not get the execution end time (or even better
when
were first and last tuple delivered).

Is there a way to get these ?

I vaguely remember that 7.0.x logged both "query start" and "query end"
times, no ?

----------------------------
Hannu

Tom Lane wrote:

Hannu Krosing <hannu@tm.ee> writes:

I vaguely remember that 7.0.x logged both "query start" and "query end"
times, no ?

I do not think that any logging ability got removed between 7.0 and 7.1.

IIRC It was possible to determine how long a _certain_ query took in 7.0.x.

regards, tom lane

Ok, I found the statistics flags too, but how am I to tell which stats
go to which query ?

I think that having backend pid in QUERY STATISTICS should be enough to
help out.

2001-12-02 04:12:39 [7369] DEBUG: query: select count(*) from item
i1,item i2;
2001-12-02 04:12:43 [7311] DEBUG: query: select count(*) from item;
QUERY STATISTICS
! system usage stats:
! 0.005394 elapsed 0.010000 user 0.000000 system sec
! [0.040000 user 0.020000 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/2 [282/197] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 0/0 [0/0] voluntary/involuntary context switches
! postgres usage stats:
! Shared blocks: 0 read, 0 written, buffer hit
rate = 100.00%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written
QUERY STATISTICS
! system usage stats:
! 21.127781 elapsed 7.470000 user 0.010000 system sec
! [7.480000 user 0.050000 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 15/6 [267/196] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 0/0 [0/0] voluntary/involuntary context switches
! postgres usage stats:
! Shared blocks: 8 read, 0 written, buffer hit
rate = 99.84%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written

I can't even figure this out by time elapsed, as I don't know when the
stats were written

-------------------------------
Hannu

Hannu Krosing <hannu@tm.ee> writes:

I vaguely remember that 7.0.x logged both "query start" and "query end"
times, no ?

I do not think that any logging ability got removed between 7.0 and 7.1.

regards, tom lane