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]