Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1VoaBl-0000EN-9q for pgsql-performance@arkaria.postgresql.org; Thu, 05 Dec 2013 14:46:01 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.80) (envelope-from ) id 1VoaBj-0002TS-SQ for pgsql-performance@arkaria.postgresql.org; Thu, 05 Dec 2013 14:45:59 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1Voa9i-0007xw-4m for pgsql-performance@postgresql.org; Thu, 05 Dec 2013 14:43:54 +0000 Received: from nm27-vm3.bullet.mail.ne1.yahoo.com ([98.138.91.157]) by magus.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1Voa9e-0000iV-CE for pgsql-performance@postgresql.org; Thu, 05 Dec 2013 14:43:53 +0000 Received: from [98.138.100.113] by nm27.bullet.mail.ne1.yahoo.com with NNFMP; 05 Dec 2013 14:43:48 -0000 Received: from [98.138.89.169] by tm104.bullet.mail.ne1.yahoo.com with NNFMP; 05 Dec 2013 14:43:48 -0000 Received: from [127.0.0.1] by omp1025.mail.ne1.yahoo.com with NNFMP; 05 Dec 2013 14:43:48 -0000 X-Yahoo-Newman-Property: ymail-3 X-Yahoo-Newman-Id: 171735.42274.bm@omp1025.mail.ne1.yahoo.com Received: (qmail 1909 invoked by uid 60001); 5 Dec 2013 14:43:48 -0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s1024; t=1386254628; bh=tqKVWrMRT1CpjDsdAn5lZKBXaXwkqDPeKsB2P140ENs=; h=X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type; b=VqmyTKYK1gQZ2Fl/VIkCiHdYcHzU4sGMLdDRX9pi7q68D/VXL1QJaIyjV/jXKwy/tOHrTeFKuHSyP0IzxDbTXniiefZD6mRBZ4O3LOeB4QaWquxJUEUPHzmEAZC0W/4y5oT0gtPVLPOVSJTOdaosZLHjZWR8WeKhUHfWgviNLgY= DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com; h=X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type; b=Hec3Evd+cY3AdksRyaAQ8CijzKpEoYeQy7rusg8h8TGn8zHAX5AXrNGvDrb3lAoL1ZpYY57RZTP/HgN5Wwgkbv50Ya53GQWzL2Vx1L1763tNCwDtKubZR1wMGGP9QH1PEFzJdocsOERcGyRhTmzIZ4yezERcXxZsMVkcKj9I1Hs=; X-YMail-OSG: hanL8kMVM1lT8J08WvZj_PJ.7ZYsln4pX5h5Ru4z.TF6G56 JdkKZDn0ZernYk9vPlfw6_WTRGK3dcs9OQ_ZZuY5bYwrMGbddnIiXGmADsXj fyfvBmvJ177dxX11HOvahK18UBTYyKIJWVnyNHB5eZ0xOncwQhkGjWXt4jql p0YeEj.dKuIYISvimqi65hz1Bm7PAVUHjZjHGsvlVqn0xvonsjkzjrSTkYWT qevmQbqmDpnxVsQ7KG4edtPBIpz0ICLLE_QbwEDM0jM.w.ssNMqRFDRSj0SQ O_qSdMuJEUjo6FhTeJ.zmUTt0LlIHM0ErtQkW0tfaOINC4ISZop9.71JQgVN z6tp7jf_gqxHG3vKK._F87UDeVv.Gue2jd7LmQMSnWHtGqzFhhDCpEse9DUi OP3isFPOvB59DpPmsxk1h6EK0j4a4S5gGPGnn_Mrw08WkzJaOTKiZCAQJjQ5 r7hpn7PPA.XtJruspBE9dUiX_kZhupbpA6EBiNH_cjR981JYI8DpGm5SvGq. Hj.fE5CJCWSd18zaECndXQ4FsbmyerJD1DBPRP1T_VPzuy2JQlfyPDxQCRK8 nQjoeKIM7WA-- Received: from [80.152.211.89] by web122205.mail.ne1.yahoo.com via HTTP; Thu, 05 Dec 2013 06:43:47 PST X-Rocket-MIMEInfo: 002.001, SGVsbG8gVG9tLAoKVGhlIGhhcmR3YXJlIGlzIHByZXR0eSBnb29kLCBJIGhhdmUgOCBjcHVzIG9mIEludGVsKFIpIENvcmUoVE0pIGk3LCAyLjQgR0ggLCBhbmQgMTYgR2liIG9mIFJBTS4gSXMgdGhlcmUgYW55IGNvbmZpZ3VyYXRpb24gcGFyYW1ldGVyIHRoYXQgY2FuIGxlYWQgdG8gdGhpcyBpc3N1ZS4KClJlZ2FyZHMKCgoKCgpPbiBUaHVyc2RheSwgRGVjZW1iZXIgNSwgMjAxMyAzOjIzIFBNLCB2aW5jZW50IGVsc2Nob3QgPHZpbm55QHhzNGFsbC5ubD4gd3JvdGU6CiAKCgpPbiAwNS0xMi0xMyAxNTowOSwBMAEBAQE- X-Mailer: YahooMailWebService/0.8.169.609 References: <1386252540.32882.YahooMailNeo@web122206.mail.ne1.yahoo.com> <52A08BE0.9080504@xs4all.nl> Message-ID: <1386254627.81908.YahooMailNeo@web122205.mail.ne1.yahoo.com> Date: Thu, 5 Dec 2013 06:43:47 -0800 (PST) From: salah jubeh Reply-To: salah jubeh Subject: Re: Explain analyze time overhead To: vincent elschot , "pgsql-performance@postgresql.org" In-Reply-To: <52A08BE0.9080504@xs4all.nl> MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="-1522790894-336544143-1386254627=:81908" X-Pg-Spam-Score: -2.0 (--) List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-performance Precedence: bulk Sender: pgsql-performance-owner@postgresql.org ---1522790894-336544143-1386254627=:81908 Content-Type: text/plain; charset=iso-8859-1 Content-Transfer-Encoding: quoted-printable Hello Tom,=0A=0AThe hardware is pretty good, I have 8 cpus of Intel(R) Core= (TM) i7, 2.4 GH , and 16 Gib of RAM. Is there any configuration parameter t= hat can lead to this issue.=0A=0ARegards=0A=0A=0A=0A=0A=0AOn Thursday, Dece= mber 5, 2013 3:23 PM, vincent elschot wrote:=0A =0A=0A=0A= On 05-12-13 15:09, salah jubeh wrote:=0A=0A=0A>=0A>Hello guys, =0A>=0A>=0A>= =0A>When I excute a query,=A0 the exection time is about 1 minute; however,= when I execute the query with explain analyze the excution time jumps to 1= 0 minutes. =0A>=0A>I have tried this for several queries, where=A0 I need t= o optimize;=A0 and using explain analyze leads alway to a huge time overhea= d in factor of 10.=0A>=0A>=0A>=0A>This is a little bit starnge for me; did = any one experience somthing like this? Can I trust the generated plans?=0A>= =0A>=0A>=0A>Regards=0AExplain analyze does a lot more work than just explai= ning the query,=0A it excecutes it and takes not of how long things actu= ally took,=0A which itself takes time. Apparently on some machines, it c= an take=0A much longer than just executing the query would take.=0A=0AFr= om the manual:=0A=0A"In order to measure the run-time cost of each node in = the execution plan, the current implementation of=A0EXPLAIN ANALYZE=A0adds = profiling overhead to query execution. As a result, running=A0EXPLAIN ANALY= ZE=A0on a query can sometimes take significantly longer than executing the = query normally. The amount of overhead depends on the nature of the query, = as well as the platform being used. The worst case occurs for plan nodes th= at in themselves require very little time per execution, and on machines th= at have relatively slow operating system calls for obtaining the time of da= y." ---1522790894-336544143-1386254627=:81908 Content-Type: text/html; charset=iso-8859-1 Content-Transfer-Encoding: quoted-printable
Hello Tom,
=
The hardware is pretty good, I have 8 cpus of Intel(R) C= ore(TM) i7, 2.4 GH , and 16 Gib of RAM. Is there any configuration paramete= r that can lead to this issue.

