Re: Consecutive Query Executions with Increasing Execution Time - Mailing list pgsql-performance

Hi Shijia,

It sounds like concurrency on the queries: the second starts before the first ends, and so on. With a short wait in between you ensure sequential execution. Notice that you also have the overhead of concurrent psql...

Sounds normal to me.

Best regards

Olivier

On Mon, Dec 16, 2019, 07:00 Shijia Wei <shijiawei@utexas.edu> wrote:

Hi all,

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.

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
"

In addition, if the repeated more times, the total execution time can end up being 10X and more!!!

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.

For more complex queries, the "wait period" needs to be longer to avoid the increase in execution time.

Some metadata about this table "lineitem":

tpch=# \d lineitem
                         Table "public.lineitem"
     Column      |         Type          | Collation | Nullable | Default
-----------------+-----------------------+-----------+----------+---------
 l_orderkey      | integer               |           | not null |
 l_partkey       | integer               |           | not null |
 l_suppkey       | integer               |           | not null |
 l_linenumber    | integer               |           | not null |
 l_quantity      | numeric(15,2)         |           | not null |
 l_extendedprice | numeric(15,2)         |           | not null |
 l_discount      | numeric(15,2)         |           | not null |
 l_tax           | numeric(15,2)         |           | not null |
 l_returnflag    | character(1)          |           | not null |
 l_linestatus    | character(1)          |           | not null |
 l_shipdate      | date                  |           | not null |
 l_commitdate    | date                  |           | not null |
 l_receiptdate   | date                  |           | not null |
 l_shipinstruct  | character(25)         |           | not null |
 l_shipmode      | character(10)         |           | not null |
 l_comment       | character varying(44) |           | not null |
Indexes:
    "i_l_commitdate" btree (l_commitdate)
    "i_l_orderkey" btree (l_orderkey)
    "i_l_orderkey_quantity" btree (l_orderkey, l_quantity)
    "i_l_partkey" btree (l_partkey)
    "i_l_receiptdate" btree (l_receiptdate)
    "i_l_shipdate" btree (l_shipdate)
    "i_l_suppkey" btree (l_suppkey)
    "i_l_suppkey_partkey" btree (l_partkey, l_suppkey)

tpch=# SELECT relname, relpages, reltuples, relallvisible, relkind, relnatts, relhassubclass, reloptions, pg_table_size(oid) FROM pg_class WHERE relname='lineitem';
 relname  | relpages |  reltuples   | relallvisible | relkind | relnatts | relhassubclass | reloptions | pg_table_size
----------+----------+--------------+---------------+---------+----------+----------------+------------+---------------
 lineitem |   112503 | 6.001167e+06 |        112503 | r       |       16 | f              |            |     921903104
(1 row)

Postgresql 12.0 and 12.1 are all manually installed from source.

Both are running on Ubuntu 16.04 kernel 4.4.0-142-generic, on Intel(R) Core(TM) i7-6700K.

Any help greatly appreciated!

Shijia