Content-Type: text/plain;
	charset=us-ascii
Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3731.500.231\))
Subject: Re: Unexplained rapid growth in memory usage of idle backends
From: Alex Balashov <abalashov@evaristesys.com>
In-Reply-To: <729198445.317848.1683934680067@office.mailbox.org>
Date: Fri, 12 May 2023 19:56:50 -0400
Content-Transfer-Encoding: quoted-printable
Message-Id: <7402BB66-E774-405D-8F75-86142239194F@evaristesys.com>
References: <2D17E15D-8D5B-4DF7-A238-12455C2731D8@evaristesys.com>
 <729198445.317848.1683934680067@office.mailbox.org>
To: Erik Wienhold <ewie@ewie.name>,
 pgsql-admin <pgsql-admin@lists.postgresql.org>
Archived-At: 
 <https://www.postgresql.org/message-id/7402BB66-E774-405D-8F75-86142239194F%40evaristesys.com>
Precedence: bulk


> On May 12, 2023, at 7:38 PM, Erik Wienhold <ewie@ewie.name> wrote:
>=20
>> On 13/05/2023 00:12 CEST Alex Balashov <abalashov@evaristesys.com> =
wrote:
>>=20
>> 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.
>=20
> Which pg14 minor version exactly?

# dpkg -l postgresql-14
Desired=3DUnknown/Install/Remove/Purge/Hold
| =
Status=3DNot/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-=
pend
|/ Err?=3D(none)/Reinst-required (Status,Err: uppercase=3Dbad)
||/ Name           Version          Architecture Description
=
+++-=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D-=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D-=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D-=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D
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)

>=20
>> 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.
>>=20
>>    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
>=20
> Function pg_log_backend_memory_contexts(pid int) may give you some =
insights on
> on the memory allocation for specific backends.
>=20
> =
https://www.postgresql.org/docs/14/functions-admin.html#FUNCTIONS-ADMIN-SI=
GNAL-TABLE

Ah, thanks!

2023-05-12 23:53:23.293 UTC [3934125] eti_adm@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@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@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@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@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@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@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@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@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@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

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