From amedici@fr.netcentrex.net Wed Oct 6 10:15:46 2004 X-Original-To: pgsql-benchmarks-postgresql.org@localhost.postgresql.org Received: from localhost (unknown [200.46.204.144]) by svr1.postgresql.org (Postfix) with ESMTP id 34DD6329D7F; Wed, 6 Oct 2004 11:15:46 +0100 (BST) Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org [200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 40870-09; Wed, 6 Oct 2004 10:15:33 +0000 (GMT) Received: from mailer.unicite.fr.netcentrex.net (unknown [62.161.167.249]) by svr1.postgresql.org (Postfix) with ESMTP id 5B0F4329CDD; Wed, 6 Oct 2004 11:15:33 +0100 (BST) Received: from [192.168.101.228] ([192.168.101.228]) by mailer.unicite.fr.netcentrex.net with SMTP (Microsoft Exchange Internet Mail Service Version 5.5.2657.72) id 42CX026B; Wed, 6 Oct 2004 12:15:32 +0200 Message-ID: <4163C5C3.3030304@fr.netcentrex.net> Date: Wed, 06 Oct 2004 12:15:31 +0200 From: =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= Organization: NetCentrex User-Agent: Mozilla Thunderbird 0.8 (Windows/20040913) X-Accept-Language: en-us, en MIME-Version: 1.0 To: pgsql-benchmarks@postgresql.org, pgsql-performance@postgresql.org Subject: stats on cursor and query execution troubleshooting Content-Type: multipart/alternative; boundary="------------040806000209030206000904" X-Virus-Scanned: by amavisd-new at hub.org X-Spam-Status: No, hits=0.5 tagged_above=0.0 required=5.0 tests=HTML_40_50, HTML_MESSAGE X-Spam-Level: X-Archive-Number: 200410/1 X-Sequence-Number: 18 This is a multi-part message in MIME format. --------------040806000209030206000904 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: quoted-printable Hi, I'm looking for the statistic of memory, CPU, filesystem access while=20 executing some regular SQL query, and I want to compare them to same kind of results while executing a cursor function. The stat collector give me good results (sequencial scans , acceded=20 tuple .....) for regular query but nor for cursor (as explain in the=20 documentation) For more results, i have activated some log level in the postgresql.conf : show_query_stats =3D true But I have some trouble in the results interpretation such as : ! system usage stats: ! 2.776053 elapsed 1.880000 user 0.520000 system sec ! [1.910000 user 0.540000 sys total] ! 0/0 [0/0] filesystem blocks in/out ! 5/1 [319/148] page faults/reclaims, 0 [0] swaps ! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent ! 0/0 [0/0] voluntary/involuntary context switches ! postgres usage stats: ! Shared blocks: 3877 read, 0 written, buffer hit rate= =3D 0.00% ! Local blocks: 0 read, 0 written, buffer hit rate= =3D 0.00% ! Direct blocks: 0 read, 0 written Here is result done after fetching ALL a row with 178282 records in the=20 table. looking at the i/o stat of linux I saw a filesystem access while=20 executing this request but not in the previous log !!! ! 0/0 [0/0] filesystem blocks in/out I'm running postgresql 7.2.4 under redhat 7.2 Does am i wrong in my interpretation ? Does any newest postgresql version could told me execution paln for a=20 fetch AND better stats ? thx Ps: please excuse my poor english --=20 Alban M=E9dici R&D software engineer ------------------------------ you can contact me @ : http://www.netcentrex.net ------------------------------ --------------040806000209030206000904 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Hi,

I'm looking for the statistic of memory, CPU, filesystem access while executing some regular SQL query, and I want to compare them to
same kind of results while executing a cursor function.

The stat collector give me good results (sequencial scans , acceded tuple .....) for regular query but nor for cursor (as explain in the documentation)

For more results, i have activated some log level in the postgresql.conf :
show_query_stats = true

But I have some trouble in the results interpretation such as :

! system usage stats:

!       2.776053 elapsed 1.880000 user 0.520000 system sec

!       [1.910000 user 0.540000 sys total]

!       0/0 [0/0] filesystem blocks in/out

!       5/1 [319/148] page faults/reclaims, 0 [0] swaps

!       0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent

!       0/0 [0/0] voluntary/involuntary context switches

! postgres usage stats:

!       Shared blocks:       3877 read,          0 written, buffer hit rate = 0.00%

!       Local  blocks:          0 read,          0 written, buffer hit rate = 0.00%

! Direct blocks: 0 read, 0 written

Here is result done after fetching ALL a row with 178282 records in the table.
looking at the i/o stat of linux I saw a filesystem access while executing this request but not in the previous log !!!

!       0/0 [0/0] filesystem blocks in/out

I'm running postgresql 7.2.4 under redhat 7.2

Does am i wrong in my interpretation ?

Does any newest postgresql version could told me execution paln for a fetch AND better stats ?

thx

Ps: please excuse my poor english

-- 
Alban Médici
R&D software engineer
------------------------------
you can contact me @ :
http://www.netcentrex.net
------------------------------

--------------040806000209030206000904-- From tgl@sss.pgh.pa.us Wed Oct 6 14:16:50 2004 X-Original-To: pgsql-benchmarks-postgresql.org@localhost.postgresql.org Received: from localhost (unknown [200.46.204.144]) by svr1.postgresql.org (Postfix) with ESMTP id 2793F329E8E; Wed, 6 Oct 2004 15:16:50 +0100 (BST) Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org [200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 12764-06; Wed, 6 Oct 2004 14:16:44 +0000 (GMT) Received: from sss.pgh.pa.us (sss.pgh.pa.us [66.207.139.130]) by svr1.postgresql.org (Postfix) with ESMTP id D2716329E64; Wed, 6 Oct 2004 15:16:43 +0100 (BST) Received: from sss2.sss.pgh.pa.us (tgl@localhost [127.0.0.1]) by sss.pgh.pa.us (8.13.1/8.13.1) with ESMTP id i96EGeKS025577; Wed, 6 Oct 2004 10:16:40 -0400 (EDT) To: =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= Cc: pgsql-benchmarks@postgresql.org, pgsql-performance@postgresql.org Subject: Re: [PERFORM] stats on cursor and query execution troubleshooting In-reply-to: <4163C5C3.3030304@fr.netcentrex.net> References: <4163C5C3.3030304@fr.netcentrex.net> Comments: In-reply-to =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= message dated "Wed, 06 Oct 2004 12:15:31 +0200" Date: Wed, 06 Oct 2004 10:16:39 -0400 Message-ID: <25576.1097072199@sss.pgh.pa.us> From: Tom Lane X-Virus-Scanned: by amavisd-new at hub.org X-Spam-Status: No, hits=0.0 tagged_above=0.0 required=5.0 tests= X-Spam-Level: X-Archive-Number: 200410/2 X-Sequence-Number: 19 =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= writes: > I'm looking for the statistic of memory, CPU, filesystem access while=20 > executing some regular SQL query, and I want to compare them to > same kind of results while executing a cursor function. I think your second query is finding all the disk pages it needs in kernel disk cache, because they were all read in by the first query. This has little to do with cursor versus non cursor, and everything to do with hitting recently-read data again. regards, tom lane From amedici@fr.netcentrex.net Fri Oct 8 08:47:51 2004 X-Original-To: pgsql-benchmarks-postgresql.org@localhost.postgresql.org Received: from localhost (unknown [200.46.204.144]) by svr1.postgresql.org (Postfix) with ESMTP id 6CF7A329E47; Fri, 8 Oct 2004 09:47:51 +0100 (BST) Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org [200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 32175-09; Fri, 8 Oct 2004 08:47:44 +0000 (GMT) Received: from mailer.unicite.fr.netcentrex.net (unknown [62.161.167.249]) by svr1.postgresql.org (Postfix) with ESMTP id 777A7329E51; Fri, 8 Oct 2004 09:47:43 +0100 (BST) Received: from [192.168.101.228] ([192.168.101.228]) by mailer.unicite.fr.netcentrex.net with SMTP (Microsoft Exchange Internet Mail Service Version 5.5.2657.72) id 42CX03QZ; Fri, 8 Oct 2004 10:47:42 +0200 Message-ID: <4166542E.2020809@fr.netcentrex.net> Date: Fri, 08 Oct 2004 10:47:42 +0200 From: =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= User-Agent: Mozilla Thunderbird 0.8 (Windows/20040913) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Tom Lane Cc: pgsql-benchmarks@postgresql.org, pgsql-performance@postgresql.org Subject: Re: [PERFORM] stats on cursor and query execution troubleshooting References: <4163C5C3.3030304@fr.netcentrex.net> <25576.1097072199@sss.pgh.pa.us> In-Reply-To: <25576.1097072199@sss.pgh.pa.us> Content-Type: multipart/alternative; boundary="------------030409030803050401070308" X-Virus-Scanned: by amavisd-new at hub.org X-Spam-Status: No, hits=0.5 tagged_above=0.0 required=5.0 tests=HTML_20_30, HTML_MESSAGE X-Spam-Level: X-Archive-Number: 200410/3 X-Sequence-Number: 20 This is a multi-part message in MIME format. --------------030409030803050401070308 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: quoted-printable Thanks for your repply, but I still don"t understand why the statistic=20 logs : ! 0/0 [0/0] filesystem blocks in/out it told me there is no hard disk access, I'm sure there is, I heard my=20 HDD, and see activity using gkrellm (even using my first query ; big=20 select *) ? 2004-10-08 10:40:05 DEBUG: query: select * from "LINE_Line"; 2004-10-08 10:40:53 DEBUG: QUERY STATISTICS ! system usage stats: ! 48.480196 elapsed 42.010000 user 0.700000 system sec ! [42.030000 user 0.720000 sys total] ! 0/0 [0/0] filesystem blocks in/out ! 6/23 [294/145] page faults/reclaims, 0 [0] swaps ! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent ! 0/0 [0/0] voluntary/involuntary context switches ! postgres usage stats: ! Shared blocks: 3902 read, 0 written, buffer hit=20 rate =3D 11.78% ! Local blocks: 0 read, 0 written, buffer hit=20 rate =3D 0.00% ! Direct blocks: 0 read, 0 written looking at the web some logs, I saw those fields filled (i/o filesystem) Does my postgresql.conf missing an option or is therer a known bug of my=20 postgresql server 7.2.4 ? thx regards Alban M=E9dici on 06/10/2004 16:16 Tom Lane said the following: >=3D?ISO-8859-1?Q?=3D22Alban_M=3DE9dici_=3D28NetCentrex=3D29=3D22?=3D writes: >=20=20 > >>I'm looking for the statistic of memory, CPU, filesystem access while= =3D20 >>executing some regular SQL query, and I want to compare them to >>same kind of results while executing a cursor function. >>=20=20=20=20 >> > >I think your second query is finding all the disk pages it needs in >kernel disk cache, because they were all read in by the first query. >This has little to do with cursor versus non cursor, and everything >to do with hitting recently-read data again. > > regards, tom lane > >=20=20 > --=20 Alban M=E9dici R&D software engineer ------------------------------ you can contact me @ : http://www.netcentrex.net ------------------------------ --------------030409030803050401070308 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Thanks for your repply, but I still don"t understand why the statistic logs :

!       0/0 [0/0] filesystem blocks in/out

it told me there is no hard disk access, I'm sure there is, I heard my HDD, and see activity using gkrellm (even using my first query ; big select *) ? 2004-10-08 10:40:05 DEBUG: query: select * from "LINE_Line"; 2004-10-08 10:40:53 DEBUG: QUERY STATISTICS ! system usage stats: ! 48.480196 elapsed 42.010000 user 0.700000 system sec ! [42.030000 user 0.720000 sys total] ! 0/0 [0/0] filesystem blocks in/out ! 6/23 [294/145] page faults/reclaims, 0 [0] swaps ! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent ! 0/0 [0/0] voluntary/involuntary context switches ! postgres usage stats: ! Shared blocks: 3902 read, 0 written, buffer hit rate = 11.78% ! Local blocks: 0 read, 0 written, buffer hit rate = 0.00% ! Direct blocks: 0 read, 0 written looking at the web some logs, I saw those fields filled (i/o filesystem) Does my postgresql.conf missing an option or is therer a known bug of my postgresql server 7.2.4 ? thx regards Alban Médicion 06/10/2004 16:16 Tom Lane said the following:

=?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= <amedici@fr.netcentrex.net> writes:

I'm looking for the statistic of memory,  CPU,  filesystem access while=20
executing some regular SQL query,  and I want to compare them to
same kind of results while executing a cursor function.


I think your second query is finding all the disk pages it needs in
kernel disk cache, because they were all read in by the first query.
This has little to do with cursor versus non cursor, and everything
to do with hitting recently-read data again.

			regards, tom lane

-- 
Alban Médici
R&D software engineer
------------------------------
you can contact me @ :
http://www.netcentrex.net
------------------------------

--------------030409030803050401070308-- From tgl@sss.pgh.pa.us Fri Oct 8 13:56:04 2004 X-Original-To: pgsql-benchmarks-postgresql.org@localhost.postgresql.org Received: from localhost (unknown [200.46.204.144]) by svr1.postgresql.org (Postfix) with ESMTP id 27CDB32A090; Fri, 8 Oct 2004 14:56:04 +0100 (BST) Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org [200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 27480-02; Fri, 8 Oct 2004 13:55:54 +0000 (GMT) Received: from sss.pgh.pa.us (sss.pgh.pa.us [66.207.139.130]) by svr1.postgresql.org (Postfix) with ESMTP id AFDC4329E3E; Fri, 8 Oct 2004 14:55:57 +0100 (BST) Received: from sss2.sss.pgh.pa.us (tgl@localhost [127.0.0.1]) by sss.pgh.pa.us (8.13.1/8.13.1) with ESMTP id i98DtuVB011895; Fri, 8 Oct 2004 09:55:57 -0400 (EDT) To: =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= Cc: pgsql-benchmarks@postgresql.org, pgsql-performance@postgresql.org Subject: Re: [PERFORM] stats on cursor and query execution troubleshooting In-reply-to: <4166542E.2020809@fr.netcentrex.net> References: <4163C5C3.3030304@fr.netcentrex.net> <25576.1097072199@sss.pgh.pa.us> <4166542E.2020809@fr.netcentrex.net> Comments: In-reply-to =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= message dated "Fri, 08 Oct 2004 10:47:42 +0200" Date: Fri, 08 Oct 2004 09:55:56 -0400 Message-ID: <11894.1097243756@sss.pgh.pa.us> From: Tom Lane X-Virus-Scanned: by amavisd-new at hub.org X-Spam-Status: No, hits=0.0 tagged_above=0.0 required=5.0 tests= X-Spam-Level: X-Archive-Number: 200410/4 X-Sequence-Number: 21 =?ISO-8859-1?Q?=22Alban_M=E9dici_=28NetCentrex=29=22?= writes: > Thanks for your repply, but I still don"t understand why the statistic > logs : > ! 0/0 [0/0] filesystem blocks in/out > it told me there is no hard disk access, I'm sure there is, Complain to your friendly local kernel hacker. We just report what getrusage() tells us; so if the number is wrong then it's a kernel bug. regards, tom lane