DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com;
	h=Message-ID:X-YMail-OSG:Received:X-Mailer:Date:From:Subject:To:MIME-Version:Content-Type;
	b=ICdFPKfytcm1T7o3evShl/AlOXqSU95FMPNvyLJy58ZEzw0PEptHmf8IdQfiXTRoJEblK89adDlRwBg/iUZNAwlZGf43/QuzqLdRHiZNzITgQC2NS8Fc6VAJPCH2fK9UazUrvnbFWGDvGEobzTUISFrCYfRz1Z9u84VSbZvW5CM=;
Message-ID: <798506.30088.qm@web111308.mail.gq1.yahoo.com>
Date: Tue, 10 Mar 2009 16:24:57 -0700 (PDT)
From: Jessica Richard <rjessil@yahoo.com>
Subject: how to figure out how long a query takes in the pg log file...
To: pgsql-admin@postgresql.org
MIME-Version: 1.0
Content-Type: multipart/alternative; boundary="0-1046998474-1236727497=:30088"


--0-1046998474-1236727497=:30088
Content-Type: text/plain; charset=us-ascii

I need to identify the slowest queries by analyzing the postgre log file.

By the following log_line_prefix set up, I can see all the query contents and I can see the duration times:

log_line_prefix = '%u %d %h %m %c %x '      

..
..
postgres testdb [local] 2009-03-10 14:36:35.110 EDT 49b6b31a.8ad 30898958 DETAIL:  ! system usage stats:
postgres testdb [local] 2009-03-10 14:36:35.110 EDT 49b6b31a.8ad 30898958 LOG:  statement: select count(*) from testtable;
postgres testdb [local] 2009-03-10 14:36:35.111 EDT 49b6b31a.8ad 30898958 LOG:  PARSE ANALYSIS STATISTICS
postgres testdb [local] 2009-03-10 14:36:35.111 EDT 49b6b31a.8ad 30898958 DETAIL:  ! system usage stats:
..
postgres testdb [local] 2009-03-10 14:36:47.935 EDT 49b6b31a.8ad 0 LOG:  duration: 12825.670 ms


But I am unable to link he duration time taken by the original query. Even though I used the session id %c and the transaction id %x, when it comes to the duration line, the transaction id is always "0" -- I can't match it to the query line that has a non-zero transaction id.

I ideally I expect to see something in common between the duration line and the query line so that I can group them together --- then I will be able to see the slowest queries and look for the tuning options from there. Since all the queries take different amounts of time to finish, the duration time showed up few lines after the query line does not mean it was the time that query took.  The same session id can have many different transaction ids.

Could some one out there help me on this?

Thanks a lot,
Jessica


--0-1046998474-1236727497=:30088
Content-Type: text/html; charset=us-ascii

<html><head><style type="text/css"><!-- DIV {margin:0px;} --></style></head><body><div style="font-family:times new roman,new york,times,serif;font-size:12pt"><div>I need to identify the slowest queries by analyzing the postgre log file.<br><br>By the following log_line_prefix set up, I can see all the query contents and I can see the duration times:<br><br>log_line_prefix = '%u %d %h %m %c %x '&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; <br><br>.<br>.<br>postgres testdb [local] 2009-03-10 14:36:35.110 EDT 49b6b31a.8ad 30898958 DETAIL:&nbsp; ! system usage stats:<br>postgres testdb [local] 2009-03-10 14:36:35.110 EDT 49b6b31a.8ad 30898958 LOG:&nbsp; statement: select count(*) from testtable;<br>postgres testdb [local] 2009-03-10 14:36:35.111 EDT 49b6b31a.8ad 30898958 LOG:&nbsp; PARSE ANALYSIS STATISTICS<br>postgres testdb [local] 2009-03-10 14:36:35.111 EDT 49b6b31a.8ad 30898958 DETAIL:&nbsp; ! system usage stats:<br>.<br>postgres testdb [local] 2009-03-10
 14:36:47.935 EDT 49b6b31a.8ad 0 LOG:&nbsp; duration: 12825.670 ms<br><br><br>But I am unable to link he duration time taken by the original query. Even though I used the session id %c and the transaction id %x, when it comes to the duration line, the transaction id is always "0" -- I can't match it to the query line that has a non-zero transaction id.<br><br>I ideally I expect to see something in common between the duration line and the query line so that I can group them together --- then I will be able to see the slowest queries and look for the tuning options from there. Since all the queries take different amounts of time to finish, the duration time showed up few lines after the query line does not mean it was the time that query took.&nbsp; The same session id can have many different transaction ids.<br><br>Could some one out there help me on this?<br><br>Thanks a lot,<br>Jessica<br></div></div><br>


      </body></html>
--0-1046998474-1236727497=:30088--