Received: from maia.hub.org (maia-3.hub.org [200.46.204.243]) by mail.postgresql.org (Postfix) with ESMTP id 5C4991337BEA for ; Thu, 13 Jan 2011 10:13:41 -0400 (AST) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.243]) (amavisd-maia, port 10024) with ESMTP id 50316-01-9 for ; Thu, 13 Jan 2011 14:13:33 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from smadev.internal.net (host3.dynacom.ondsl.gr [62.103.35.211]) by mail.postgresql.org (Postfix) with ESMTP id 76CE61337C1E for ; Thu, 13 Jan 2011 10:13:23 -0400 (AST) Received: from smadev.internal.net (localhost.internal.net [127.0.0.1]) by smadev.internal.net (8.14.2/8.14.2) with ESMTP id p0DEDNJt092132 for ; Thu, 13 Jan 2011 16:13:23 +0200 (EET) (envelope-from achill@matrix.gatewaynet.com) Received: from localhost (localhost [[UNIX: localhost]]) by smadev.internal.net (8.14.2/8.14.2/Submit) id p0DEDNCq092131 for pgsql-admin@postgresql.org; Thu, 13 Jan 2011 16:13:23 +0200 (EET) (envelope-from achill@matrix.gatewaynet.com) From: Achilleas Mantzios Organization: Dynacom Tankers Mgmt To: pgsql-admin@postgresql.org Subject: Re: Postgresql 9.0.2 explain analyze very slow (10x), compared to actual query time Date: Thu, 13 Jan 2011 16:13:23 +0200 User-Agent: KMail/1.9.7 References: <201101111753.22602.achill@matrix.gatewaynet.com> <201101121817.11143.achill@matrix.gatewaynet.com> <27365.1294850720@sss.pgh.pa.us> In-Reply-To: <27365.1294850720@sss.pgh.pa.us> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-7" Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Message-Id: <201101131613.23428.achill@matrix.gatewaynet.com> X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-0.451 tagged_above=-10 required=5 tests=BAYES_00=-1.9, RCVD_IN_BRBL_LASTEXT=1.449 X-Spam-Level: X-Archive-Number: 201101/69 X-Sequence-Number: 36509 =D3=F4=E9=F2 Wednesday 12 January 2011 18:45:20 =EF/=E7 Tom Lane =DD=E3=F1= =E1=F8=E5: > Achilleas Mantzios writes: > > =D3=F4=E9=F2 Wednesday 12 January 2011 17:07:53 =EF/=E7 Tom Lane =DD=E3= =F1=E1=F8=E5: > >> Right offhand I'd wonder whether that was more bound by gettimeofday or > >> by printf. Please try it without printf in the loop. >=20 > > Changed that to smth like: micros_total =3D micros_total + (double) mic= ros; > > instead of the printf to beat any compiler optimization, and still linu= x runs at light speed: > > FBSD_TEST : user 0.089s, sys 1.4s > > FBSD_DEV : user 0.183s, sys 3.8s > > LINUX_PROD : user 0.168s, sys 0s >=20 > Well, there's your problem all right: the FBSD_DEV system takes 22X > longer to execute gettimeofday() than the LINUX_PROD system. The > particular plan that 9.0 is choosing is especially vulnerable to this > because it involves a whole lot of calls of the Materialize plan node: >=20 You are absolutely right! Changing kern.timecounter.hardware=3DTSC (from ACPI-fast) *solved* the slow= explain analyze effect. Now i get reasonable EXPLAIN ANALYZE times! It also helps to be running > an OS that is able to read the clock in userspace without invoking a > kernel call. It looks like your Linux box is winning on both counts > compared to your BSD boxes. Next step, if i am lucky tonight, i'll set up a new linux box with 9.0.2 an= d load=20 the same small (coming from FBSD_DEV) database. So my problem was twofold : a) EXPLAIN ANALYZE performance, b) the particul= ar slow query. It seems there is only b) to solve. (see the previous email) A lot of thanx (but stay tuned ;) >=20 > regards, tom lane >=20 =2D-=20 Achilleas Mantzios