Re: Consecutive Query Executions with Increasing Execution Time

On Sun, 2019-12-15 at 23:59 -0600, Shijia Wei wrote:
> 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
increasemonotonically.
 
> 
> I simplified query-1 to demonstrate this effect:
> ``` example.sql
> explain (analyze, buffers) select
>         max(l_shipdate) as max_data,
>         count(*) as count_order
> from
>         lineitem
> where
>         l_shipdate <= date '1998-12-01' - interval '20' day;
> ```
> 
> When I execute (from fish) following command:
> `for i in (seq 1 20); psql tpch < example.sql | grep Execution; end`
> The results I get are as follows:
> "
>  Execution Time: 184.864 ms
>  Execution Time: 192.758 ms
>  Execution Time: 197.380 ms
>  Execution Time: 200.384 ms
>  Execution Time: 202.950 ms
>  Execution Time: 205.695 ms
>  Execution Time: 208.082 ms
>  Execution Time: 209.108 ms
>  Execution Time: 212.428 ms
>  Execution Time: 214.539 ms
>  Execution Time: 215.799 ms
>  Execution Time: 219.057 ms
>  Execution Time: 222.102 ms
>  Execution Time: 223.779 ms
>  Execution Time: 227.819 ms
>  Execution Time: 229.710 ms
>  Execution Time: 239.439 ms
>  Execution Time: 237.649 ms
>  Execution Time: 249.178 ms
>  Execution Time: 261.268 ms

I don't know TPC-H, but the slowdown is not necessarily surprising:

If the number of rows that satisfy the condition keeps growing over time,
counting those rows will necessarily take longer.

Maybe you can provide more details, for example EXPLAIN (ANALYZE, BUFFERS)
output for the query when it is fast and when it is slow.

Yours,
Laurenz Albe
-- 
+43-670-6056265
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26, A-2700 Wiener Neustadt
Web: https://www.cybertec-postgresql.com