pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedimpact of auto explain on overall performance
5+ messages / 5 participants
[nested] [flat]
* impact of auto explain on overall performance
@ 2019-03-14 07:29 Stephan Schmidt <schmidt@dltmail.de>
2019-03-14 08:23 ` Re: impact of auto explain on overall performance Justin Pryzby <pryzby@telsasoft.com>
2019-03-14 17:50 ` Re: impact of auto explain on overall performance Jeff Janes <jeff.janes@gmail.com>
2019-03-14 19:58 ` Re: impact of auto explain on overall performance Jeremy Schneider <schneider@ardentperf.com>
0 siblings, 3 replies; 5+ messages in thread
From: Stephan Schmidt @ 2019-03-14 07:29 UTC (permalink / raw)
To: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
Hello,
i’m currently working on a high Performance Database and want to make sure that whenever there are slow queries during regular operations i’ve got all Information about the query in my logs. So auto_explain come to mind, but the documentation explicitly states that it Comes at a cost. My Question is, how big is the latency added by auto_explain in percentage or ms ?
Best regards,
stephan
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: impact of auto explain on overall performance
2019-03-14 07:29 impact of auto explain on overall performance Stephan Schmidt <schmidt@dltmail.de>
@ 2019-03-14 08:23 ` Justin Pryzby <pryzby@telsasoft.com>
2019-03-14 09:08 ` Re: impact of auto explain on overall performance Adrien NAYRAT <adrien.nayrat@anayrat.info>
2 siblings, 1 reply; 5+ messages in thread
From: Justin Pryzby @ 2019-03-14 08:23 UTC (permalink / raw)
To: Stephan Schmidt <schmidt@dltmail.de>; +Cc: pgsql-performance@lists.postgresql.org
On Thu, Mar 14, 2019 at 07:29:17AM +0000, Stephan Schmidt wrote:
> i’m currently working on a high Performance Database and want to make sure that whenever there are slow queries during regular operations i’ve got all Information about the query in my logs. So auto_explain come to mind, but the documentation explicitly states that it Comes at a cost. My Question is, how big is the latency added by auto_explain in percentage or ms ?
https://www.postgresql.org/docs/current/auto-explain.html
|log_analyze
...
|When this parameter is on, per-plan-node timing occurs for all statements executed, whether or not they run long enough to actually get logged. This can have an extremely negative impact on performance. Turning off auto_explain.log_timing ameliorates the performance cost, at the price of obtaining less information.
|auto_explain.log_timing (boolean)
|auto_explain.log_timing controls whether per-node timing information is printed when an execution plan is logged; it's equivalent to the TIMING option of EXPLAIN. The overhead of repeatedly reading the system clock can slow down queries significantly on some systems, so it may be useful to set this parameter to off when only actual row counts, and not exact times, are needed. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is on by default. Only superusers can change this setting.
I believe the cost actually varies significantly with the type of plan "node",
with "nested loops" incurring much higher overhead.
I think you could compare using explain(analyze) vs explain(analyze,timing
off). While you're at it, compare without explain at all.
I suspect the overhead is inconsequential if you set log_timing=off and set
log_min_duration such that only the slowest queries are logged.
Then, you can manually run "explain (analyze,costs on)" on any problematic
queries to avoid interfering with production clients.
Justin
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: impact of auto explain on overall performance
2019-03-14 07:29 impact of auto explain on overall performance Stephan Schmidt <schmidt@dltmail.de>
2019-03-14 08:23 ` Re: impact of auto explain on overall performance Justin Pryzby <pryzby@telsasoft.com>
@ 2019-03-14 09:08 ` Adrien NAYRAT <adrien.nayrat@anayrat.info>
0 siblings, 0 replies; 5+ messages in thread
From: Adrien NAYRAT @ 2019-03-14 09:08 UTC (permalink / raw)
To: Justin Pryzby <pryzby@telsasoft.com>; Stephan Schmidt <schmidt@dltmail.de>; +Cc: pgsql-performance@lists.postgresql.org
On 3/14/19 9:23 AM, Justin Pryzby wrote:
> On Thu, Mar 14, 2019 at 07:29:17AM +0000, Stephan Schmidt wrote:
>> i’m currently working on a high Performance Database and want to make sure that whenever there are slow queries during regular operations i’ve got all Information about the query in my logs. So auto_explain come to mind, but the documentation explicitly states that it Comes at a cost. My Question is, how big is the latency added by auto_explain in percentage or ms ?
>
> https://www.postgresql.org/docs/current/auto-explain.html
> |log_analyze
> ...
> |When this parameter is on, per-plan-node timing occurs for all statements executed, whether or not they run long enough to actually get logged. This can have an extremely negative impact on performance. Turning off auto_explain.log_timing ameliorates the performance cost, at the price of obtaining less information.
>
> |auto_explain.log_timing (boolean)
> |auto_explain.log_timing controls whether per-node timing information is printed when an execution plan is logged; it's equivalent to the TIMING option of EXPLAIN. The overhead of repeatedly reading the system clock can slow down queries significantly on some systems, so it may be useful to set this parameter to off when only actual row counts, and not exact times, are needed. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is on by default. Only superusers can change this setting.
>
> I believe the cost actually varies significantly with the type of plan "node",
> with "nested loops" incurring much higher overhead.
>
> I think you could compare using explain(analyze) vs explain(analyze,timing
> off). While you're at it, compare without explain at all.
>
> I suspect the overhead is inconsequential if you set log_timing=off and set
> log_min_duration such that only the slowest queries are logged.
>
> Then, you can manually run "explain (analyze,costs on)" on any problematic
> queries to avoid interfering with production clients.
>
> Justin
>
You should also consider auto_explain.sample_rate:
auto_explain.sample_rate causes auto_explain to only explain a fraction
of the statements in each session. The default is 1, meaning explain all
the queries. In case of nested statements, either all will be explained
or none. Only superusers can change this setting.
This option is available since 9.6
Regards
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: impact of auto explain on overall performance
2019-03-14 07:29 impact of auto explain on overall performance Stephan Schmidt <schmidt@dltmail.de>
@ 2019-03-14 17:50 ` Jeff Janes <jeff.janes@gmail.com>
2 siblings, 0 replies; 5+ messages in thread
From: Jeff Janes @ 2019-03-14 17:50 UTC (permalink / raw)
To: Stephan Schmidt <schmidt@dltmail.de>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On Thu, Mar 14, 2019 at 3:29 AM Stephan Schmidt <schmidt@dltmail.de> wrote:
> Hello,
>
>
>
> i’m currently working on a high Performance Database and want to make sure
> that whenever there are slow queries during regular operations i’ve got all
> Information about the query in my logs. So auto_explain come to mind, but
> the documentation explicitly states that it Comes at a cost. My Question
> is, how big is the latency added by auto_explain in percentage or ms ?
>
You will have to measure it yourself and see. It depends on your hardware,
OS, and OS version, and PostgreSQL version. And the nature of your
queries. If you have auto_explain.log_timing=on, then I find that large
sorts are the worst impacted. So if you have a lot of those, you should be
careful.
On older kernels, I would run with auto_explain.log_timing=off. On newer
kernels where you can read the clock from user-space, I run with
auto_explain.log_timing=on. I find the slowdown noticeable with careful
investigation (around 3%, last time I carefully investigated it), but
usually well worth paying to have actual data to work with when I find slow
queries in the log. I made a special role with auto_explain disabled for
use with a few reporting queries with large sorts, both to circumvent the
overhead and to avoid spamming the log with slow queries I already know
about.
Cheers,
Jeff
>
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: impact of auto explain on overall performance
2019-03-14 07:29 impact of auto explain on overall performance Stephan Schmidt <schmidt@dltmail.de>
@ 2019-03-14 19:58 ` Jeremy Schneider <schneider@ardentperf.com>
2 siblings, 0 replies; 5+ messages in thread
From: Jeremy Schneider @ 2019-03-14 19:58 UTC (permalink / raw)
To: Stephan Schmidt <schmidt@dltmail.de>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On 3/14/19 00:29, Stephan Schmidt wrote:
> i’m currently working on a high Performance Database and want to make
> sure that whenever there are slow queries during regular operations i’ve
> got all Information about the query in my logs. So auto_explain come to
> mind, but the documentation explicitly states that it Comes at a cost.
> My Question is, how big is the latency added by auto_explain in
> percentage or ms ?
One thought - what if the problem query is a 4ms query that just went to
6ms but it's executed millions of times per second? That would create a
150% increase to the load on the system.
The approach I've had the most success with is to combine active session
sampling (from pg_stat_activity) with pg_stat_statements (ideally with
periodic snapshots) to identify problematic SQL statements, then use
explain analyze after you've identified them.
There are a handful of extensions on the internet that can do active
session sampling for you, and I've seen a few scripts that can be put
into a scheduler to capture snapshots of stats tables.
Maybe something to consider in addition to the auto_explain stuff.
-Jeremy
--
http://about.me/jeremy_schneider
^ permalink raw reply [nested|flat] 5+ messages in thread
end of thread, other threads:[~2019-03-14 19:58 UTC | newest]
Thread overview: 5+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2019-03-14 07:29 impact of auto explain on overall performance Stephan Schmidt <schmidt@dltmail.de>
2019-03-14 08:23 ` Justin Pryzby <pryzby@telsasoft.com>
2019-03-14 09:08 ` Adrien NAYRAT <adrien.nayrat@anayrat.info>
2019-03-14 17:50 ` Jeff Janes <jeff.janes@gmail.com>
2019-03-14 19:58 ` Jeremy Schneider <schneider@ardentperf.com>
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