public inbox for [email protected]  

help / color / mirror / Atom feed

From: [email protected]
To: [email protected]
Subject: Re: Random slow queries
Date: Wed, 29 Jun 2016 20:04:31 +0200
Message-ID: <CACjsgD=Pg3utmjD8F3ZSYXYnb+2CjuxyDzNbrfwA-_giWGM1sA@mail.gmail.com> (raw)
In-Reply-To: <DM2PR07MB5578DB88C4DCCEA3213FA76DA230@DM2PR07MB557.namprd07.prod.outlook.com>
References: <CACjsgDm+n0s=5cMwGF7nRMXS8fX6CF9t1HsOr_M2iejpxKgS1A@mail.gmail.com>
	<DM2PR07MB5578DB88C4DCCEA3213FA76DA230@DM2PR07MB557.namprd07.prod.outlook.com>
List-Unsubscribe:  <mailto:[email protected]?body=unsub%20pgsql-performance>

On 29 June 2016 at 16:32, Igor Neyman <[email protected]> wrote:
> Did you try AUTO_EXPLAIN extension
> (https://www.postgresql.org/docs/9.3/static/auto-explain.html) for
> diagnostic purposes?
> With auto_explain.loganalize = true it will log automatically EXPLAIN
> ANALYZE output, rather than just EXPLAIN output.  Turning this parameter ON
> permanently could have negative impact on over-all performance, so use it
> judiciously.
>
> Regards,
> Igor
>

Yes, I tried that. As mentioned in my original email:
> Things I tried:
> ...
> - Enable auto_explain to obtain more information. Unfortunately, for the
> 2-minute queries no plan is logged. If I manually force a query to take a
> long time (eg SELECT pg_sleep(5)) or if I set auto_explain.log_min_duration
> low enough plans are logged for slow queries, _except_ for these 2-minute
> mysteries. This makes it very hard to see exactly why the query is taking so
> long. Is this a bug in auto_explain? Are cached plans never logged (this is
> not indicated in the documentation)? Some other reason why no plan would be
> logged? Note that this happens both in PostgreSQL 9.3.4 and 9.5.3

To be more precise, this is the config I used for auto_explain:
shared_preload_libraries = 'auto_explain'
auto_explain.log_min_duration = 2000
auto_explain.log_analyze = true
auto_explain.log_buffers = true
auto_explain.log_timing = true

On a test query (eg using pg_sleep) there is logging for both the slow query
log and for auto_explain; for my actual problem queries there's only the slow
query log output, no auto_explain query plan.
As you can see from the logs I posted, it appears the execution plan was
cached (LOG:  duration: 122006.000 ms  bind cached-1453392550: select....).
Maybe those aren't processed by auto_explain?

Best regards,
Roel



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

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: [email protected]
  Cc: [email protected]
  Subject: Re: Random slow queries
  In-Reply-To: <CACjsgD=Pg3utmjD8F3ZSYXYnb+2CjuxyDzNbrfwA-_giWGM1sA@mail.gmail.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox