Re: strange slow query - lost lot of time somewhere

2022-05-15 Thread Pavel Stehule
po 16. 5. 2022 v 6:11 odesílatel David Rowley napsal: > On Fri, 6 May 2022 at 21:27, David Rowley wrote: > > I've attached a patch to fix. I'll look at it in more detail after the > weekend. > > I've now pushed this fix to master and backpatched to 14. > Thank you Pavel > > David >

Re: strange slow query - lost lot of time somewhere

2022-05-15 Thread David Rowley
On Fri, 6 May 2022 at 21:27, David Rowley wrote: > I've attached a patch to fix. I'll look at it in more detail after the > weekend. I've now pushed this fix to master and backpatched to 14. David

Re: strange slow query - lost lot of time somewhere

2022-05-10 Thread David Rowley
On Tue, 10 May 2022 at 14:22, Justin Pryzby wrote: > On Fri, May 06, 2022 at 09:27:57PM +1200, David Rowley wrote: > > I'm very tempted to change the EXPLAIN output in at least master to > > display the initial and final (maximum) hash table sizes. Wondering if > > anyone would object to that? >

Re: strange slow query - lost lot of time somewhere

2022-05-09 Thread Justin Pryzby
On Tue, May 03, 2022 at 02:13:18PM +1200, David Rowley wrote: > I'm wishing I put the initial hash table size and the final hash table > size in EXPLAIN + EXPLAIN ANALYZE now. Perhaps it's not too late for > v15 to do that so that it might help us figure things out in the > future. On Fri, May

Re: strange slow query - lost lot of time somewhere

2022-05-06 Thread Pavel Stehule
pá 6. 5. 2022 v 10:05 odesílatel David Rowley napsal: > On Fri, 6 May 2022 at 17:52, Pavel Stehule > wrote: > > Breakpoint 1, build_hash_table (size=4369066, mstate=0xfc7f08) at > nodeMemoize.c:268 > > 268 if (size == 0) > > (gdb) p size > > $1 = 4369066 > > Thanks for the report. I think I

Re: strange slow query - lost lot of time somewhere

2022-05-06 Thread David Rowley
On Fri, 6 May 2022 at 20:04, David Rowley wrote: > Thanks for the report. I think I now see the problem. Looking at > [1], it seems that's a bushy plan. That's fine, but less common than a > left deep plan. On second thoughts, it does not need to be a bushy plan for the outer side of the

Re: strange slow query - lost lot of time somewhere

2022-05-06 Thread David Rowley
On Fri, 6 May 2022 at 17:52, Pavel Stehule wrote: > Breakpoint 1, build_hash_table (size=4369066, mstate=0xfc7f08) at > nodeMemoize.c:268 > 268 if (size == 0) > (gdb) p size > $1 = 4369066 Thanks for the report. I think I now see the problem. Looking at [1], it seems that's a bushy plan.

Re: strange slow query - lost lot of time somewhere

2022-05-06 Thread Tom Lane
Pavel Stehule writes: > Breakpoint 1, build_hash_table (size=4369066, mstate=0xfc7f08) at > nodeMemoize.c:268 > 268 if (size == 0) > (gdb) p size > $1 = 4369066 Uh-huh regards, tom lane

Re: strange slow query - lost lot of time somewhere

2022-05-05 Thread Pavel Stehule
pá 6. 5. 2022 v 1:19 odesílatel David Rowley napsal: > On Thu, 5 May 2022 at 19:26, Pavel Stehule > wrote: > > > > čt 5. 5. 2022 v 8:51 odesílatel Jakub Wartak > napsal: > >> > Breakpoint 1, 0x7f557f0c16c0 in mmap64 () from /lib64/libc.so.6 > >> > (gdb) bt > >> > #0 0x7f557f0c16c0 in

Re: strange slow query - lost lot of time somewhere

2022-05-05 Thread Pavel Stehule
pá 6. 5. 2022 v 1:28 odesílatel David G. Johnston < david.g.johns...@gmail.com> napsal: > On Mon, May 2, 2022 at 10:02 PM Pavel Stehule > wrote: > >> >> >> út 3. 5. 2022 v 6:57 odesílatel Tom Lane napsal: >> >>> Pavel Stehule writes: >>> > there is really something strange (see attached file).

Re: strange slow query - lost lot of time somewhere

2022-05-05 Thread David G. Johnston
On Mon, May 2, 2022 at 10:02 PM Pavel Stehule wrote: > > > út 3. 5. 2022 v 6:57 odesílatel Tom Lane napsal: > >> Pavel Stehule writes: >> > there is really something strange (see attached file). Looks so this >> issue >> > is much more related to planning time than execution time >> >> You

