Thread: difference on execution time between prepared statement in pgAdmin and through JDBC Stack

difference on execution time between prepared statement in pgAdmin and through JDBC Stack

From

Lars Feistner

Date:

24 February 2011, 18:41:09

Hello everyone,

i am puzzled like many other users of this list before. I read a lot of
old threads today, but nothing seemed to explain what i see in my log files.

I am using Postgres 9 on linux and the appropriate JDBC driver for this
database. I can also see the same behaviour on production system running
postgres 8.4.

My query:

prepare t1 (int4, int4) AS
  SELECT DISTINCT vec.*, s.statistic_difficulty as examination_difficulty,
  s.statistic_discriminatorypower as examination_discriminatorypower,
  vimc.mediacount,vis.difficulty, vis.discriminatorypower,
vis.statistic_counter, virc.reviewcount, u.user_surname
  FROM ims_vexaminationcontent vec
  LEFT OUTER JOIN ims_statistic s ON vec.item_id = s.object_id AND
s.examination_id = vec.examination_id
  LEFT OUTER JOIN ims_vitemmediacount vimc ON (vimc.item_id = vec.item_id)
  LEFT OUTER JOIN ims_vitemstatistic vis ON (vis.item_id = vec.item_id)
  INNER JOIN ims_user u on (author_id = u.user_id)
  LEFT OUTER JOIN ims_vitemreviewcount virc ON virc.item_id = vec.item_id
  WHERE ((vec.examinationcontentversion_version=1 AND
vec.examination_entityid=7429))
  ORDER BY vec.examinationcontentversion_sequenceno ASC NULLS LAST

and following execute t1 (1,7429); runs in approx. 100 ms.

If a run the same query through my web application (using the same
parameters) my server log file tells me the statement takes approx.
1100ms. This is factor 10!

duration: 1151.088 ms  execute <unnamed>: SELECT DISTINCT vec.*,
s.statistic_difficulty as examination_difficulty,
s.statistic_discriminatorypower as examination_discriminatorypower,
vimc.mediacount,vis.difficulty, vis.discriminatorypower,
vis.statistic_counter, virc.reviewcount, u.user_surname FROM
ims_vexaminationcontent vec LEFT OUTER JOIN ims_statistic s ON
vec.item_id = s.object_id AND s.examination_id = vec.examination_id LEFT
OUTER JOIN ims_vitemmediacount vimc ON (vimc.item_id = vec.item_id) LEFT
OUTER JOIN ims_vitemstatistic vis ON (vis.item_id = vec.item_id) INNER
JOIN ims_user u on (author_id = u.user_id) LEFT OUTER JOIN
ims_vitemreviewcount virc ON virc.item_id = vec.item_id WHERE
((vec.examinationcontentversion_version=$1 AND
vec.examination_entityid=$2)) ORDER BY
vec.examinationcontentversion_sequenceno ASC NULLS LAST LIMIT
2011-02-24 15:22:16 CET DETAIL:  parameters: $1 = '1', $2 = '7429'

As you can see the application uses unnamed prepared statements which i
learnt today executes query planning everytime the statement runs and
after the variables are bound.

So i don't understand the difference between running the query through
the jdbc stack.

Thank you for any helpful link or explanation in advance.

Lars

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Lars Feistner

Kompetenzzentrum für Prüfungen in der Medizin
Medizinische Fakultät Heidelberg,
Im Neuenheimer Feld 346, Raum 013
69120 Heidelberg

E-Mail: feistner@uni-heidelberg.de
Fon:   +49-6221-56-8269
Fax:   +49-6221-56-7175

WWW:   http://www.ims-m.de
        http://www.kompmed.de
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Re: difference on execution time between prepared statement in pgAdminand through JDBC Stack

From

jerome.moliere@gmail.com

Date:

24 February 2011, 19:08:23

Hi lars do you execute this query from jdbc code or is it generated through any jpa hibernate or any other layer? Do
youuse the same db with same volume of data? I would think that you may have binding parameters problems.regards
 
