Skip site navigation (1) Skip section navigation (2)

Change in Log Format and Prepared Statements

From: Alexander Stanier <alexander(dot)stanier(at)egsgroup(dot)com>
To: pgsql-jdbc(at)postgresql(dot)org
Subject: Change in Log Format and Prepared Statements
Date: 2012-09-13 12:47:22
Message-ID: 5051D5DA.8050404@egsgroup.com (view raw or flat)
Thread:
Lists: pgsql-jdbc
Hi,

Over the past year we have performed upgrades to both our PostgreSQL 
server our jdbc driver over the last few months:

 From PostgreSQL 8.2.10 with pg74.216.jdbc3 driver
To PostgreSQL 8.2.10 with pg8.2-511.jdbc4 driver
To PostgreSQL 9.1.4 with pg9.1-902.jdbc4 driver

(O/S is Centos 5)

When we moved from the pg74.216.jdbc3 driver to the pg8.2-511.jdbc4 we 
saw a distinct change in the logging output by the database.

Previously with the pg74.216.jdbc3 driver we saw the statement followed 
by a duration:

2012-09-13 13:08:48 BST [22116] [mp_demo] [pg] LOG:  statement: SELECT 
users.USERID, users.LOGINID, users.ORGID, users.FIRSTNAME, 
users.LASTNAME, users.TITLE, users.TELEPHONE, users.CELLPHONE, 
users.PAGER, users.FAX, users.EMAIL, users.LASTLOGIN, users.ADDRESSID, 
users.USERSTATUSID, users.SHARED, users.MODDATE, users.ISPROXY FROM 
users WHERE users.LOGINID='alex-admin';
2012-09-13 13:08:48 BST [22116] [mp_demo] [pg] LOG:  duration: 0.805 ms

Now with the pg8.2-511.jdbc4 and pg9.1-902.jdbc4 drivers we see the 
statement issued as an execute and three durations:

2012-09-13 13:07:33 BST [21664] [mp_demo] [pg] LOG:  execute <unnamed>: 
SELECT users.USERID, users.LOGINID, users.ORGID, users.FIRSTNAME, 
users.LASTNAME, users.TITLE, users.TELEPHONE, users.CELLPHONE, 
users.PAGER, users.FAX, users.EMAIL, users.LASTLOGIN, users.ADDRESSID, 
users.USERSTATUSID, users.SHARED, users.MODDATE, users.ISPROXY FROM 
users WHERE users.LOGINID='alex-admin'
2012-09-13 13:07:33 BST [21664] [mp_demo] [pg] LOG:  duration: 0.208 ms
2012-09-13 13:07:33 BST [21664] [mp_demo] [pg] LOG:  duration: 1.136 ms
2012-09-13 13:07:33 BST [21664] [mp_demo] [pg] LOG:  duration: 0.156 ms

Indeed we still see the former if I run the same statement direct from 
psql. So it looks to me as though the later drivers may be making use of 
prepared statements (hence the "execute"?) but why do we now see 3 
durations?

Also, as far as I can every single statement coming from the jdbc driver 
is being issued as "execute <unnamed>: ......". Even BEGIN, COMMIT and 
ROLLBACK statements are being issued in the same way and result in 2 or 
3 duration statements. Is this normal?

If so, I am not convinced that we really want to use prepared statements 
all the time, as it doesn't appear that statements are being repeated 
(repetition being my understanding of why you would want to make use of 
prepared statements). After looking at the documentation, I have tried 
using the prepareThreshold parameter on the connection string in my 
Tomcat server.xml (Tomcat v.6.0.29) to disable prepared statements, e.g.:

url="jdbc:postgresql://servername:5434/mp_demo?prepareThreshold=0"

.....but this doesn't seem to have any effect. Could anyone tell me what 
is going on and how to effectively control this jdbc behaviour? I am 
concerned the continual use of prepared statements for one-time-only 
statements could be a performance drain on our system.

Alex Stanier.


This message has been scanned for malware by SurfControl plc. www.surfcontrol.com


Responses

pgsql-jdbc by date

Next:From: Dave CramerDate: 2012-09-13 19:24:36
Subject: Re: Change in Log Format and Prepared Statements
Previous:From: Dave CramerDate: 2012-09-13 12:34:26
Subject: Re: Bug : FAST_NUMBER_FAILED when getting NaN on BigDecimal

Privacy Policy | About PostgreSQL
Copyright © 1996-2014 The PostgreSQL Global Development Group