Re: strange slow query - lost lot of time somewhere

2022-05-05 Thread David Rowley
On Thu, 5 May 2022 at 19:26, Pavel Stehule wrote: > > čt 5. 5. 2022 v 8:51 odesílatel Jakub Wartak napsal: >> > Breakpoint 1, 0x7f557f0c16c0 in mmap64 () from /lib64/libc.so.6 >> > (gdb) bt >> > #0 0x7f557f0c16c0 in mmap64 () from /lib64/libc.so.6 >> > #1 0x7f557f04dd91 in

Re: strange slow query - lost lot of time somewhere

2022-05-05 Thread Pavel Stehule
čt 5. 5. 2022 v 8:51 odesílatel Jakub Wartak napsal: > Hi Pavel, > > > I have not debug symbols, so I have not more details now > > Breakpoint 1 at 0x7f557f0c16c0 > > (gdb) c > > Continuing. > > > Breakpoint 1, 0x7f557f0c16c0 in mmap64 () from /lib64/libc.so.6 > > (gdb) bt > > #0

RE: strange slow query - lost lot of time somewhere

2022-05-05 Thread Jakub Wartak
Hi Pavel, > I have not debug symbols, so I have not more details now > Breakpoint 1 at 0x7f557f0c16c0 > (gdb) c > Continuing. > Breakpoint 1, 0x7f557f0c16c0 in mmap64 () from /lib64/libc.so.6 > (gdb) bt > #0  0x7f557f0c16c0 in mmap64 () from /lib64/libc.so.6 > #1  0x7f557f04dd91 in

Re: strange slow query - lost lot of time somewhere

2022-05-04 Thread Pavel Stehule
st 4. 5. 2022 v 16:08 odesílatel Jakub Wartak napsal: > > Additional three ways to figure that one (all are IMHO production safe): > a) already mentioned perf with --call-graph dwarf -p PID > b) strace -p PID -e 'mmap' # verify if mmap() NULL is not having > MAP_ANONYMOUS flag, size of mmap()

Re: strange slow query - lost lot of time somewhere

2022-05-04 Thread Pavel Stehule
st 4. 5. 2022 v 2:15 odesílatel David Rowley napsal: > On Tue, 3 May 2022 at 17:02, Pavel Stehule > wrote: > > út 3. 5. 2022 v 6:57 odesílatel Tom Lane napsal: > >> You sure there's not something taking an exclusive lock on one of these > >> tables every so often? > > > > I am almost sure, I

RE: strange slow query - lost lot of time somewhere

2022-05-04 Thread Jakub Wartak
> I do agree that the perf report does indicate that the extra time is taken > due to > some large amount of memory being allocated. I just can't quite see how that > would happen in Memoize given that > estimate_num_groups() clamps the distinct estimate as the number of input > rows, which is 91

Re: strange slow query - lost lot of time somewhere

