<div dir="ltr"><div>I see.</div><div><br></div><div>The problem is, the OOM happens when all RAM is already compromised by pgpool (all 16Gb of RAM is dedicated to pgpool), so any common request will die anyway.</div><div><br></div><div>It happens on versions: 4.2.5 and 4.2.1. Now, I'm running the same application on 3.7.3 and it's running great.</div><div><br></div><div>I don't know if it helps, but just to demonstrate the amount of RAM is necessary to run a few connections I created another VM, and comparing:</div><div><br></div><div>62 active connections running on 4.2.1 (same behaviour on 4.2.5):</div><div>$ vmstat -a -SM<br>procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----<br> r b swpd free inact active si so bi bo in cs us sy id wa st<br> 0 0 0 4829 173 10772 0 0 2 1 68 56 1 1 99 0 0</div><div><br></div><div>31 active connections running on 3.7.3:</div><div>$ vmstat -a -SM<br>procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----<br> r b swpd free inact active si so bi bo in cs us sy id wa st<br> 0 0 0 15174 73 635 0 0 1 1 76 3 0 0 100 0 0</div><div><br></div><div>Both are running basically the same application.<br></div><div><br></div><div>Seeing the RAM consumption of 3.7.3, it does not seem to be receiving such a big requests. Is there a way to track it down?</div><div><br></div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Mon, Sep 27, 2021 at 9:07 AM Tatsuo Ishii <<a href="mailto:ishii@sraoss.co.jp">ishii@sraoss.co.jp</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">At this point I cannot judge whether the problem is caused by a pgpool<br>
bug or client's resource request is too much.<br>
<br>
Typical bug which requests too much memory allocation is not something<br>
like this because 33947648 = 32MB memory request itself is not insane.<br>
<br>
> Sep 24 09:14:10 pgpool pgpool[12650]: [426-2] 2021-09-24 09:14:10: pid<br>
> 12650: DETAIL: Failed on request of size 33947648.<br>
<br>
(Please let us know what version of Pgpool-II you are using because<br>
it's important information to identify any known bug).<br>
<br>
In the mean time, however, I think 32MB memory request is not very<br>
common in pgpool. One thing I wonder is, whether your application<br>
issues SQL which requires large memory: e.g. very long SQL statement,<br>
COPY for large data set. They will request large read/write buffer in<br>
pgpool.<br>
<br>
> We saw both, but pgpool aborting is way more common:<br>
> Sep 24 09:14:10 pgpool pgpool[12650]: [426-1] 2021-09-24 09:14:10: pid<br>
> 12650: ERROR: out of memory<br>
> Sep 24 09:14:10 pgpool pgpool[12650]: [426-2] 2021-09-24 09:14:10: pid<br>
> 12650: DETAIL: Failed on request of size 33947648.<br>
> Sep 24 09:14:10 pgpool pgpool[12650]: [426-3] 2021-09-24 09:14:10: pid<br>
> 12650: LOCATION: mcxt.c:900<br>
> <br>
> Here, two other ways we saw at the logs, but those just occurred once each:<br>
> Sep 24 07:33:14 pgpool pgpool[5874]: [434-1] 2021-09-24 07:33:14: pid 5874:<br>
> FATAL: failed to fork a child<br>
> Sep 24 07:33:14 pgpool pgpool[5874]: [434-2] 2021-09-24 07:33:14: pid 5874:<br>
> DETAIL: system call fork() failed with reason: Cannot allocate memory<br>
> Sep 24 07:33:14 pgpool pgpool[5874]: [434-3] 2021-09-24 07:33:14: pid 5874:<br>
> LOCATION: pgpool_main.c:681<br>
> <br>
> And:<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691518] pgpool invoked oom-killer:<br>
> gfp_mask=0x24200ca, order=0, oom_score_adj=0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691525] CPU: 1 PID: 1194 Comm:<br>
> pgpool Not tainted 4.4.276 #1<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691527] Hardware name: VMware, Inc.<br>
> VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00<br>
> 12/12/2018<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691528] 0000000000000000<br>
> ffff8803281cbae8 ffffffff81c930e7 ffff880420efe2c0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691530] ffff880420efe2c0<br>
> ffff8803281cbb50 ffffffff81c8d9da ffff8803281cbb08<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691532] ffffffff81133f1a<br>
> ffff8803281cbb80 ffffffff81182eb0 ffff8800bba393c0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691533] Call Trace:<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691540] [<ffffffff81c930e7>]<br>
> dump_stack+0x57/0x6d<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691542] [<ffffffff81c8d9da>]<br>
> dump_header.isra.9+0x54/0x1ae<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691547] [<ffffffff81133f1a>] ?<br>
> __delayacct_freepages_end+0x2a/0x30<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691553] [<ffffffff81182eb0>] ?<br>
> do_try_to_free_pages+0x350/0x3d0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691556] [<ffffffff811709f9>]<br>
> oom_kill_process+0x209/0x3c0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691558] [<ffffffff81170eeb>]<br>
> out_of_memory+0x2db/0x2f0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691561] [<ffffffff81176111>]<br>
> __alloc_pages_nodemask+0xa81/0xae0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691565] [<ffffffff811ad2cd>]<br>
> __read_swap_cache_async+0xdd/0x130<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691567] [<ffffffff811ad337>]<br>
> read_swap_cache_async+0x17/0x40<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691569] [<ffffffff811ad455>]<br>
> swapin_readahead+0xf5/0x190<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691571] [<ffffffff8119ce3f>]<br>
> handle_mm_fault+0xf3f/0x15e0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691574] [<ffffffff81c9d4e2>] ?<br>
> __schedule+0x272/0x770<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691576] [<ffffffff8104e241>]<br>
> __do_page_fault+0x161/0x370<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691577] [<ffffffff8104e49c>]<br>
> do_page_fault+0xc/0x10<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691579] [<ffffffff81ca3782>]<br>
> page_fault+0x22/0x30<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691581] Mem-Info:<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691584] active_anon:3564689<br>
> inactive_anon:445592 isolated_anon:0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691584] active_file:462<br>
> inactive_file:44 isolated_file:0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691584] unevictable:0 dirty:2<br>
> writeback:2212 unstable:0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691584] slab_reclaimable:3433<br>
> slab_unreclaimable:5859<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691584] mapped:989 shmem:2607<br>
> pagetables:16367 bounce:0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691584] free:51773 free_pcp:189<br>
> free_cma:0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691589] DMA free:15904kB min:128kB<br>
> low:160kB high:192kB active_anon:0kB inactive_anon:0kB active_file:0kB<br>
> inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB<br>
> present:15992kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB<br>
> mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB<br>
> kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB<br>
> local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0<br>
> all_unreclaimable? yes<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691590] lowmem_reserve[]: 0 2960<br>
> 15991 15991<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691596] DMA32 free:77080kB<br>
> min:25000kB low:31248kB high:37500kB active_anon:2352676kB<br>
> inactive_anon:590536kB active_file:472kB inactive_file:140kB<br>
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3129216kB<br>
> managed:3043556kB mlocked:0kB dirty:0kB writeback:4144kB mapped:1140kB<br>
> shmem:3568kB slab_reclaimable:1028kB slab_unreclaimable:3004kB<br>
> kernel_stack:816kB pagetables:10988kB unstable:0kB bounce:0kB<br>
> free_pcp:312kB local_pcp:196kB free_cma:0kB writeback_tmp:0kB<br>
> pages_scanned:4292 all_unreclaimable? yes<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691597] lowmem_reserve[]: 0 0 13031<br>
> 13031<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691601] Normal free:114108kB<br>
> min:110032kB low:137540kB high:165048kB active_anon:11906080kB<br>
> inactive_anon:1191832kB active_file:1376kB inactive_file:36kB<br>
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:13631488kB<br>
> managed:13343784kB mlocked:0kB dirty:8kB writeback:4704kB mapped:2816kB<br>
> shmem:6860kB slab_reclaimable:12704kB slab_unreclaimable:20432kB<br>
> kernel_stack:4848kB pagetables:54480kB unstable:0kB bounce:0kB<br>
> free_pcp:444kB local_pcp:196kB free_cma:0kB writeback_tmp:0kB<br>
> pages_scanned:105664 all_unreclaimable? yes<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691602] lowmem_reserve[]: 0 0 0 0<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691603] DMA: 0*4kB 0*8kB 0*16kB<br>
> 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB<br>
> (U) 3*4096kB (M) = 15904kB<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691610] DMA32: 48*4kB (ME) 63*8kB<br>
> (ME) 62*16kB (E) 46*32kB (UME) 35*64kB (UME) 26*128kB (UME) 25*256kB (UME)<br>
> 61*512kB (UME) 28*1024kB (UME) 1*2048kB (M) 0*4096kB = 77080kB<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691616] Normal: 165*4kB (MEH)<br>
> 317*8kB (UMEH) 442*16kB (UMEH) 289*32kB (UMEH) 162*64kB (UMEH) 121*128kB<br>
> (UMEH) 74*256kB (UMEH) 33*512kB (UMEH) 24*1024kB (ME) 0*2048kB 2*4096kB (M)<br>
> = 113980kB<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691623] 5552 total pagecache pages<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691624] 2355 pages in swap cache<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691625] Swap cache stats: add<br>
> 5385308, delete 5382953, find 1159094/1325033<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691626] Free swap = 0kB<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691626] Total swap = 4194300kB<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691627] 4194174 pages RAM<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691628] 0 pages HighMem/MovableOnly<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691628] 93363 pages reserved<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691989] Out of memory: Kill process<br>
> 8975 (pgpool) score 7 or sacrifice child<br>
> Sep 23 17:07:40 pgpool kernel: [157160.691995] Killed process 8975 (pgpool)<br>
> total-vm:337504kB, anon-rss:166824kB, file-rss:1920kB<br>
> <br>
> <br>
> <br>
> On Mon, Sep 27, 2021 at 1:22 AM Tatsuo Ishii <<a href="mailto:ishii@sraoss.co.jp" target="_blank">ishii@sraoss.co.jp</a>> wrote:<br>
> <br>
>> Hi,<br>
>><br>
>> > Hello,<br>
>> ><br>
>> > Our pgpool is consuming A LOT of memory and frequently dies with: Out of<br>
>> > memory error.<br>
>> ><br>
>> > We have 2 backends, 1 master and 1 slave. Here some config:<br>
>> > num_init_children = 150<br>
>> > max_pool = 1<br>
>> > child_life_time = 300<br>
>> > child_max_connections = 1<br>
>> > connection_life_time = 0<br>
>> > client_idle_limit = 0<br>
>> > connection_cache = on<br>
>> > load_balance_mode = on<br>
>> > memory_cache_enabled = off<br>
>> ><br>
>> > RAM: 16Gb<br>
>> ><br>
>> > Does anyone have a clue what's going on?<br>
>> ><br>
>> > Thank you.<br>
>><br>
>> Is that OOM killer or pgpool itself aborted with an out of memory<br>
>> error? If latter, can you share the pgpool log?<br>
>> --<br>
>> Tatsuo Ishii<br>
>> SRA OSS, Inc. Japan<br>
>> English: <a href="http://www.sraoss.co.jp/index_en.php" rel="noreferrer" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
>> Japanese:<a href="http://www.sraoss.co.jp" rel="noreferrer" target="_blank">http://www.sraoss.co.jp</a><br>
>><br>
> <br>
> <br>
> -- <br>
> Luiz Fernando Pasqual S. Souza<br>
> mail: <a href="mailto:luiz@pasquall.com" target="_blank">luiz@pasquall.com</a><br>
</blockquote></div><br clear="all"><br>-- <br><div dir="ltr" class="gmail_signature">Luiz Fernando Pasqual S. Souza<br>mail: <a href="mailto:luiz@pasquall.com" target="_blank">luiz@pasquall.com</a></div>