From: Josh Berkus <josh@agliodbs.com>
To: pgsql-performance@postgresql.org
Subject: Performance bug in prepared statement binding in 9.2?
Date: Wed, 29 May 2013 17:14:30 -0700
Message-ID: <51A699E6.3000008@agliodbs.com> (raw)
List-Unsubscribe: <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>
Folks,
I'm seeing what may be a major performance bug in BIND in 9.2.4.
We have a client who has an application which uses
Tomcat+Hibernate+JDBC. They are in the process of upgrading this
application from 8.4.17 to 9.2.4. As part of this, they have been doing
performance testing, and 9.2 is coming out MUCH worse than 8.4. The
problem appears to be bind/plan time.
Their application does not use prepared queries usefully, doing
parse,bind,execute on every query cycle.
Here's timings overall for 29 test cycles (cycle 1 has been omitted).
As you can see, parse+execute times are pretty much constant, as are
application think times, but bind times vary quite a lot. In 8.4, the
29 cycles are constantly 4.5min to 5.75min long. In 9.2, which is the
chart below, they are all over the place.
Definitions:
cycle: test cycle #, arbitrary. Each cycle does the same amount of
"work" measured in rows of data.
non_bind_time: time spent in PARSE and EXECUTE.
bind_time: time spent in BIND
app_time: time spent outside Postgres
all times are in minutes:
cycle | non_bind_time | bind_time | app_time | total_time
-------+---------------+-----------+----------+------------
2 | 0.79 | 0.62 | 3.19 | 4.60
3 | 0.77 | 0.87 | 3.13 | 4.77
4 | 0.76 | 1.10 | 3.16 | 5.02
5 | 0.76 | 1.26 | 3.08 | 5.10
6 | 0.72 | 1.40 | 3.08 | 5.20
7 | 0.72 | 1.51 | 3.05 | 5.28
8 | 0.70 | 1.60 | 3.07 | 5.37
9 | 0.73 | 1.72 | 3.05 | 5.50
10 | 0.71 | 1.84 | 3.05 | 5.60
11 | 0.70 | 1.96 | 3.07 | 5.73
12 | 0.74 | 2.11 | 3.08 | 5.93
13 | 0.74 | 3.58 | 3.08 | 7.40
14 | 0.73 | 2.41 | 3.08 | 6.22
15 | 0.75 | 4.15 | 3.08 | 7.98
16 | 0.74 | 2.69 | 3.09 | 6.52
17 | 0.76 | 4.68 | 3.09 | 8.53
18 | 0.74 | 2.99 | 3.09 | 6.82
19 | 0.77 | 5.24 | 3.11 | 9.12
20 | 0.75 | 3.29 | 3.08 | 7.12
21 | 0.78 | 5.90 | 3.14 | 9.82
22 | 0.78 | 3.57 | 3.12 | 7.47
23 | 0.76 | 6.17 | 3.10 | 10.03
24 | 0.77 | 6.61 | 3.10 | 10.48
25 | 0.77 | 3.97 | 3.11 | 7.85
26 | 0.77 | 5.24 | 3.12 | 9.13
27 | 0.76 | 7.15 | 3.12 | 11.03
28 | 0.76 | 4.37 | 3.10 | 8.23
29 | 0.78 | 4.48 | 3.12 | 8.38
30 | 0.76 | 7.73 | 3.11 | 11.60
I pulled out some of the queries with the greatest variance in bind
time. Unexpectedly, they are not particularly complex. Here's the
anonymized plan for a query which in the logs took 80ms to bind:
http://explain.depesz.com/s/YSj
Nested Loop (cost=8.280..26.740 rows=1 width=289)
-> Nested Loop (cost=8.280..18.450 rows=1 width=248)
-> Hash Join (cost=8.280..10.170 rows=1 width=140)
Hash Cond: (foxtrot2kilo_oscar.quebec_seven =
kilo_juliet1kilo_oscar.sierra_quebec)
-> Seq Scan on foxtrot november (cost=0.000..1.640
rows=64 width=25)
-> Hash (cost=8.270..8.270 rows=1 width=115)
-> Index Scan using quebec_six on victor_india
sierra_oscar (cost=0.000..8.270 rows=1 width=115)
Index Cond: (quebec_seven = 10079::bigint)
-> Index Scan using alpha on seven_tango lima
(cost=0.000..8.270 rows=1 width=108)
Index Cond: ((xray = 10079::bigint) AND (golf =
10002::bigint))
-> Index Scan using six on india victor_romeo (cost=0.000..8.280
rows=1 width=41)
Index Cond: (quebec_seven = seven_victor0kilo_oscar.delta)
As you can see, it's not particularly complex; it only joins 4 tables,
and it has 2 parameters. This database does have some horrible ugly
queries with up to 500 parameters, but inexplicably those don't take a
particularly long time to bind.
Note that I have not been able to reproduce this long bind time
interactively, but it's 100% reproducable in the test.
--
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-performance@postgresql.org
Cc: josh@agliodbs.com
Subject: Re: Performance bug in prepared statement binding in 9.2?
In-Reply-To: <51A699E6.3000008@agliodbs.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox