Postgres Pro
Downloads
Home   >   mailing lists

Re: strange slow query - lost lot of time somewhere - Mailing list pgsql-hackers

From Pavel Stehule
Subject Re: strange slow query - lost lot of time somewhere
Date
Msg-id CAFj8pRAuiS9LoH=OU5TMjfSw+XcysapLCdgLHem0jkvA7fEdng@mail.gmail.com
Whole thread Raw
In response to Re: strange slow query - lost lot of time somewhere  (David Rowley <dgrowleyml@gmail.com>)
Responses Re: strange slow query - lost lot of time somewhere
Re: strange slow query - lost lot of time somewhere
List pgsql-hackers
Tree view


pá 6. 5. 2022 v 1:19 odesílatel David Rowley <dgrowleyml@gmail.com> napsal:
On Thu, 5 May 2022 at 19:26, Pavel Stehule <pavel.stehule@gmail.com> wrote:
>
> čt 5. 5. 2022 v 8:51 odesílatel Jakub Wartak <Jakub.Wartak@tomtom.com> napsal:
>> > Breakpoint 1, 0x00007f557f0c16c0 in mmap64 () from /lib64/libc.so.6
>> > (gdb) bt
>> > #0  0x00007f557f0c16c0 in mmap64 () from /lib64/libc.so.6
>> > #1  0x00007f557f04dd91 in sysmalloc () from /lib64/libc.so.6
>> > #2  0x00007f557f04eaa9 in _int_malloc () from /lib64/libc.so.6
>> > #3  0x00007f557f04fb1e in malloc () from /lib64/libc.so.6
>> > #4  0x0000000000932134 in AllocSetAlloc ()
>> > #5  0x00000000009376cf in MemoryContextAllocExtended ()
>> > #6  0x00000000006ad915 in ExecInitMemoize ()
>>
>> Well the PGDG repo have the debuginfos (e.g. postgresql14-debuginfo) rpms / dpkgs(?) so I hope you are basically 1 command away of being able to debug it further what happens in ExecInitMemoize()
>> Those packages seem to be safe as they modify only /usr/lib/debug so should not have any impact on production workload.
>
> I just have to wait for admin action - I have no root rights for the server.

Looking at ExecInitMemoize() it's hard to see what could take such a
long time other than the build_hash_table().  Tom did mention this,
but I can't quite see how the size given to that function could be
larger than 91 in your case.

If you get the debug symbols installed, can you use gdb to

break nodeMemoize.c:268
p size

maybe there's something I'm missing following the code and maybe there
is some way that est_entries is not set to what I thought it was.

It would also be good to see the same perf report again after the
debug symbols are installed in order to resolve those unresolved
function names.

Breakpoint 1, build_hash_table (size=4369066, mstate=0xfc7f08) at nodeMemoize.c:268
268 if (size == 0)
(gdb) p size
$1 = 4369066

This is work_mem size

+   99,92%     0,00%  postmaster  postgres               [.] ServerLoop                                                                  ▒
+   99,92%     0,00%  postmaster  postgres               [.] PostgresMain                                                                ▒
+   99,92%     0,00%  postmaster  postgres               [.] exec_simple_query                                                           ▒
+   99,70%     0,00%  postmaster  postgres               [.] PortalRun                                                                   ▒
+   99,70%     0,00%  postmaster  postgres               [.] FillPortalStore                                                             ▒
+   99,70%     0,02%  postmaster  postgres               [.] PortalRunUtility                                                            ▒
+   99,68%     0,00%  postmaster  pg_stat_statements.so  [.] 0x00007f5579b599c6                                                          ▒
+   99,68%     0,00%  postmaster  postgres               [.] standard_ProcessUtility                                                     ▒
+   99,68%     0,00%  postmaster  postgres               [.] ExplainQuery                                                                ◆
+   99,63%     0,00%  postmaster  postgres               [.] ExplainOneQuery                                                             ▒
+   99,16%     0,00%  postmaster  postgres               [.] ExplainOnePlan                                                              ▒
+   99,06%     0,00%  postmaster  pg_stat_statements.so  [.] 0x00007f5579b5ad2c                                                          ▒
+   99,06%     0,00%  postmaster  postgres               [.] standard_ExecutorStart                                                      ▒
+   99,06%     0,00%  postmaster  postgres               [.] InitPlan (inlined)                                                          ▒
+   99,06%     0,00%  postmaster  postgres               [.] ExecInitNode                                                                ▒
+   99,06%     0,00%  postmaster  postgres               [.] ExecInitNestLoop                                                            ▒
+   99,00%     0,02%  postmaster  postgres               [.] ExecInitMemoize                                                             ▒
+   98,87%    26,80%  postmaster  libc-2.28.so           [.] __memset_avx2_erms                                                          ▒
+   98,87%     0,00%  postmaster  postgres               [.] build_hash_table (inlined)                                                  ▒
+   98,87%     0,00%  postmaster  postgres               [.] memoize_create (inlined)                                                    ▒
+   98,87%     0,00%  postmaster  postgres               [.] memoize_allocate (inlined)                                                  ▒
+   98,87%     0,00%  postmaster  postgres               [.] MemoryContextAllocExtended                                                  ▒
+   72,08%    72,08%  postmaster  [unknown]              [k] 0xffffffffbaa010e0
     0,47%     0,00%  postmaster  postgres               [.] pg_plan_query
     0,47%     0,00%  postmaster  pg_stat_statements.so  [.] 0x00007f5579b59ba4
     0,47%     0,00%  postmaster  postgres               [.] standard_planner
     0,47%     0,00%  postmaster  postgres               [.] subquery_planner
     0,47%     0,00%  postmaster  postgres               [.] grouping_planner
     0,47%     0,00%  postmaster  postgres               [.] query_planner
 

David

pgsql-hackers by date:

Previous
From: Pavel Stehule
Date:
Subject: Re: strange slow query - lost lot of time somewhere
Next
From: Tom Lane
Date:
Subject: Re: strange slow query - lost lot of time somewhere