Re: Analyzer for postgresql.log

Hi Tielman,

The times I refer to are the execution times of the queries.

In my log file, there is a line containing the beginning of statement
timestamp, another containing a timestamp and a query, and finally one
that includes a timestamp when the instruction finished.

The timestamp is formatted like 011210.18:04:44.123 for the date and
time I was writing this e-mail.

I take the beginning timestamp and substract the end timestamp. The
resulting value, in milliseconds (see script for details) is printed
along with the query.

If your queries take 0 ms then you will get

0;begin

for example.

As I said, "It works for me.", which means that I took my very own log,
read it, and built a dumb reader for that specific log.

The script is not very well commented. Hmmm... is not commented at all
(sorry), but hopefully it shouldn't be too hard to understand.

Probably if you are not using PostgreSQL 7.0.3 the log file format may
have changed. You will need to adapt it to your very needs. Particularly
if the timestamp format has changed, my script may well understand
absolutely nothing.

BTW, if a number on a query has the form "m1234" (yes, it's a "m"), that
will be considered a number, as if it were "-1234". I needed that.
Taking that functionality out of the script is just a matter of taking
the "m" out of the regex.

I use the PID (which is shown right after the timestamp, in square
brackets, on my log file) to track which backend executes which query.
That allows me to know which actual query a given beginning and end match.

cat complaints > /dev/null, but I promise to try to help you getting it
work, if you send me a piece of your log file (several statements should
be enough).

Yours,

Antonio Fiol

P.S. Here are three lines I find particularly useful, once the script works:

# Sort by request (needed for the other lines)
sort -t ';' -k 2 <post.analysis > post.analysis.sorted
# Count every request (requires a sorted input)
cut -f 2 -d ';' post.analysis.sorted | uniq -c | sort -r -n >
post.analysis.bycount
# Add up the times used by every request type (also requires a sorted input)
awk 'BEGIN { FS=";"; s=0; q=""; } // { if(q==$2) s+=$1; else { print s,
q; s=$1; q=$2; } }' < post.analysis.sorted | sort -r -n >
post.analysis.bytime

Have fun!

Tielman J de Villiers wrote:

>Thank you,
>
>I will be using this in a cronjob to act kind of as the "analog" web log
>analyser for my postgres logs ...
>
>Just one question -- the "list of times" (eg 13,15) wheat do they refer to
>(mine all shows a "0")
>
>Regards
>
>Tielman J de Villiers
>BondNet Pty Ltd
>
>-----Original Message-----
>From: Antonio Fiol Bonnín [mailto:fiol(at)w3ping(dot)com]
>Sent: Monday, December 10, 2001 2:37 PM
>To: PostgreSQL General Mailing list
>Subject: [GENERAL] Analyzer for postgresql.log
>
>
>Attached is a little AWK script that you may find of some use.
>
>It takes as standard input a file with the format of the Postgresql log
>(level 2, for PostgreSQL 7.0.3 tested).
>
>On standard output, you get a list of times and a mangled form of every
>executed request.
>
>Something like
>
>13;select * from my_table where field=''
>15;select * from other_table where id= and test>
>
>All number are removed from requests. Also removed are the contents
>between single quotes.
>
>This allows me to sort by request and then either count them or add up
>the times. That way I know what I need to optimize.
>
>The script is far from perfect. It just works for me ;-)
>
>Antonio Fiol
>
>.
>