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

Pavel Stehule <[email protected]> Tue, 17 Dec 2019 07:46:46 +0100
Newsgroups gmane.comp.db.postgresql.bugs
Message-ID <CAFj8pRBA12DHHNb=S5rK6YW5kSGhpSxQp6xh0AKpY036J36DCg@mail.gmail.com>
út 17. 12. 2019 v 7:32 odesílatel avinash varma <[email protected]>
napsal:

> Hi Pavel,
>
> Collation " en_US.UTF-8" is same on both databases. Infact both the v10
> and V11 databases are on same machine.
>
> Can you please let us know if i need to check anything..
>

a) please don't send top post reply
https://en.wikipedia.org/wiki/Posting_style - top posting is prohibited here

b) can you compare size of databases, indexes?

Pavel


> Thanks,
> Avinash
>
> On Tue, Dec 17, 2019 at 11:50 AM Pavel Stehule <[email protected]>
> wrote:
>
>>
>>
>> út 17. 12. 2019 v 7:11 odesílatel avinash varma <
>> [email protected]> napsal:
>>
>>> Hi Tom,
>>>
>>>   You didn't answer the question:
>>>
>>> >> First thing to do is to look into pg_stats and see how large those
>>> >> arrays actually are in each case ...
>>>
>>> We reproduced issue with sample tables "child" and "core", moreover
>>> these tables  doesn't contains any data in it in both postgresql 10 & 11.
>>>
>>> select count(1) from child --0
>>> select count(1) from core --0
>>>
>>> I did analyzed both the tables using the below command and after which i
>>> ran the below explain analyze and took the perf report.
>>>
>>> Vacuum analyze child;
>>> vacuum analyze core;
>>>
>>> Both configuration parameters are identical in V10 & V11. But we observe
>>> high planning time in V11 when compared with V10.
>>>
>>> PostDB11=# explain analyze  SELECT --DISTINCT kc.childid AS rlid,
>>> PostDB11-#     kc.id AS rlrightid--,
>>> PostDB11-#    -- 0 AS rlproxytype
>>> PostDB11-#    FROM child kc
>>> PostDB11-#   WHERE NOT (EXISTS ( SELECT 1
>>> PostDB11(#            FROM core
>>> PostDB11(#           WHERE kc.id = core.groupid));
>>>
>>>
>>> Postgres 10
>>>
>>> -bash-4.2$ perf report -g
>>> Samples: 6K of event 'cpu-clock:uhH', Event count (approx.): 1541000000
>>>   Children      Self  Command   Shared Object          Symbol
>>>
>>>
>>>
>>>
>>> *+   13.72%     0.00%  postgres  [unknown]              [.]
>>> 0000000000000000+    5.34%     0.08%  postgres  libc-2.17.so
>>> <http://libc-2.17.so>           [.] __vsnprintf_chk+    4.62%     1.52%
>>>  postgres  libc-2.17.so <http://libc-2.17.so>           [.] vfprintf+
>>>  4.59%     4.59%  postgres  postgres               [.] SearchCatCache+
>>>  4.12%     0.00%  postgres  [unknown]              [.] 0x0000000001d86000*
>>> +    4.09%     4.09%  postgres  postgres               [.] base_yyparse
>>> +    2.09%     0.00%  postgres  [unknown]              [.]
>>> 0x312e2e32362e3135
>>> +    2.04%     2.03%  postgres  postgres               [.]
>>> hash_search_with_hash_value
>>>      1.83%     1.83%  postgres  libc-2.17.so           [.]
>>> __strcmp_sse42
>>> +    1.78%     0.00%  postgres  [unknown]              [.]
>>> 0x0000000001d83638
>>> +    1.74%     0.00%  postgres  [unknown]              [.]
>>> 0x0000000000cb3260
>>> +    1.49%     1.43%  postgres  libc-2.17.so           [.]
>>> __GI___printf_fp_l
>>>
>>>
>>>
>>> Postgres 11
>>>
>>>
>>> bash-4.2$ perf report -g
>>> Samples: 235K of event 'cpu-clock:uhH', Event count (approx.):
>>> 58888750000
>>>   Children      Self  Command   Shared Object       Symbol
>>> +   37.73%    37.73%  postgres  postgres            [.] FunctionCall2Coll
>>> +   28.57%    28.57%  postgres  postgres            [.] eqjoinsel
>>> +   13.94%    13.94%  postgres  postgres            [.] int8eq
>>> +    5.68%     5.68%  postgres  postgres            [.]
>>> eqjoinsel_semi.isra.3
>>> +    1.78%     0.14%  postgres  libc-2.17.so        [.] __clock_gettime
>>> +    1.76%     1.76%  postgres  postgres            [.] pglz_decompress
>>> +    1.68%     1.68%  postgres  [vdso]              [.]
>>> __vdso_clock_gettime
>>> +    1.43%     0.00%  postgres  [unknown]           [.] 0000000000000000
>>> +    1.22%     0.00%  postgres  postgres            [.] TTSOpsVirtual+0x0
>>> +    0.93%     0.00%  postgres  postgres            [.]
>>> TTSOpsBufferHeapTuple+0x0
>>> +    0.72%     0.00%  postgres  [unknown]           [.]
>>> 0x00000000026bb0d0
>>>      0.44%     0.44%  postgres  postgres            [.] deconstruct_array
>>>
>>> Thanks,
>>> Avinash
>>>
>>
>> is same collation in both databases?
>>
>> Maybe there are some issues in virtualization
>>
>> Pavel
>>
>
>
> --
> Thanks & Regards,
>
> Avinash.
>