Re: [PERFORM] Performance bug in prepared statement binding in 9.2?
On 08/01/2013 03:20 PM, Jeff Janes wrote: On Thu, Aug 1, 2013 at 10:58 AM, Josh Berkus wrote: Amit, All: So we just retested this on 9.3b2. The performance is the same as 9.1 and 9.2; that is, progressively worse as the test cycles go on, and unacceptably slow compared to 8.4. Some issue introduced in 9.1 is causing BINDs to get progressively slower as the PARSEs BINDs get run repeatedly. Per earlier on this thread, that can bloat to 200X time required for a BIND, and it's definitely PostgreSQL-side. I'm trying to produce a test case which doesn't involve the user's application. However, hints on other things to analyze would be keen. Does it seem to be all CPU time (it is hard to imagine what else it would be, but...) Could you use oprofile or perf or gprof to get a profile of the backend during a run? That should quickly narrow it down to which C function has the problem. Did you test 9.0 as well? This has been tested back to 9.0. What we have found is that the problem disappears if the database has come in via dump/restore, but is present if it is the result of pg_upgrade. There are some long-running transactions also running alongside this - we are currently planning a test where those are not present. We're also looking at constructing a self-contained test case. Here is some perf output from the bad case: + 14.67% postgres [.] heap_hot_search_buffer + 11.45% postgres [.] LWLockAcquire + 8.39% postgres [.] LWLockRelease + 6.60% postgres [.] _bt_checkkeys + 6.39% postgres [.] PinBuffer + 5.96% postgres [.] hash_search_with_hash_value + 5.43% postgres [.] hash_any + 5.14% postgres [.] UnpinBuffer + 3.43% postgres [.] ReadBuffer_common + 2.34% postgres [.] index_fetch_heap + 2.04% postgres [.] heap_page_prune_opt + 2.00% libc-2.15.so [.] 0x8041b + 1.94% postgres [.] _bt_next + 1.83% postgres [.] btgettuple + 1.76% postgres [.] index_getnext_tid + 1.70% postgres [.] LockBuffer + 1.54% postgres [.] ReadBufferExtended + 1.25% postgres [.] FunctionCall2Coll + 1.14% postgres [.] HeapTupleSatisfiesNow + 1.09% postgres [.] ReleaseAndReadBuffer + 0.94% postgres [.] ResourceOwnerForgetBuffer + 0.81% postgres [.] _bt_saveitem + 0.80% postgres [.] _bt_readpage + 0.79% [kernel.kallsyms] [k] 0x81170861 + 0.64% postgres [.] CheckForSerializableConflictOut + 0.60% postgres [.] ResourceOwnerEnlargeBuffers + 0.59% postgres [.] BufTableLookup and here is the good case: + 9.54% libc-2.15.so [.] 0x15eb1f + 7.31% [kernel.kallsyms] [k] 0x8117924b + 5.65% postgres [.] AllocSetAlloc + 3.57% postgres [.] SearchCatCache + 2.67% postgres [.] hash_search_with_hash_value + 1.69% postgres [.] base_yyparse + 1.49% libc-2.15.so [.] vfprintf + 1.34% postgres [.] MemoryContextAllocZeroAligned + 1.34% postgres [.] XLogInsert + 1.24% postgres [.] copyObject + 1.10% postgres [.] palloc + 1.09% postgres [.] _bt_compare + 1.04% postgres [.] core_yylex + 0.96% postgres [.] _bt_checkkeys + 0.95% postgres [.] expression_tree_walker + 0.88% postgres [.] ScanKeywordLookup + 0.87% postgres [.] pg_encoding_mbcliplen + 0.86% postgres [.] LWLockAcquire + 0.72% postgres [.] nocachegetattr + 0.67% postgres [.] FunctionCall2Coll + 0.63% postgres [.] fmgr_info_cxt_security + 0.62% postgres [.] hash_any + 0.62% postgres [.] ExecInitExpr + 0.58% postgres [.] hash_uint32 + 0.55% postgres [.] PostgresMain + 0.55% postgres [.] LWLockRelease + 0.54% postgres [.] lappend + 0.52% postgres [.] slot_deform_tuple + 0.50% postgres [.] PinBuffer + 0.48% postgres [.] AllocSetFree + 0.46% postgres [.] check_stack_depth + 0.44% postgres [.] DirectFunctionCall1Coll + 0.43% postgres [.] ExecScanHashBucket + 0.36% postgres [.] deconstruct_array + 0.36% postgres [.] CatalogCacheComputeHashValue + 0.35% postgres [.] pfree + 0.33% libc-2.15.so [.] _IO_default_xsputn + 0.32% libc-2.15.so [.] malloc + 0.32% postgres [.] TupleDescInitEntry + 0.30% postgres [.] new_tail_cell.isra.2 + 0.30% libm-2.15.so [.] 0x5898
Re: [PERFORM] Performance bug in prepared statement binding in 9.2?
On Mon, Sep 9, 2013 at 08:38:09PM -0400, Andrew Dunstan wrote: > > On 08/01/2013 03:20 PM, Jeff Janes wrote: > >On Thu, Aug 1, 2013 at 10:58 AM, Josh Berkus wrote: > >>Amit, All: > >> > >>So we just retested this on 9.3b2. The performance is the same as 9.1 > >>and 9.2; that is, progressively worse as the test cycles go on, and > >>unacceptably slow compared to 8.4. > >> > >>Some issue introduced in 9.1 is causing BINDs to get progressively > >>slower as the PARSEs BINDs get run repeatedly. Per earlier on this > >>thread, that can bloat to 200X time required for a BIND, and it's > >>definitely PostgreSQL-side. > >> > >>I'm trying to produce a test case which doesn't involve the user's > >>application. However, hints on other things to analyze would be keen. > >Does it seem to be all CPU time (it is hard to imagine what else it > >would be, but...) > > > >Could you use oprofile or perf or gprof to get a profile of the > >backend during a run? That should quickly narrow it down to which C > >function has the problem. > > > >Did you test 9.0 as well? > > > This has been tested back to 9.0. What we have found is that the > problem disappears if the database has come in via dump/restore, but > is present if it is the result of pg_upgrade. There are some > long-running transactions also running alongside this - we are > currently planning a test where those are not present. We're also > looking at constructing a self-contained test case. > > Here is some perf output from the bad case: > >+ 14.67% postgres [.] heap_hot_search_buffer OK, certainly looks like a HOT chain issue. I think there are two possibilities: 1) the heap or index file is different from a dump/restore vs. pg_upgrade 2) some other files is missing or changed between the two My guess is that the dump/restore removes all the HOT chains as it just dumps the most recent value of the chain. Could it be HOT chain overhead that you are seeing, rather than a pg_upgrade issue/bug? -- Bruce Momjian http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. + -- 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] Performance bug in prepared statement binding in 9.2?
Let me clarify further - when we reconstruct our schema (without the upgrade step) via a sql script, the problem still persists. Restoring an upgraded DB which contains existing data into exactly the same instance will correct the behavior. Mel Llaguno | Principal Engineer (Performance/Deployment) Coverity | 800 6th Avenue S.W. | Suite 410 | Calgary, AB | Canada | T2P 3G3 mllag...@coverity.com From: pgsql-performance-ow...@postgresql.org [pgsql-performance-ow...@postgresql.org] on behalf of Andrew Dunstan [and...@dunslane.net] Sent: Monday, September 09, 2013 6:38 PM To: Jeff Janes Cc: Josh Berkus; Amit Kapila; pgsql-performance@postgresql.org Subject: Re: [PERFORM] Performance bug in prepared statement binding in 9.2? On 08/01/2013 03:20 PM, Jeff Janes wrote: > On Thu, Aug 1, 2013 at 10:58 AM, Josh Berkus wrote: >> Amit, All: >> >> So we just retested this on 9.3b2. The performance is the same as 9.1 >> and 9.2; that is, progressively worse as the test cycles go on, and >> unacceptably slow compared to 8.4. >> >> Some issue introduced in 9.1 is causing BINDs to get progressively >> slower as the PARSEs BINDs get run repeatedly. Per earlier on this >> thread, that can bloat to 200X time required for a BIND, and it's >> definitely PostgreSQL-side. >> >> I'm trying to produce a test case which doesn't involve the user's >> application. However, hints on other things to analyze would be keen. > Does it seem to be all CPU time (it is hard to imagine what else it > would be, but...) > > Could you use oprofile or perf or gprof to get a profile of the > backend during a run? That should quickly narrow it down to which C > function has the problem. > > Did you test 9.0 as well? This has been tested back to 9.0. What we have found is that the problem disappears if the database has come in via dump/restore, but is present if it is the result of pg_upgrade. There are some long-running transactions also running alongside this - we are currently planning a test where those are not present. We're also looking at constructing a self-contained test case. Here is some perf output from the bad case: + 14.67% postgres [.] heap_hot_search_buffer + 11.45% postgres [.] LWLockAcquire + 8.39% postgres [.] LWLockRelease + 6.60% postgres [.] _bt_checkkeys + 6.39% postgres [.] PinBuffer + 5.96% postgres [.] hash_search_with_hash_value + 5.43% postgres [.] hash_any + 5.14% postgres [.] UnpinBuffer + 3.43% postgres [.] ReadBuffer_common + 2.34% postgres [.] index_fetch_heap + 2.04% postgres [.] heap_page_prune_opt + 2.00% libc-2.15.so [.] 0x8041b + 1.94% postgres [.] _bt_next + 1.83% postgres [.] btgettuple + 1.76% postgres [.] index_getnext_tid + 1.70% postgres [.] LockBuffer + 1.54% postgres [.] ReadBufferExtended + 1.25% postgres [.] FunctionCall2Coll + 1.14% postgres [.] HeapTupleSatisfiesNow + 1.09% postgres [.] ReleaseAndReadBuffer + 0.94% postgres [.] ResourceOwnerForgetBuffer + 0.81% postgres [.] _bt_saveitem + 0.80% postgres [.] _bt_readpage + 0.79% [kernel.kallsyms] [k] 0x81170861 + 0.64% postgres [.] CheckForSerializableConflictOut + 0.60% postgres [.] ResourceOwnerEnlargeBuffers + 0.59% postgres [.] BufTableLookup and here is the good case: + 9.54% libc-2.15.so [.] 0x15eb1f + 7.31% [kernel.kallsyms] [k] 0x8117924b + 5.65% postgres [.] AllocSetAlloc + 3.57% postgres [.] SearchCatCache + 2.67% postgres [.] hash_search_with_hash_value + 1.69% postgres [.] base_yyparse + 1.49% libc-2.15.so [.] vfprintf + 1.34% postgres [.] MemoryContextAllocZeroAligned + 1.34% postgres [.] XLogInsert + 1.24% postgres [.] copyObject + 1.10% postgres [.] palloc + 1.09% postgres [.] _bt_compare + 1.04% postgres [.] core_yylex + 0.96% postgres [.] _bt_checkkeys + 0.95% postgres [.] expression_tree_walker + 0.88% postgres [.] ScanKeywordLookup + 0.87% postgres [.] pg_encoding_mbcliplen + 0.86% postgres [.] LWLockAcquire + 0.72% postgres [.] nocachegetattr + 0.67% postgres [.] FunctionCall2Coll + 0.63% postgres [.] fmgr_info_cxt_security + 0.62% postgres [.] hash_any + 0.62% postgres [.] ExecInitExpr + 0.58% postgres [.] hash_uint32 + 0.55%
Re: [PERFORM] Performance bug in prepared statement binding in 9.2?
On Tue, Sep 10, 2013 at 01:36:27AM +, Mel Llaguno wrote: > Let me clarify further - when we reconstruct our schema (without the > upgrade step) via a sql script, the problem still persists. Restoring > an upgraded DB which contains existing data into exactly the same > instance will correct the behavior. I do not understand what you are saying above. -- Bruce Momjian http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. + -- 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] Performance bug in prepared statement binding in 9.2?
We're currently using an embedded PG 8.4.17 for our application. Our PG 9.x tests consists of one of the following : - Take a 8.4.17 DB which contains only our application schema and required seed data and use pg_upgrade to create a 9.x database directory, run the analyze_new_cluster.sh script and fire up the application. Under this set of conditions, the bind connection issue is present during our test. - Start with a fresh PG 9.x DB (using use create_db) and use psql to recreate our application schema and required seed data. When the application is started and our test executed, the bind connection issue is still present. In both of the above cases, a base application schema is used. If I upgrade an 8.4.17 DB that contains additional application data (generated by interaction with our application) to 9.x, the bind connection issue is no longer present. Restoring this upgraded 9.x DB into any PG instance in the previously described scenarios also seems to fix the bind connection issue. Please let me know if this clarifies my earlier post. Thanks, M. Mel Llaguno | Principal Engineer (Performance/Deployment) Coverity | 800 6th Avenue S.W. | Suite 410 | Calgary, AB | Canada | T2P 3G3 mllag...@coverity.com From: Bruce Momjian [br...@momjian.us] Sent: Monday, September 09, 2013 7:45 PM To: Mel Llaguno Cc: Andrew Dunstan; Jeff Janes; Josh Berkus; Amit Kapila; pgsql-performance@postgresql.org Subject: Re: [PERFORM] Performance bug in prepared statement binding in 9.2? On Tue, Sep 10, 2013 at 01:36:27AM +, Mel Llaguno wrote: > Let me clarify further - when we reconstruct our schema (without the > upgrade step) via a sql script, the problem still persists. Restoring > an upgraded DB which contains existing data into exactly the same > instance will correct the behavior. I do not understand what you are saying above. -- Bruce Momjian http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. + -- 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] Performance bug in prepared statement binding in 9.2?
On Tue, Sep 10, 2013 at 02:06:08AM +, Mel Llaguno wrote: > We're currently using an embedded PG 8.4.17 for our application. Our > PG 9.x tests consists of one of the following : > > - Take a 8.4.17 DB which contains only our application schema and > required seed data and use pg_upgrade to create a 9.x database > directory, run the analyze_new_cluster.sh script and fire up the > application. Under this set of conditions, the bind connection issue > is present during our test. > > - Start with a fresh PG 9.x DB (using use create_db) and use psql > to recreate our application schema and required seed data. When the > application is started and our test executed, the bind connection > issue is still present. > > In both of the above cases, a base application schema is used. > > If I upgrade an 8.4.17 DB that contains additional application data > (generated by interaction with our application) to 9.x, the bind > connection issue is no longer present. Restoring this upgraded 9.x DB > into any PG instance in the previously described scenarios also seems > to fix the bind connection issue. > > Please let me know if this clarifies my earlier post. Yes, that is clear. So it is the seed data that is causing the problem? That is the only different I see from #2 and #3. -- Bruce Momjian http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. + -- 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] Performance bug in prepared statement binding in 9.2?
Bruce, First of all, I'd like to thank you for taking some interest in this issue. We'd love to migrate to the latest PG version, but this issue is currently preventing us from doing so. Regardless of the DB used (base application schema _or_ restored DB with additional app data + base application schema), seed information is present in all tests. I guess my question is this - why would having existing data change the bind behavior at all? Is it possible that the way indexes are created has changed between 8.4 -> 9.x? Thanks, M. Mel Llaguno | Principal Engineer (Performance/Deployment) Coverity | 800 6th Avenue S.W. | Suite 410 | Calgary, AB | Canada | T2P 3G3 mllag...@coverity.com From: Bruce Momjian [br...@momjian.us] Sent: Monday, September 09, 2013 8:16 PM To: Mel Llaguno Cc: pgsql-performance@postgresql.org Subject: Re: [PERFORM] Performance bug in prepared statement binding in 9.2? On Tue, Sep 10, 2013 at 02:06:08AM +, Mel Llaguno wrote: > We're currently using an embedded PG 8.4.17 for our application. Our > PG 9.x tests consists of one of the following : > > - Take a 8.4.17 DB which contains only our application schema and > required seed data and use pg_upgrade to create a 9.x database > directory, run the analyze_new_cluster.sh script and fire up the > application. Under this set of conditions, the bind connection issue > is present during our test. > > - Start with a fresh PG 9.x DB (using use create_db) and use psql > to recreate our application schema and required seed data. When the > application is started and our test executed, the bind connection > issue is still present. > > In both of the above cases, a base application schema is used. > > If I upgrade an 8.4.17 DB that contains additional application data > (generated by interaction with our application) to 9.x, the bind > connection issue is no longer present. Restoring this upgraded 9.x DB > into any PG instance in the previously described scenarios also seems > to fix the bind connection issue. > > Please let me know if this clarifies my earlier post. Yes, that is clear. So it is the seed data that is causing the problem? That is the only different I see from #2 and #3. -- Bruce Momjian http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. + -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