Regards



<= div class=3D"yiv3249516174yui_3_13_0_ym1_1_1386252066335_8765" style=3D"font-f= amily:HelveticaNeue, Helvetica Neue, Helvetica, Arial, Lucida Grande, sans-= serif;font-size:10pt;">
On Thursday, December 5, 2013 3:23 PM, vincent = elschot <vinny@xs4all.nl> wrote:
<= div class=3D"yiv3249516174y_msg_container">
= =0A
=0A
On= 05-12-13 15:09, salah jubeh wrote:
=0A
=0A <= blockquote type=3D"cite">=0A
=0A

=0A
=0A =
Hello=0A guys,
= =0A
=0A

=0A =
=0A
When I=0A excute a q= uery,  the exection time is about 1 minute; however,=0A when = I execute the query with explain analyze the excution=0A time jump= s to 10 minutes.
=0A
=0A
I have=0A tried this for several queries, where = I need to optimize; =0A and using explain analyze leads alwa= y to a huge time overhead=0A in factor of 10.
= =0A
=0A

=0A =
=0A
This is a=0A little = bit starnge for me; did any one experience somthing=0A like this? = Can I trust the generated plans?
=0A
=0A =

=0A
=0A =
Regards
=0A
=0A =0A
=0A Explain analyze does a lot more work th= an just explaining the query,=0A it excecutes it and takes not of how lo= ng things actually took,=0A which itself takes time. Apparently on some = machines, it can take=0A much longer than just executing the query would= take.
=0A
=0A From the manual:<= br clear=3D"none">=0A
"In order to measur= e the run-time cost of each node=0A in the execution plan, the current= implementation of = EXPLAIN ANALYZE adds=0A profiling ov= erhead to query execution. As a result, running EXPLAIN ANALYZE on a=0A query can sometimes take significantly longer than executi= ng the=0A query normally. The amount of overhead depends on the nature= of=0A the query, as well as the platform being used. The worst case= =0A occurs for plan nodes that in themselves require very little time= =0A per execution, and on machines that have relatively slow operating= =0A system calls for obtaining the time of day."
=0A=
=0A
=0A =0A


---1522790894-336544143-1386254627=:81908--