Re: Planning time is high in Postgres 11.5 Compared with Postgres 10.11

Поиск
Список
Период
Сортировка
От avinash varma
Тема Re: Planning time is high in Postgres 11.5 Compared with Postgres 10.11
Дата
Msg-id CADaHE9F1UKPwPeNvrkw_a-a7mkse_U3nVxRwwRfLekzaLj1ESw@mail.gmail.com
обсуждение исходный текст
Ответ на Re: Planning time is high in Postgres 11.5 Compared with Postgres10.11  (Heikki Linnakangas <hlinnaka@iki.fi>)
Ответы Re: Planning time is high in Postgres 11.5 Compared with Postgres 10.11  (Tom Lane <tgl@sss.pgh.pa.us>)
Список pgsql-bugs
Thanks Heikki,

I did reproduce on postgres 11.5 and took the perf report.  

CS-PostDB11=# explain analyze  SELECT --DISTINCT kc.childid AS rlid,
CS-PostDB11-#     kc.id AS rlrightid--,
CS-PostDB11-#    -- 0 AS rlproxytype
CS-PostDB11-#    FROM child kc
CS-PostDB11-#   WHERE NOT (EXISTS ( SELECT 1
CS-PostDB11(#            FROM core
CS-PostDB11(#           WHERE kc.id = core.groupid));
                                                 QUERY PLAN
------------------------------------------------------------------------------------------------------------
 Hash Anti Join  (cost=51.62..102.61 rows=1736 width=8) (actual time=0.005..0.007 rows=0 loops=1)
   Hash Cond: (kc.id = core.groupid)
   ->  Seq Scan on child kc  (cost=0.00..28.50 rows=1850 width=8) (actual time=0.005..0.005 rows=0 loops=1)
   ->  Hash  (cost=28.50..28.50 rows=1850 width=8) (never executed)
         ->  Seq Scan on core  (cost=0.00..28.50 rows=1850 width=8) (never executed)
 Planning Time: 11.378 ms
 Execution Time: 0.057 ms
(7 rows)

CS-PostDB11=# \timing
Timing is on.
CS-PostDB11=#
CS-PostDB11=# do $$
CS-PostDB11$# begin
CS-PostDB11$#    for i in 1..1000 loop
CS-PostDB11$#    execute $query$
CS-PostDB11$#      EXPLAIN SELECT kc.id AS rlrightid FROM child kc
CS-PostDB11$#      WHERE NOT (EXISTS ( SELECT 1 FROM core
CS-PostDB11$#                 WHERE kc.id = core.groupid));
CS-PostDB11$#    $query$;
CS-PostDB11$#    end loop;
CS-PostDB11$# end;
CS-PostDB11$# $$;


DO
Time: 10469.144 ms (00:10.469)

Perf Report Output:

Samples: 41K of event 'cpu-clock:uhH', Event count (approx.): 10461000000
  Children      Self  Command   Shared Object          Symbol
+   49.97%    49.97%  postgres  postgres               [.] FunctionCall2Coll
+   17.58%    17.58%  postgres  postgres               [.] int8eq
+   15.15%    15.15%  postgres  postgres               [.] eqjoinsel
+   12.82%    12.82%  postgres  postgres               [.] eqjoinsel_semi.isra.17

+    1.82%     1.82%  postgres  postgres               [.] pglz_decompress
+    0.96%     0.00%  postgres  [unknown]              [.] 0000000000000000
+    0.62%     0.00%  postgres  [unknown]              [.] 0x0000000000000010
     0.56%     0.56%  postgres  postgres               [.] deconstruct_array
     0.20%     0.00%  postgres  [unknown]              [.] 0x0000000001674bd0


Thanks,
Avinash


On Mon, Dec 16, 2019 at 5:53 PM Heikki Linnakangas <hlinnaka@iki.fi> wrote:
On 16/12/2019 10:58, avinash varma wrote:
> We have performed load test on 11.5 and observed high cpu utilization in
> db server when compared with 10.11. On further investigation we observed
> that below query is taking high planning time(highlighted in yellow) in
> 11.5 and higher versions.

I cannot reproduce that on my laptop. Planning takes less than 1 ms, and
there is no big difference between server versions. Do you have any
non-default settings in postgresql.conf?

I think you'll need to do more investigation on your end, to figure out
where exactly the time is spent. If you're running on a Linux system,
I'd suggest using 'perf' to capture a trace of the backend functions
where the time is spent:

1. Open a psql session. Run "select pg_backend_pid();" to get the
backend's PID

2. In another terminal, launch "perf record -g -p <pid>".

3. Run the EXPLAIN in a loop:

\timing
do $$
begin
   for i in 1..100000 loop
   execute $query$
     EXPLAIN SELECT kc.id AS rlrightid FROM child kc
     WHERE NOT (EXISTS ( SELECT 1 FROM core
                WHERE kc.id = core.groupid));
   $query$;
   end loop;
end;
$$;

4. Quit psql, and run "perf report -g". It should print a detailed
report on which parts of the system the CPU time is spent.

> Also please note that below kind of query will executes million times in
> our regular activities. So which might creating high CPU issue.

Using a prepared statement would be a good idea in that case.

- Heikki


--
Thanks & Regards,

Avinash.

В списке pgsql-bugs по дате отправления:

Предыдущее
От: Tomas Vondra
Дата:
Сообщение: Re: BUG #16104: Invalid DSA Memory Alloc Request in Parallel Hash
Следующее
От: Tom Lane
Дата:
Сообщение: Re: Planning time is high in Postgres 11.5 Compared with Postgres 10.11