pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: Andres Freund <andres@2ndquadrant.com>
To: Andrew Dunstan <andrew@dunslane.net>
Cc: Jeff Janes <jeff.janes@gmail.com>
Cc: Josh Berkus <josh@agliodbs.com>
Cc: Amit Kapila <amit.kapila@huawei.com>
Cc: pgsql-performance@postgresql.org <pgsql-performance@postgresql.org>
Subject: Re: Performance bug in prepared statement binding in 9.2?
Date: Tue, 10 Sep 2013 14:32:07 +0200
Message-ID: <20130910123207.GG1024477@alap2.anarazel.de> (raw)
In-Reply-To: <522E69F1.8070203@dunslane.net>
References: <51A699E6.3000008@agliodbs.com>
	<WM!f3d412a8ff9fb2a52f4cfd0f48c225b6122ba5bf1e1523173b5dbc63db143b9cab09ac3f5518a12a19d2507538472d98!@asav-1.01.com>
	<51A79512.4020200@agliodbs.com>
	<WM!c84cb8479a8b2ec21d1061c951095da00bc52608e9822124f1438b9de432ec7ebedaf25085801b67d581eed6d368c344!@asav-2.01.com>
	<51FAA1B8.6040809@agliodbs.com>
	<CAMkU=1wn3npjTjEkC8rYMgmoKXYoAgfxosT_Q3v_=wTfriPKdA@mail.gmail.com>
	<522E69F1.8070203@dunslane.net>
List-Unsubscribe:  <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>

On 2013-09-09 20:38:09 -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 <josh@agliodbs.com> 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

After a second look at this, I very tentatively guess that you'll see
get_actual_variable_range() as the entry point here. Which would explain
why you're seing this during PARSE.

But there still is the question why we never actually seem to prune...

Greetings,

Andres Freund

-- 
 Andres Freund	                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services


-- 
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance



view thread (43+ messages)  latest in thread

Message-ID: <20130910123207.GG1024477@alap2.anarazel.de>
Permalink:  ../20130910123207.GG1024477@alap2.anarazel.de/
Also on:    postgresql.org/message-id/20130910123207.GG1024477@alap2.anarazel.de

 · 

reply

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: andres@2ndquadrant.com, andrew@dunslane.net, jeff.janes@gmail.com, josh@agliodbs.com, amit.kapila@huawei.com
  Subject: Re: Performance bug in prepared statement binding in 9.2?
  In-Reply-To: <20130910123207.GG1024477@alap2.anarazel.de>

* 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