From: | Julien Rouhaud <rjuju123(at)gmail(dot)com> |
---|---|
To: | Alvaro Herrera <alvherre(at)alvh(dot)no-ip(dot)org> |
Cc: | Matheus Martin <matheus(dot)martin(at)voidbridge(dot)com>, pgsql-general(at)postgresql(dot)org |
Subject: | Re: Missing query plan for auto_explain. |
Date: | 2022-08-30 12:30:53 |
Message-ID: | 20220830123053.s5ypjyhsnao2pimb@jrouhaud |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-general |
Hi,
On Tue, Aug 30, 2022 at 01:16:43PM +0200, Alvaro Herrera wrote:
> On 2022-Aug-30, Matheus Martin wrote:
>
> > Our Postgres recently started reporting considerably different
> > execution times for the same query. When executed from our JDBC
> > application the Postgres logs report an average execution time of 1500
> > ms but when the query is manually executed through `psql` it doesn't
> > take longer than 50 ms.
>
> I don't know why the plan is not saved by auto_explain (maybe we're
> missing ExecutorEnd calls somewhere? that would be strange), but one
> frequent reason for queries to show different plan in JDBC than psql is
> the use of prepared statements. Did you try using "PREPARE
> yourquery(...)" and then EXPLAIN EXECUTE(...)? Sometimes that helps to
> recreate the original problem.
>
> (Apparently, ExecutorEnd is called from PortalCleanup; what happens with
> the portal for an extended-protocol query?)
AFAICS log_min_duration_statements threshold is based on the full query
processing time while auto_explain is only based on the executor runtime, so
one more likely explanation is that out of the 1423ms, more than 423ms were
spent in the planner?
From | Date | Subject | |
---|---|---|---|
Next Message | Matheus Martin | 2022-08-30 16:26:40 | Re: Missing query plan for auto_explain. |
Previous Message | Alvaro Herrera | 2022-08-30 11:16:43 | Re: Missing query plan for auto_explain. |