timing queries

Started by Christopher Kings-Lynnealmost 24 years ago3 messages
#1Christopher Kings-Lynne
chriskl@familyhealth.com.au

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

#2Gavin Sherry
swm@linuxworld.com.au
In reply to: Christopher Kings-Lynne (#1)
Re: 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

#3Hannu Krosing
hannu@tm.ee
In reply to: Gavin Sherry (#2)
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]