Re: using memoize in in paralel query decreases performance

po 6. 3. 2023 v 22:52 odesílatel David Rowley <dgrowleyml(at)gmail(dot)com> napsal:

> On Mon, 6 Mar 2023 at 21:55, Pavel Stehule <pavel(dot)stehule(at)gmail(dot)com>
> wrote:
> > default https://explain.depesz.com/s/fnBe
>
> It looks like the slowness is coming from the Bitmap Index scan and
> Bitmap heap scan rather than Memoize.
>
> -> Bitmap Heap Scan on public.item i (cost=285.69..41952.12
> rows=29021 width=16) (actual time=20.395..591.606 rows=20471
> loops=784)
> Output: i.id, i.item_category_id
> Recheck Cond: (i.item_category_id = ictc.sub_category_id)
> Heap Blocks: exact=1590348
> Worker 0: actual time=20.128..591.426 rows=20471 loops=112
> Worker 1: actual time=20.243..591.627 rows=20471 loops=112
> Worker 2: actual time=20.318..591.660 rows=20471 loops=112
> Worker 3: actual time=21.180..591.644 rows=20471 loops=112
> Worker 4: actual time=20.226..591.357 rows=20471 loops=112
> Worker 5: actual time=20.597..591.418 rows=20471 loops=112
> -> Bitmap Index Scan on ixfk_ite_itemcategoryid
> (cost=0.00..278.43 rows=29021 width=0) (actual time=14.851..14.851
> rows=25362 loops=784)
> Index Cond: (i.item_category_id = ictc.sub_category_id)
> Worker 0: actual time=14.863..14.863 rows=25362 loops=112
> Worker 1: actual time=14.854..14.854 rows=25362 loops=112
> Worker 2: actual time=14.611..14.611 rows=25362 loops=112
> Worker 3: actual time=15.245..15.245 rows=25362 loops=112
> Worker 4: actual time=14.909..14.909 rows=25362 loops=112
> Worker 5: actual time=14.841..14.841 rows=25362 loops=112
>
> > disabled memoize https://explain.depesz.com/s/P2rP
>
> -> Bitmap Heap Scan on public.item i (cost=285.69..41952.12
> rows=29021 width=16) (actual time=9.256..57.503 rows=20471 loops=784)
> Output: i.id, i.item_category_id
> Recheck Cond: (i.item_category_id = ictc.sub_category_id)
> Heap Blocks: exact=1590349
> Worker 0: actual time=9.422..58.420 rows=20471 loops=112
> Worker 1: actual time=9.449..57.539 rows=20471 loops=112
> Worker 2: actual time=9.751..58.129 rows=20471 loops=112
> Worker 3: actual time=9.620..57.484 rows=20471 loops=112
> Worker 4: actual time=8.940..57.911 rows=20471 loops=112
> Worker 5: actual time=9.454..57.488 rows=20471 loops=112
> -> Bitmap Index Scan on ixfk_ite_itemcategoryid
> (cost=0.00..278.43 rows=29021 width=0) (actual time=4.581..4.581
> rows=25363 loops=784)
> Index Cond: (i.item_category_id = ictc.sub_category_id)
> Worker 0: actual time=4.846..4.846 rows=25363 loops=112
> Worker 1: actual time=4.734..4.734 rows=25363 loops=112
> Worker 2: actual time=4.803..4.803 rows=25363 loops=112
> Worker 3: actual time=4.959..4.959 rows=25363 loops=112
> Worker 4: actual time=4.402..4.402 rows=25363 loops=112
> Worker 5: actual time=4.778..4.778 rows=25363 loops=112
>
> I wonder if the additional work_mem required for Memoize is just doing
> something like causing kernel page cache evictions and leading to
> fewer buffers for ixfk_ite_itemcategoryid and the item table being
> cached in the kernel page cache.
>
> Maybe you could get an idea of that if you SET track_io_timing = on;
> and EXPLAIN (ANALYZE, BUFFERS) both queries.
>

https://explain.depesz.com/s/vhk0
https://explain.depesz.com/s/R5ju

Regards

Pavel

> David
>