2022-05-03 Thread David Rowley
On Tue, 3 May 2022 at 17:02, Pavel Stehule wrote: > út 3. 5. 2022 v 6:57 odesílatel Tom Lane napsal: >> You sure there's not something taking an exclusive lock on one of these >> tables every so often? > > I am almost sure, I can see this issue only every time when I set a higher > work mem. I

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
út 3. 5. 2022 v 6:57 odesílatel Tom Lane napsal: > Pavel Stehule writes: > > there is really something strange (see attached file). Looks so this > issue > > is much more related to planning time than execution time > > You sure there's not something taking an exclusive lock on one of these >

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Tom Lane
Pavel Stehule writes: > there is really something strange (see attached file). Looks so this issue > is much more related to planning time than execution time You sure there's not something taking an exclusive lock on one of these tables every so often? regards, tom lane

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
út 3. 5. 2022 v 6:09 odesílatel Pavel Stehule napsal: > > > po 2. 5. 2022 v 23:48 odesílatel David Rowley > napsal: > >> On Mon, 2 May 2022 at 21:00, Pavel Stehule >> wrote: >> > I found a query that is significantly slower with more memory >> >> Can you clarify what you mean here? More

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
po 2. 5. 2022 v 23:48 odesílatel David Rowley napsal: > On Mon, 2 May 2022 at 21:00, Pavel Stehule > wrote: > > I found a query that is significantly slower with more memory > > Can you clarify what you mean here? More memory was installed on the > machine? or work_mem was increased? or? > > >

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David Rowley
On Tue, 3 May 2022 at 15:22, David G. Johnston wrote: > Plugging in: > n = 2,000 > e = 500 > c = 10,000 > > proper = 5% > incorrect = 25% > > But of the 10,000 calls we will receive, the first 2,000 will be misses while > 2,000 of the remaining 8,000 will be hits, due to sharing 2,000 distinct

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David G. Johnston
On Mon, May 2, 2022 at 7:30 PM David Rowley wrote: > On Tue, 3 May 2022 at 13:43, David G. Johnston > wrote: > > hit_ratio = (est_entries / ndistinct) - (ndistinct / calls) || clamp to > 0.0 > > I don't understand the adjustment factor ndistinct/calls > > I've attached a spreadsheet showing you

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David G. Johnston
On Mon, May 2, 2022 at 7:13 PM David Rowley wrote: > On Tue, 3 May 2022 at 11:02, Tom Lane wrote: > > > > David Rowley writes: > > > On Mon, 2 May 2022 at 21:00, Pavel Stehule > wrote: > > >> I found a query that is significantly slower with more memory > > > > > If it was work_mem you

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David Rowley
On Tue, 3 May 2022 at 13:43, David G. Johnston wrote: > hit_ratio = (est_entries / ndistinct) - (ndistinct / calls) || clamp to 0.0 > I don't understand the adjustment factor ndistinct/calls I've attached a spreadsheet showing you the impact of subtracting (ndistinct / calls). What this is

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David Rowley
On Tue, 3 May 2022 at 11:02, Tom Lane wrote: > > David Rowley writes: > > On Mon, 2 May 2022 at 21:00, Pavel Stehule wrote: > >> I found a query that is significantly slower with more memory > > > If it was work_mem you increased, it seems strange that the plan would > > switch over to using a

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David G. Johnston
On Mon, May 2, 2022 at 4:02 PM Tom Lane wrote: > David Rowley writes: > > On Mon, 2 May 2022 at 21:00, Pavel Stehule > wrote: > >> I found a query that is significantly slower with more memory > > > If it was work_mem you increased, it seems strange that the plan would > > switch over to using

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Tom Lane
David Rowley writes: > On Mon, 2 May 2022 at 21:00, Pavel Stehule wrote: >> I found a query that is significantly slower with more memory > If it was work_mem you increased, it seems strange that the plan would > switch over to using a Nested Loop / Memoize plan. Yeah, there's something

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread David Rowley
On Mon, 2 May 2022 at 21:00, Pavel Stehule wrote: > I found a query that is significantly slower with more memory Can you clarify what you mean here? More memory was installed on the machine? or work_mem was increased? or? > plan 1 - fast https://explain.depesz.com/s/XM1f > > plan 2 - slow

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
po 2. 5. 2022 v 16:44 odesílatel Matthias van de Meent < boekewurm+postg...@gmail.com> napsal: > On Mon, 2 May 2022 at 16:09, Pavel Stehule > wrote: > > > > > > > > po 2. 5. 2022 v 16:02 odesílatel Pavel Stehule > napsal: > >> there is just shared buffers changed to 32GB and work_mem to 70MB. >

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Matthias van de Meent
On Mon, 2 May 2022 at 16:09, Pavel Stehule wrote: > > > > po 2. 5. 2022 v 16:02 odesílatel Pavel Stehule > napsal: >> there is just shared buffers changed to 32GB and work_mem to 70MB. >> Unfortunately - it is in production environment with customer data, so I >> cannot to play too much >> >>

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
po 2. 5. 2022 v 16:02 odesílatel Pavel Stehule napsal: > > > po 2. 5. 2022 v 15:28 odesílatel Matthias van de Meent < > boekewurm+postg...@gmail.com> napsal: > >> On Mon, 2 May 2022 at 11:00, Pavel Stehule >> wrote: >> > >> > Hi >> > >> > I found a query that is significantly slower with more

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
po 2. 5. 2022 v 15:28 odesílatel Matthias van de Meent < boekewurm+postg...@gmail.com> napsal: > On Mon, 2 May 2022 at 11:00, Pavel Stehule > wrote: > > > > Hi > > > > I found a query that is significantly slower with more memory > > Which PostgreSQL version did you use? Did you enable assert

Re: strange slow query - lost lot of time somewhere

2022-05-02 Thread Matthias van de Meent
On Mon, 2 May 2022 at 11:00, Pavel Stehule wrote: > > Hi > > I found a query that is significantly slower with more memory Which PostgreSQL version did you use? Did you enable assert checking? Do you have an example database setup to work with? > plan 2 > QUERY PLAN > >

strange slow query - lost lot of time somewhere

2022-05-02 Thread Pavel Stehule
Hi I found a query that is significantly slower with more memory plan 1 - fast https://explain.depesz.com/s/XM1f plan 2 - slow https://explain.depesz.com/s/2rBw Strange - the time of last row is +/- same, but execution time is 10x worse It looks like slow environment cleaning