MIME-Version: 1.0
References: <CAFj8pRD080wW5fkf3odyV5R7+vTWi42Tj-TWPmp4r+DnzQfMdQ@mail.gmail.com>
 <CAApHDvonLQUDc7SUD4Usok=BP4T+5fK7rcM-wVOmtsvqdu1nAA@mail.gmail.com> <CAFj8pRBRvK2_EGeD7J_37ncax0x7Q==C=zTpg2WzM0uWnvaixg@mail.gmail.com>
In-Reply-To: <CAFj8pRBRvK2_EGeD7J_37ncax0x7Q==C=zTpg2WzM0uWnvaixg@mail.gmail.com>
From: David Rowley <dgrowleyml@gmail.com>
Date: Tue, 7 Mar 2023 10:52:08 +1300
Message-ID: <CAApHDvo3tzN1--Ery+7C3qOnM4gJQw8bz_iG1k9D+O6XxQjGtw@mail.gmail.com>
Subject: Re: using memoize in in paralel query decreases performance
To: Pavel Stehule <pavel.stehule@gmail.com>
Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Content-Type: text/plain; charset="UTF-8"
Archived-At: <https://www.postgresql.org/message-id/CAApHDvo3tzN1--Ery%2B7C3qOnM4gJQw8bz_iG1k9D%2BO6XxQjGtw%40mail.gmail.com>
Precedence: bulk

On Mon, 6 Mar 2023 at 21:55, Pavel Stehule <pavel.stehule@gmail.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.

David