---- Envoyé avec BlackBerry® d'Orange ----

-----Original Message-----
From: Lars Feistner <feistner@uni-heidelberg.de>
Sender: pgsql-jdbc-owner@postgresql.orgDate: Thu, 24 Feb 2011 20:10:16 
To: <pgsql-jdbc@postgresql.org>
Subject: [JDBC] difference on execution time between prepared statement in pgAdmin
 and through JDBC Stack

Hello everyone,

i am puzzled like many other users of this list before. I read a lot of 
old threads today, but nothing seemed to explain what i see in my log files.

I am using Postgres 9 on linux and the appropriate JDBC driver for this 
database. I can also see the same behaviour on production system running 
postgres 8.4.

My query:

prepare t1 (int4, int4) AS
  SELECT DISTINCT vec.*, s.statistic_difficulty as examination_difficulty,
  s.statistic_discriminatorypower as examination_discriminatorypower,
  vimc.mediacount,vis.difficulty, vis.discriminatorypower, 
vis.statistic_counter, virc.reviewcount, u.user_surname
  FROM ims_vexaminationcontent vec
  LEFT OUTER JOIN ims_statistic s ON vec.item_id = s.object_id AND 
s.examination_id = vec.examination_id
  LEFT OUTER JOIN ims_vitemmediacount vimc ON (vimc.item_id = vec.item_id)
  LEFT OUTER JOIN ims_vitemstatistic vis ON (vis.item_id = vec.item_id)
  INNER JOIN ims_user u on (author_id = u.user_id)
  LEFT OUTER JOIN ims_vitemreviewcount virc ON virc.item_id = vec.item_id
  WHERE ((vec.examinationcontentversion_version=1 AND 
vec.examination_entityid=7429))
  ORDER BY vec.examinationcontentversion_sequenceno ASC NULLS LAST

and following execute t1 (1,7429); runs in approx. 100 ms.

If a run the same query through my web application (using the same 
parameters) my server log file tells me the statement takes approx. 
1100ms. This is factor 10!

duration: 1151.088 ms  execute <unnamed>: SELECT DISTINCT vec.*, 
s.statistic_difficulty as examination_difficulty, 
s.statistic_discriminatorypower as examination_discriminatorypower, 
vimc.mediacount,vis.difficulty, vis.discriminatorypower, 
vis.statistic_counter, virc.reviewcount, u.user_surname FROM 
ims_vexaminationcontent vec LEFT OUTER JOIN ims_statistic s ON 
vec.item_id = s.object_id AND s.examination_id = vec.examination_id LEFT 
OUTER JOIN ims_vitemmediacount vimc ON (vimc.item_id = vec.item_id) LEFT 
OUTER JOIN ims_vitemstatistic vis ON (vis.item_id = vec.item_id) INNER 
JOIN ims_user u on (author_id = u.user_id) LEFT OUTER JOIN 
ims_vitemreviewcount virc ON virc.item_id = vec.item_id WHERE 
((vec.examinationcontentversion_version=$1 AND 
vec.examination_entityid=$2)) ORDER BY 
vec.examinationcontentversion_sequenceno ASC NULLS LAST LIMIT
2011-02-24 15:22:16 CET DETAIL:  parameters: $1 = '1', $2 = '7429'

As you can see the application uses unnamed prepared statements which i 
learnt today executes query planning everytime the statement runs and 
after the variables are bound.

So i don't understand the difference between running the query through 
the jdbc stack.

Thank you for any helpful link or explanation in advance.

Lars

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Lars Feistner

Kompetenzzentrum für Prüfungen in der Medizin
Medizinische Fakultät Heidelberg,
Im Neuenheimer Feld 346, Raum 013
69120 Heidelberg

E-Mail: feistner@uni-heidelberg.de
Fon:   +49-6221-56-8269
Fax:   +49-6221-56-7175

WWW:   http://www.ims-m.de
        http://www.kompmed.de
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

-- 
Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-jdbc