pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: Tom Lane <tgl@sss.pgh.pa.us>
To: Shijia Wei <shijiawei@utexas.edu>
Cc: pgsql-performance@lists.postgresql.org
Subject: Re: Consecutive Query Executions with Increasing Execution Time
Date: Mon, 16 Dec 2019 08:50:36 -0500
Message-ID: <13512.1576504236@sss.pgh.pa.us> (raw)
In-Reply-To: <CABSfb-6iUvpGCzcgni+tVoiUWTc9aQdUtKbOzFzGqJcypiLa4g@mail.gmail.com>
References: <CABSfb-6iUvpGCzcgni+tVoiUWTc9aQdUtKbOzFzGqJcypiLa4g@mail.gmail.com>

Shijia Wei <shijiawei@utexas.edu> writes:
> I am running TPC-H on recent postgresql (12.0 and 12.1).
> On some of the queries (that may involve parallel scans) I see this
> interesting behavior:
> When these queries are executed back-to-back (sent from psql interactive
> terminal), the total execution time of them increase monotonically.

FWIW, I can't reproduce this here.  Using a different chosen-at-random
query, I tried

$ for i in `seq 1 20`; do              
> psql -c 'explain (analyze) select * from tenk1 a,tenk1 b where a.hundred=b.hundred;' regression | grep Execution
> done
 Execution Time: 468.548 ms
 Execution Time: 467.905 ms
 Execution Time: 467.634 ms
 Execution Time: 465.852 ms
 Execution Time: 463.328 ms
 Execution Time: 462.541 ms
 Execution Time: 463.922 ms
 Execution Time: 466.171 ms
 Execution Time: 464.778 ms
 Execution Time: 464.474 ms
 Execution Time: 466.087 ms
 Execution Time: 463.092 ms
 Execution Time: 463.700 ms
 Execution Time: 468.924 ms
 Execution Time: 464.970 ms
 Execution Time: 464.844 ms
 Execution Time: 464.665 ms
 Execution Time: 465.247 ms
 Execution Time: 465.931 ms
 Execution Time: 466.722 ms


> When there a wait period in-between queries, (e.g. sleep 10) in the above
> for loop, this increasing execution time behavior goes a way.

A conceivable theory is that the previous backends haven't exited yet and
the extra runtime represents overhead due to having lots of active
PGPROC entries.  This is pretty hard to credit on a multi-core machine,
however.  I think it'd require assuming that the old backends have some
seconds' worth of cleanup work to do before they can exit, which makes
little sense.  (Unless, perhaps, you have turned on coverage
instrumentation, or some other expensive debug monitoring?)

I concur with the suggestion to try to pin down where the cycles are
going.  I'd suggest using perf or some similar tool.

			regards, tom lane





view thread (18+ messages)  latest in thread

Message-ID: <13512.1576504236@sss.pgh.pa.us>
Permalink:  ../13512.1576504236@sss.pgh.pa.us/
Also on:    postgresql.org/message-id/13512.1576504236@sss.pgh.pa.us

 · 

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: tgl@sss.pgh.pa.us, shijiawei@utexas.edu, pgsql-performance@lists.postgresql.org
  Subject: Re: Consecutive Query Executions with Increasing Execution Time
  In-Reply-To: <13512.1576504236@sss.pgh.pa.us>

* 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