Hi hackers,

Is there any way of logging all queries and their duration in postgres?  I
know you can log queries - but I can't see any way of logging durations.

If not - would it be a worthwhile TODO?

Chris


Tue, 29 Jan 2002 15:42:59 +0800
"Christopher Kings-Lynne" <chriskl@familyhealth.com.au>
timing queries
On Tue, 29 Jan 2002, Christopher Kings-Lynne wrote:

> Hi hackers,
> 
> Is there any way of logging all queries and their duration in postgres?  I
> know you can log queries - but I can't see any way of logging durations.

I discussed auditing in PostgreSQL 7.3. This would probably be a useful
bit of data to include in the audit trail.

Gavin


Tue, 29 Jan 2002 21:14:18 +1100 (EST)
Gavin Sherry <swm@linuxworld.com.au>
Re: timing queries
Gavin Sherry wrote:
> 
> On Tue, 29 Jan 2002, Christopher Kings-Lynne wrote:
> 
> > Hi hackers,
> >
> > Is there any way of logging all queries and their duration in postgres?  I
> > know you can log queries - but I can't see any way of logging durations.
> 
> I discussed auditing in PostgreSQL 7.3. This would probably be a useful
> bit of data to include in the audit trail.

I use the following code snippet to extract slow queries from postgresql
log

It could be improved trivially to include also the query text -
currently it 
just shows the start time and backend number.

#!/usr/bin/python

""
020118.10:05:11.879 [27337] ProcessQuery
020118.10:05:11.879 [27337] CommitTransactionCommand
020118.10:05:11.882 [27337] StartTransactionCommand
020118.10:05:11.882 [27337] query: SET DateStyle TO 'ISO';
"""

import sys,string,time

def ts2time(ts):
    yr = int(ts[ 0: 2])
    mo = int(ts[ 2: 4])
    dy = int(ts[ 4: 6])
    hr = int(ts[ 7: 9])
    mi = int(ts[10:12])
    se = int(ts[13:15])
    hu = float(ts[15:])
    return time.mktime((yr,mo,dy,hr,mi,se,0,0,0)) + hu


file = sys.stdin
lnr = 0
trx_dict = {}

SLOW = 1  # longer than this seconds is slow

while 1:
    pos = file.tell()
    line = file.readline()
    if not line: break
    lnr = lnr + 1
    try:
        ts, pid, inf = string.split(line)[:3]
#        print '-', ts, pid, inf
        ti = ts2time(ts)
    except:
        continue
    try:
        lastlnr, lastpos, lasttime, lastts, lastinf = trx_dict[pid]
#        print '*',lastlnr, lastpos, lasttime, lastts, lastinf
#        if lastinf == 'ProcessQuery\n':
#            print ti-lasttime, lastlnr, lastpos, lastts, ts
        if((ti-lasttime) > SLOW) and (lastinf == 'ProcessQuery'):
            print ti-lasttime, lastlnr, lastpos, lastts, ts
    except:
        pass
    if inf=='exit(0)\n':
        del trx_dict[pid]
    else:
        trx_dict[pid] = (lnr,pos,ti,ts,inf)

for key in trx_dict.keys():
    print trx_dict[key]

Tue, 29 Jan 2002 14:34:39 +0200
Hannu Krosing <hannu@tm.ee>
Re: timing queries