Re: [PERFORM] BUG: endless lseek(.., SEEK_END) from select queries on x64 builds
On 22.02.2013 20:10, Markus Schulz wrote:
Am Freitag, 22. Februar 2013, 14:35:25 schrieb Heikki Linnakangas:
You could check what the generic plan looks like by taking the query
used in the java program, with the parameter markers, and running
EXPLAIN on that.
how can i do this?
I've tried the following in my ejb-test-function to:
String query = ...
entitymanager.createNativeQuery(query)...;
entitymanager.createNativeQuery(EXPLAIN ANALYZE + query)...;
but the second createNativeQuery call runs fast every time and will show the
same plan and the first hangs after the fourth call to this function.
You can take the query, replace the ? parameter markers with $1, $2, and
so forth, and explain it with psql like this:
prepare foo (text) as select * from mytable where id = $1;
explain analyze execute foo ('foo');
On 9.2, though, this will explain the specific plan for those
parameters, so it might not be any different from what you already
EXPLAINed.
- Heikki
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] BUG: endless lseek(.., SEEK_END) from select queries on x64 builds
Heikki Linnakangas hlinnakan...@vmware.com writes:
You can take the query, replace the ? parameter markers with $1, $2, and
so forth, and explain it with psql like this:
prepare foo (text) as select * from mytable where id = $1;
explain analyze execute foo ('foo');
On 9.2, though, this will explain the specific plan for those
parameters, so it might not be any different from what you already
EXPLAINed.
You can tell whether you're getting a generic or custom plan by noting
whether the explain output contains $n symbols or the values you put in.
In 9.2, the first five attempts will always produce custom plans, but
on the sixth and subsequent attempts you will get a generic plan, if
the plancache logic decides that it's not getting any benefit out of
custom plans. Here's a trivial example:
regression=# prepare foo(int) as select * from tenk1 where unique1 = $1;
PREPARE
regression=# explain execute foo(42);
QUERY PLAN
-
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = 42)
(2 rows)
regression=# explain execute foo(42);
QUERY PLAN
-
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = 42)
(2 rows)
regression=# explain execute foo(42);
QUERY PLAN
-
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = 42)
(2 rows)
regression=# explain execute foo(42);
QUERY PLAN
-
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = 42)
(2 rows)
regression=# explain execute foo(42);
QUERY PLAN
-
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = 42)
(2 rows)
regression=# explain execute foo(42);
QUERY PLAN
-
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = $1)
(2 rows)
It's switched to a generic plan after observing that the custom plans
weren't any cheaper. Once that happens, subsequent attempts will use
the generic plan. (Of course, in a scenario where the custom plans do
provide a benefit, it'll keep using those.)
regards, tom lane
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
[PERFORM] BUG: endless lseek(.., SEEK_END) from select queries on x64 builds
hello,
i have a strange and reproducible bug with some select queries and 64bit
postgresql builds (works fine on 32bit builds).
The postgres process will run with 100% cpu-load (no io-wait) and strace
will show endless lseek(..., SEEK_END) calls on one table for minutes.
lseek(28, 0, SEEK_END) = 26697728
lseek(28, 0, SEEK_END) = 26697728
lseek(28, 0, SEEK_END) = 26697728
...
the file-descriptor 28 points to the file for the webapps_base.Acquisition
table (see query/plan below).
Now the details:
The Query:
select count(ac.ID) as col_0_0_ from
webapps_base.Acquisition ac,
webapps_base.SalesPartnerStructure struc
where
struc.fk_SalesPartner_child=ac.fk_SalesPartner_ID
and struc.fk_SalesPartner_parent=200
and (ac.CreationDate between '2012-02-01' and '2013-01-31')
and ac.acquisitiondepot='STANDARD'
and ('2013-01-31' between struc.ValidFrom
and coalesce(struc.ValidTo, '2013-01-31'))
The Plan:
Aggregate (cost=32617.11..32617.12 rows=1 width=8) (actual
time=204.180..204.180 rows=1 loops=1)
- Merge Join (cost=32232.01..32598.26 rows=7543 width=8) (actual
time=172.882..202.218 rows=2 loops=1)
Merge Cond: (ac.fk_salespartner_id = struc.fk_salespartner_child)
- Sort (cost=5582.60..5635.69 rows=21235 width=16) (actual
time=28.920..31.121 rows=21204 loops=1)
Sort Key: ac.fk_salespartner_id
Sort Method: quicksort Memory: 1763kB
- Bitmap Heap Scan on acquisition ac (cost=395.26..4056.43
rows=21235 width=16) (actual time=3.064..15.868 rows=21223 loops=1)
Recheck Cond: ((creationdate = '2012-02-01'::date) AND
(creationdate = '2013-01-31'::date))
Filter: ((acquisitiondepot)::text = 'STANDARD'::text)
- Bitmap Index Scan on index_acquistion_creationdate
(cost=0.00..389.95 rows=21267 width=0) (actual time=2.890..2.890 rows=21514
loops=1)
Index Cond: ((creationdate = '2012-02-01'::date)
AND (creationdate = '2013-01-31'::date))
- Sort (cost=26648.60..26742.61 rows=37606 width=8) (actual
time=143.952..152.808 rows=131713 loops=1)
Sort Key: struc.fk_salespartner_child
Sort Method: quicksort Memory: 8452kB
- Bitmap Heap Scan on salespartnerstructure struc
(cost=3976.80..23790.79 rows=37606 width=8) (actual time=13.279..64.681
rows=114772 loops=1)
Recheck Cond: (fk_salespartner_parent = 200)
Filter: (('2013-01-31'::date = validfrom) AND
('2013-01-31'::date = COALESCE(validto, '2013-01-31'::date)))
- Bitmap Index Scan on index_parent_salespartner
(cost=0.00..3967.39 rows=114514 width=0) (actual time=13.065..13.065
rows=116479 loops=1)
Index Cond: (fk_salespartner_parent = 200)
Total runtime: 205.397 ms
as you can see the query runs fine.
I can run this query from a bash-psql-while-loop/jdbc-cli-tool
endless without any problems.
so far so good.
But now i run the same query from:
JBoss EAP 5.1.2 with connection pooling and xa-datasource/two-phase-commits
(transactions on multiple datasources needed)
*and* *prepared-statement-cache-size1000/prepared-statement-cache-size*
i can run the query four times with good performance and after that postgresql
starts with the strange lseek() behavior.
The query needs more then a minute to complete and during execution the
postgres process runs at 100% cpu load with lseek calls (straced).
If i flush the connection pool (close all open connections from the jboss
jmx-console) it works again for four calls.
These problem applies only to 64bit builds. If i run a 32bit postgresql
server it works fine.
We have tested the following environments:
- Debian Squeeze 64bit with Postgresql 9.1.[5,6,7] - Bad behavior
- Debian Wheezy 64bit with Postgresql 9.1.8 64bit - Bad behavior
- Ubuntu 12.04 LTS 64bit with Postgresql 9.1.8 64bit - Bad behavior
- Windows 7 x64 with Postgresql 9.1.8 64bit - Bad behavior
- Debian Wheezy 64bit with EnterpriseDB 9.2 64bit - Bad behavior
- Debian Wheezy 64bit with Postgresql 9.1.8 32bit - Good behavior
- Debian Wheezy 32bit with Postgresql 9.1.8 32bit - Good behavior
as you can see all 64bit builds of postgresql are affected (independent from
os-arch).
If i disable the prepared-statement-cache-size (remove it from -ds.xml)
it works on 64bit build too.
regards,
msc
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] BUG: endless lseek(.., SEEK_END) from select queries on x64 builds
On 22.02.2013 10:25, Markus Schulz wrote: i can run the query four times with good performance and after that postgresql starts with the strange lseek() behavior. By default, the JDBC driver re-plans the prepared statement for the first 4 invocations of the query. On the fifth invocation, it switches to using a generic plan, which will be reused on subsequent invocations. See http://jdbc.postgresql.org/documentation/head/server-prepare.html. The generic plan seems to perform much worse in this case. You can disable that mechanism and force re-planning the query every time by setting the prepareThreshold=0 parameter on the data source. You could check what the generic plan looks like by taking the query used in the java program, with the parameter markers, and running EXPLAIN on that. PostgreSQL version 9.2 might work better in this case. It has some smarts in the server to generate parameter-specific plans even when prepared statements are used, if the planner thinks a specific plan will be faster. - Heikki -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] BUG: endless lseek(.., SEEK_END) from select queries on x64 builds
Markus, * Markus Schulz (m...@antzsystem.de) wrote: as you can see the query runs fine. I can run this query from a bash-psql-while-loop/jdbc-cli-tool endless without any problems. so far so good. [...] JBoss EAP 5.1.2 with connection pooling and xa-datasource/two-phase-commits (transactions on multiple datasources needed) *and* *prepared-statement-cache-size1000/prepared-statement-cache-size* i can run the query four times with good performance and after that postgresql starts with the strange lseek() behavior. It sounds like your bash script and JBoss are doing something different. Would it be possible for you to turn on log_statements = 'all' in PG, see what's different, and then update the bash/psql script to do exactly what JBoss does, and see if you can reproduce it that way? It certainly looks like a PG bug, but it'd be a lot easier to debug with a simple, well-defined test case which shows the failure. Thanks! Stephen signature.asc Description: Digital signature
Re: [PERFORM] BUG: endless lseek(.., SEEK_END) from select queries on x64 builds
Am Freitag, 22. Februar 2013, 14:35:25 schrieb Heikki Linnakangas: On 22.02.2013 10:25, Markus Schulz wrote: i can run the query four times with good performance and after that postgresql starts with the strange lseek() behavior. By default, the JDBC driver re-plans the prepared statement for the first 4 invocations of the query. On the fifth invocation, it switches to using a generic plan, which will be reused on subsequent invocations. that sounds really interesting and i would try to change my java-jdbc-test-cli program according to that, but ... See http://jdbc.postgresql.org/documentation/head/server-prepare.html. The generic plan seems to perform much worse in this case. You can disable that mechanism and force re-planning the query every time by setting the prepareThreshold=0 parameter on the data source. it wouldn't explain why the same jboss runs fine with a 32bit postgresql server (i switched only the datasource to another server with exactly the same database). You could check what the generic plan looks like by taking the query used in the java program, with the parameter markers, and running EXPLAIN on that. how can i do this? I've tried the following in my ejb-test-function to: String query = ... entitymanager.createNativeQuery(query)...; entitymanager.createNativeQuery(EXPLAIN ANALYZE + query)...; but the second createNativeQuery call runs fast every time and will show the same plan and the first hangs after the fourth call to this function. PostgreSQL version 9.2 might work better in this case. It has some smarts in the server to generate parameter-specific plans even when prepared statements are used, if the planner thinks a specific plan will be faster. this wouldn't help: - Debian Wheezy 64bit with EnterpriseDB 9.2 64bit - Bad behavior we tried postgresql 9.2 too - Heikki regards, msc -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
