Re: ERROR: could not resize shared memory segment...No space left on device

From: Thomas Munro <thomas(dot)munro(at)gmail(dot)com>
To: Tomas Vondra <tomas(dot)vondra(at)2ndquadrant(dot)com>
Cc: Justin Pryzby <pryzby(at)telsasoft(dot)com>, pgsql-hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: Re: ERROR: could not resize shared memory segment...No space left on device
Date: 2019-12-16 23:17:08
Message-ID: CA+hUKGKfDF+Z-32ejxVjunTqkAaF-mznOAy30dhS9KEHsXjVzA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

On Tue, Dec 17, 2019 at 10:53 AM Tomas Vondra
<tomas(dot)vondra(at)2ndquadrant(dot)com> wrote:
> Interestingly enough, I ran into the same ERROR (not sure if the same
> root cause) while investigating bug #16104 [1], i.e. on a much simpler
> query (single join).
>
> This This particular machine is a bit smaller (only 8GB of RAM and less
> disk space) so I created a smaller table with "just" 1.5B rows:
>
> create table test as select generate_series(1, 1500000000)::bigint i;
> set work_mem = '150MB';
> set max_parallel_workers_per_gather = 8;
> analyze test;
>
> explain select count(*) from test t1 join test t2 using (i);
>
> QUERY PLAN
> ------------------------------------------------------------------------------------------------------------
> Finalize Aggregate (cost=67527436.36..67527436.37 rows=1 width=8)
> -> Gather (cost=67527435.53..67527436.34 rows=8 width=8)
> Workers Planned: 8
> -> Partial Aggregate (cost=67526435.53..67526435.54 rows=1 width=8)
> -> Parallel Hash Join (cost=11586911.03..67057685.47 rows=187500024 width=0)
> Hash Cond: (t1.i = t2.i)
> -> Parallel Seq Scan on test t1 (cost=0.00..8512169.24 rows=187500024 width=8)
> -> Parallel Hash (cost=8512169.24..8512169.24 rows=187500024 width=8)
> -> Parallel Seq Scan on test t2 (cost=0.00..8512169.24 rows=187500024 width=8)
> (9 rows)
>
> explain analyze select count(*) from test t1 join test t2 using (i);
>
> ERROR: could not resize shared memory segment "/PostgreSQL.1743102822" to 536870912 bytes: No space left on device
>
> Now, work_mem = 150MB might be a bit too high considering the machine
> only has 8GB of RAM (1GB of which is shared_buffers). But that's still
> just 1.2GB of RAM and this is not an OOM. This actually fills the
> /dev/shm mount, which is limited to 4GB on this box
>
> bench ~ # df | grep shm
> shm 3994752 16 3994736 1% /dev/shm
>
> So somewhere in the parallel hash join, we allocate 4GB of shared segments ...
>
> The filesystem usage from the moment of the query execution to the
> failure looks about like this:
>
> Time fs 1K-blocks Used Available Use% Mounted on
> --------------------------------------------------------------
> 10:13:34 shm 3994752 34744 3960008 1% /dev/shm
> 10:13:35 shm 3994752 35768 3958984 1% /dev/shm
> 10:13:36 shm 3994752 37816 3956936 1% /dev/shm
> 10:13:39 shm 3994752 39864 3954888 1% /dev/shm
> 10:13:42 shm 3994752 41912 3952840 2% /dev/shm
> 10:13:46 shm 3994752 43960 3950792 2% /dev/shm
> 10:13:49 shm 3994752 48056 3946696 2% /dev/shm
> 10:13:56 shm 3994752 52152 3942600 2% /dev/shm
> 10:14:02 shm 3994752 56248 3938504 2% /dev/shm
> 10:14:09 shm 3994752 60344 3934408 2% /dev/shm
> 10:14:16 shm 3994752 68536 3926216 2% /dev/shm
> 10:14:30 shm 3994752 76728 3918024 2% /dev/shm
> 10:14:43 shm 3994752 84920 3909832 3% /dev/shm
> 10:14:43 shm 3994752 84920 3909832 3% /dev/shm
> 10:14:57 shm 3994752 93112 3901640 3% /dev/shm
> 10:15:11 shm 3994752 109496 3885256 3% /dev/shm
> 10:15:38 shm 3994752 125880 3868872 4% /dev/shm
> 10:16:06 shm 3994752 142264 3852488 4% /dev/shm
> 10:19:57 shm 3994752 683208 3311544 18% /dev/shm
> 10:19:58 shm 3994752 1338568 2656184 34% /dev/shm
> 10:20:02 shm 3994752 1600712 2394040 41% /dev/shm
> 10:20:03 shm 3994752 2125000 1869752 54% /dev/shm
> 10:20:04 shm 3994752 2649288 1345464 67% /dev/shm
> 10:20:08 shm 3994752 2518216 1476536 64% /dev/shm
> 10:20:10 shm 3994752 3173576 821176 80% /dev/shm
> 10:20:14 shm 3994752 3697864 296888 93% /dev/shm
> 10:20:15 shm 3994752 3417288 577464 86% /dev/shm
> 10:20:16 shm 3994752 3697864 296888 93% /dev/shm
> 10:20:20 shm 3994752 3828936 165816 96% /dev/shm
>
> And at the end, the contents of /dev/shm looks like this:
>
> -rw------- 1 postgres postgres 33624064 Dec 16 22:19 PostgreSQL.1005341478
> -rw------- 1 postgres postgres 1048576 Dec 16 22:20 PostgreSQL.1011142277
> -rw------- 1 postgres postgres 1048576 Dec 16 22:20 PostgreSQL.1047241463
> -rw------- 1 postgres postgres 16777216 Dec 16 22:16 PostgreSQL.1094702083
> -rw------- 1 postgres postgres 268435456 Dec 16 22:20 PostgreSQL.1143288540
> -rw------- 1 postgres postgres 536870912 Dec 16 22:20 PostgreSQL.1180709918
> -rw------- 1 postgres postgres 7408 Dec 14 15:43 PostgreSQL.1239805533
> -rw------- 1 postgres postgres 134217728 Dec 16 22:20 PostgreSQL.1292496162
> -rw------- 1 postgres postgres 268435456 Dec 16 22:20 PostgreSQL.138443773
> -rw------- 1 postgres postgres 4194304 Dec 16 22:15 PostgreSQL.1442035225
> -rw------- 1 postgres postgres 67108864 Dec 16 22:20 PostgreSQL.147930162
> -rw------- 1 postgres postgres 16777216 Dec 16 22:20 PostgreSQL.1525896026
> -rw------- 1 postgres postgres 67108864 Dec 16 22:20 PostgreSQL.1541133044
> -rw------- 1 postgres postgres 33624064 Dec 16 22:14 PostgreSQL.1736434498
> -rw------- 1 postgres postgres 134217728 Dec 16 22:20 PostgreSQL.1845631548
> -rw------- 1 postgres postgres 33624064 Dec 16 22:19 PostgreSQL.1952212453
> -rw------- 1 postgres postgres 134217728 Dec 16 22:20 PostgreSQL.1965950370
> -rw------- 1 postgres postgres 8388608 Dec 16 22:15 PostgreSQL.1983158004
> -rw------- 1 postgres postgres 33624064 Dec 16 22:19 PostgreSQL.1997631477
> -rw------- 1 postgres postgres 16777216 Dec 16 22:20 PostgreSQL.2071391455
> -rw------- 1 postgres postgres 2097152 Dec 16 22:20 PostgreSQL.210551357
> -rw------- 1 postgres postgres 67108864 Dec 16 22:20 PostgreSQL.2125755117
> -rw------- 1 postgres postgres 8388608 Dec 16 22:14 PostgreSQL.2133152910
> -rw------- 1 postgres postgres 2097152 Dec 16 22:20 PostgreSQL.255342242
> -rw------- 1 postgres postgres 2097152 Dec 16 22:20 PostgreSQL.306663870
> -rw------- 1 postgres postgres 536870912 Dec 16 22:20 PostgreSQL.420982703
> -rw------- 1 postgres postgres 134217728 Dec 16 22:20 PostgreSQL.443494372
> -rw------- 1 postgres postgres 134217728 Dec 16 22:20 PostgreSQL.457417415
> -rw------- 1 postgres postgres 4194304 Dec 16 22:20 PostgreSQL.462376479
> -rw------- 1 postgres postgres 16777216 Dec 16 22:16 PostgreSQL.512403457
> -rw------- 1 postgres postgres 8388608 Dec 16 22:14 PostgreSQL.546049346
> -rw------- 1 postgres postgres 196864 Dec 16 22:13 PostgreSQL.554918510
> -rw------- 1 postgres postgres 687584 Dec 16 22:13 PostgreSQL.585813590
> -rw------- 1 postgres postgres 4194304 Dec 16 22:15 PostgreSQL.612034010
> -rw------- 1 postgres postgres 33624064 Dec 16 22:19 PostgreSQL.635077233
> -rw------- 1 postgres postgres 7408 Dec 15 17:28 PostgreSQL.69856210
> -rw------- 1 postgres postgres 268435456 Dec 16 22:20 PostgreSQL.785623413
> -rw------- 1 postgres postgres 4194304 Dec 16 22:14 PostgreSQL.802559608
> -rw------- 1 postgres postgres 67108864 Dec 16 22:20 PostgreSQL.825442833
> -rw------- 1 postgres postgres 8388608 Dec 16 22:15 PostgreSQL.827813234
> -rw------- 1 postgres postgres 268435456 Dec 16 22:20 PostgreSQL.942923396
> -rw------- 1 postgres postgres 536870912 Dec 16 22:20 PostgreSQL.948192559
> -rw------- 1 postgres postgres 2097152 Dec 16 22:20 PostgreSQL.968081079
>
> That's a lot of shared segments, considering there are only ~8 workers
> for the parallel hash join. And some of the segments are 512MB, so not
> exactly tiny/abiding to the work_mem limit :-(
>
> I'm not very familiar with the PHJ internals, but this seems a bit
> excessive. I mean, how am I supposed to limit memory usage in these
> queries? Why shouldn't this be subject to work_mem?

It's subject to work_mem per process (leader + workers). So it would
like to use 150M * 9 = 1350M, but then there are things that we don't
measure at all, including the per batch data as you were complaining
about in that other thread, and here that's quite extreme because the
bug in question is one that reaches large partition counts. You're
also looking at the raw shared memory segments, but there is a level
on top of that which is the DSA allocator. It suffers from
fragmentation like any other general purpose allocator (so maybe it is
backed by something like 2x the memory the client allocated at worst),
though unfortunately, unlike typical allocators, we have to force the
OS to really allocate the memory pages on Linux only or it fails with
SIGBUS later when the kernel can't extend a tmpfs file.

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Tom Lane 2019-12-16 23:22:58 Unportable(?) use of setenv() in secure_open_gssapi()
Previous Message Tom Lane 2019-12-16 23:09:31 Re: [PATCH] Memory leak, at src/common/exec.c