Re: Unexplained rapid growth in memory usage of idle backends

> On May 12, 2023, at 7:38 PM, Erik Wienhold <ewie(at)ewie(dot)name> wrote:
>
>> On 13/05/2023 00:12 CEST Alex Balashov <abalashov(at)evaristesys(dot)com> wrote:
>>
>> We have an application that has a preforked worker pool architecture and
>> opens a relatively large (70+) number of persistent connections to PostgreSQL
>> 14, and have `max_connections` set to 200 accordingly.
>
> Which pg14 minor version exactly?

# dpkg -l postgresql-14
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-==============-================-============-=========================================================
ii postgresql-14 14.4-1.pgdg110+1 amd64 The World's Most Advanced Open Source Relational Database

# psql -V
psql (PostgreSQL) 14.4 (Debian 14.4-1.pgdg110+1)

>
>> Occasionally, about once every 2 months, we'll get a slow-motion implosion
>> over a period of about 24 hours, where the resident memory size of some of
>> the backends shoots up from a reasonable few hundred MB to several gigs --
>> and will keep growing, e.g.
>>
>> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
>> 3932733 postgres 20 0 637740 327124 323840 R 10.7 0.5 0:00.11 postgres
>> 782930 postgres 20 0 3151360 2.8g 551704 S 9.7 4.5 221:43.17 postgres
>> 782839 postgres 20 0 2999896 2.7g 551832 S 8.7 4.3 220:54.55 postgres
>> 3932734 postgres 20 0 636128 338168 336096 R 8.7 0.5 0:00.09 postgres
>> 3932735 postgres 20 0 636128 319824 317768 R 8.7 0.5 0:00.09 postgres
>> 782851 postgres 20 0 3142152 2.8g 551872 S 7.8 4.5 221:22.62 postgres
>> 782855 postgres 20 0 3155144 2.8g 551828 S 7.8 4.5 221:38.59 postgres
>> 782897 postgres 20 0 3148808 2.8g 551724 S 7.8 4.5 220:05.94 postgres
>> 783106 postgres 20 0 3152416 2.8g 551912 S 7.8 4.5 221:24.40 postgres
>> 783168 postgres 20 0 2992592 2.7g 551968 S 7.8 4.2 220:36.06 postgres
>> 782843 postgres 20 0 3146772 2.8g 551944 R 4.9 4.5 221:38.46 postgres
>> 782778 postgres 20 0 3150956 2.8g 551852 R 3.9 4.5 220:49.88 postgres
>
> Function pg_log_backend_memory_contexts(pid int) may give you some insights on
> on the memory allocation for specific backends.
>
> https://www.postgresql.org/docs/14/functions-admin.html#FUNCTIONS-ADMIN-SIGNAL-TABLE

Ah, thanks!

2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 3; CachedPlanQuery: 2048 total in 2 blocks; 552 free (0 chunks); 1496 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 2; SPI Plan: 1024 total in 1 blocks; 600 free (0 chunks); 424 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; 828 more child contexts containing 2714624 total in 2097 blocks; 899280 free (329 chunks); 1815344 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; WAL record construction: 49768 total in 2 blocks; 6360 free (0 chunks); 43408 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; PrivateRefCount: 8192 total in 1 blocks; 2616 free (0 chunks); 5576 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; MdSmgr: 8192 total in 1 blocks; 5640 free (1 chunks); 2552 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; LOCALLOCK hash: 16384 total in 2 blocks; 4592 free (2 chunks); 11792 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; Timezones: 104120 total in 2 blocks; 2616 free (0 chunks); 101504 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: level: 1; ErrorContext: 8192 total in 1 blocks; 7928 free (5 chunks); 264 used
2023-05-12 23:53:23.293 UTC [3934125] eti_adm(at)eti LOG: Grand total: 6417232 bytes in 2461 blocks; 2409920 free (468 chunks); 4007312 used

But what can I learn from this that might be of applied value?

-- Alex

--
Alex Balashov
Principal Consultant
Evariste Systems LLC
Web: https://evaristesys.com
Tel: +1-706-510-6800