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 mllaguno@xxxxxxxxxxxx ________________________________________ From: pgsql-performance-owner@xxxxxxxxxxxxxx [pgsql-performance-owner@xxxxxxxxxxxxxx] on behalf of Andrew Dunstan [andrew@xxxxxxxxxxxx] Sent: Monday, September 09, 2013 6:38 PM To: Jeff Janes Cc: Josh Berkus; Amit Kapila; pgsql-performance@xxxxxxxxxxxxxx Subject: Re: 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 <josh@xxxxxxxxxxxx> 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] 0xffffffff81170861 + 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] 0xffffffff8117924b + 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 + 0.30% postgres [.] LockAcquireExtended + 0.30% postgres [.] _bt_first + 0.29% postgres [.] add_paths_to_joinrel + 0.28% postgres [.] MemoryContextCreate + 0.28% postgres [.] appendBinaryStringInfo + 0.28% postgres [.] MemoryContextStrdup + 0.27% postgres [.] heap_hot_search_buffer + 0.27% postgres [.] GetSnapshotData + 0.26% postgres [.] hash_search + 0.26% postgres [.] heap_getsysattr + 0.26% [vdso] [.] 0x7fff681ff70c + 0.25% postgres [.] compare_scalars + 0.25% postgres [.] pg_verify_mbstr_len cheers andrew -- Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance -- Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance