Re: Memory Leak executing small queries without closing the connection - FreeBSD - Mailing list pgsql-general

From Gerhard Wiesinger
Subject Re: Memory Leak executing small queries without closing the connection - FreeBSD
Date
Msg-id 566DC250.4060003@wiesinger.com
Whole thread Raw
In response to Re: Memory Leak executing small queries without closing the connection - FreeBSD  (Tom Lane <tgl@sss.pgh.pa.us>)
Responses Re: Memory Leak executing small queries without closing the connection - FreeBSD  (Bill Moran <wmoran@potentialtech.com>)
List pgsql-general
On 13.12.2015 18:17, Tom Lane wrote:
> Gerhard Wiesinger <lists@wiesinger.com> writes:
>>> Mem: 7814M Active, 20G Inact, 2982M Wired, 232M Cache, 1661M Buf, 30M Free
>>> Swap: 512M Total, 506M Used, 6620K Free, 98% Inuse
>> OK, but why do we then get: kernel: swap_pager_getswapspace(4): failed?
> Just judging from the name of the function, I would bet this is a direct
> result of having only 512M of swap configured.  As Bill already pointed
> out, that's a pretty useless choice on a system with 32G of RAM.  As soon
> as the kernel tries to push out any significant amount of idle processes,
> it's gonna be out of swap space.  The numbers you show above prove that
> it is almost out of free swap already.

The system wasn't designed by me, I wouldn't do it either that way. Does
swapoff help?

>
> Also, while that 20G of "inactive" pages may be candidates for reuse,
> they probably can't actually be reused without swapping them out ...
> and there's noplace for that data to go.

There is no log in syslog (where postgres log) when
swap_pager_getswapspace is logged.

But why do we have 20G of Inactive pages? They are still allocated by
kernel or user space. As you can see below (top output) NON Postgres
processes are around 9G in virtual size, resident even lower. The system
is nearly idle, and the queries typically aren't active after one second
agin. Therefore where does the rest of the 11G of Inactive pages come
from (if it isn't a Postgres/FreeBSD memory leak)?
I read that Postgres has it's own memory allocator:
https://www.reddit.com/r/programming/comments/18zija/github_got_30_better_performance_using_tcmalloc/
Might that be an issue with double allocation/freeing and the "cheese
hole" topic with memory fragmentation?

https://www.opennet.ru/base/dev/fbsdvm.txt.html
         inactive        pages not actively used by programs which are
                         dirty and (at some point) need to be written
                         to their backing store (typically disk).
                         These pages are still associated with objects and
                         can be reclaimed if a program references them.
                         Pages can be moved from the active to the inactive
                         queue at any time with little adverse effect.
                         Moving pages to the cache queue has bigger
                         consequences (note 1)

https://unix.stackexchange.com/questions/134862/what-do-the-different-memory-counters-in-freebsd-mean
     Active: Memory currently being used by a process
     Inactive: Memory that has been freed but is still cached since it
may be used again. If more Free memory is required, this memory can be
cleared and become free. This memory is not cleared before it is needed,
because "free memory is wasted memory", it doesn't cost anything to keep
the old data around in case it is needed again.
     Wired: Memory in use by the Kernel. This memory cannot be swapped
out (GW: including ZFS cache!!!)
     Cache: Memory being used to cache data, can be freed immediately if
required
     Buffers: Disk cache
     Free: Memory that is completely free and ready to use. Inactive,
Cache and Buffers can become free if they are cleaned up.

Thnx.

Ciao,
Gerhard


================================================================================================================================================================
last pid:  7277;  load averages:  0.91,  0.96,  1.02  up 18+06:22:31
18:57:54
135 processes: 2 running, 132 sleeping, 1 waiting

Mem: 8020M Active, 19G Inact, 3537M Wired, 299M Cache, 1679M Buf, 38M Free
Swap: 512M Total, 501M Used, 12M Free, 97% Inuse

   PID USERNAME    THR PRI NICE   SIZE    RES STATE   C TIME    WCPU COMMAND
77941 pgsql         5  20    0  7921M  7295M usem    7 404:32  10.25%
postgres
79570 pgsql         1  20    0  7367M  6968M sbwait  6 4:24   0.59% postgres
73449 pgsql         1  27    0  7367M  6908M sbwait  4 8:08   5.08% postgres
74209 pgsql         1  27    0  7367M  6803M sbwait  0 6:37   1.46% postgres
74207 pgsql         1  25    0  7367M  6748M sbwait  6 6:34   1.76% postgres
74206 pgsql         1  22    0  7367M  6548M sbwait  5 6:44   1.86% postgres
73380 pgsql         1  23    0  7367M  7265M sbwait  4 8:15   1.17% postgres
74208 pgsql         1  24    0  7367M  7223M sbwait  1 6:30   4.59% postgres
79569 pgsql         1  24    0  7367M  7105M sbwait  3 4:36   1.17% postgres
74210 pgsql         1  29    0  7363M  7182M sbwait  5 6:41   5.47% postgres
73479 pgsql         1  22    0  7363M  6560M sbwait  6 7:14   3.56% postgres
83030 pgsql         1  20    0  7329M   193M sbwait  5 0:00   0.00% postgres
76178 pgsql         1  20    0  7323M  7245M sbwait  2 3:44   0.00% postgres
75867 pgsql         1  20    0  7323M  7245M sbwait  2 3:45   0.00% postgres
75869 pgsql         1  20    0  7323M  7245M sbwait  2 3:46   0.00% postgres
75883 pgsql         1  20    0  7323M  7245M sbwait  7 3:46   0.00% postgres
76180 pgsql         1  20    0  7323M  7245M sbwait  7 3:45   0.00% postgres
75868 pgsql         1  20    0  7323M  7245M sbwait  6 3:46   0.00% postgres
76177 pgsql         1  20    0  7323M  7245M sbwait  3 3:45   0.00% postgres
76179 pgsql         1  20    0  7323M  7245M sbwait  3 3:44   0.00% postgres
75884 pgsql         1  20    0  7323M  7245M sbwait  7 3:46   0.00% postgres
76181 pgsql         1  20    0  7323M  7245M sbwait  7 3:44   0.00% postgres
75862 pgsql         1  20    0  7321M  7266M select  0 8:00   0.00% postgres
75863 pgsql         1  20    0  7321M  7261M select  4 4:04   0.00% postgres
  4361 pgsql         1  20    0  7321M   206M sbwait  2 0:00   0.00%
postgres
  7021 pgsql         1  20    0  7321M   181M sbwait  0 0:00   0.00%
postgres
83028 pgsql         1  20    0  7321M   180M sbwait  3 0:00   0.00% postgres
97964 pgsql         1  20    0  7321M   175M sbwait  4 0:00   0.00% postgres
97963 pgsql         1  20    0  7321M   175M sbwait  0 0:01   0.00% postgres
75865 pgsql         1  20    0  7321M   173M select  4 0:05   0.00% postgres
75864 pgsql         1  20    0  7321M   173M select  2 0:54   0.00% postgres
   593 pgsql         1  21    0  7317M   173M select  4 1:50   0.00%
postgres
32387 myusername    9  20    0   980M   375M uwait   5 69:03   1.27% node
71419 myusername    9  20    0   798M   146M uwait   1 0:40   0.00% node
77938 myusername    9  20    0   795M   115M uwait   7 691:07  15.58% node
   831 myusername    9  20    0   628M 30076K uwait   7 6:28   0.00% node
77937 myusername    5  20    0   618M 21352K usem    4 0:00   0.00% node
71418 myusername    5  20    0   618M 18000K usem    0 0:00   0.00% node
   622 myusername    1  20    0   261M  3388K kqread  3 41:01   0.00% nginx
   623 myusername    1  20    0   261M  2528K kqread  3 0:04   0.00% nginx
   621 root          1  20    0   261M  2448K pause   0 0:00   0.00% nginx
   604 myusername    1  20    0   235M 12144K kqread  1 1:27   0.00% uwsgi
   602 myusername    1  20    0   232M 11592K kqread  0 1:11   0.00% uwsgi
   600 myusername    1  20    0   231M  8736K kqread  6 0:58   0.00% uwsgi
   598 myusername    1  20    0   230M 13196K kqread  0 0:17   0.00% uwsgi
   608 myusername    1  20    0   227M 11204K kqread  7 0:46   0.00% uwsgi
   606 myusername    1  20    0   227M 10328K kqread  1 0:59   0.00% uwsgi
   610 myusername    1  20    0   227M 11656K kqread  0 1:09   0.00% uwsgi
   603 myusername    1  20    0   215M 21048K kqread  4 4:35   0.00% uwsgi
   599 myusername    1  20    0   215M 19756K kqread  5 0:52   0.00% uwsgi
   605 myusername    1  20    0   215M 19496K kqread  4 4:01   0.00% uwsgi
   597 myusername    1  20    0   215M 19284K kqread  0 3:21   0.00% uwsgi
   609 myusername    1  20    0   215M 19304K kqread  1 3:10   0.00% uwsgi
   601 myusername    1  20    0   215M 17208K kqread  2 4:47   0.00% uwsgi
   607 myusername    1  20    0   214M 17912K kqread  5 1:44   0.00% uwsgi
   595 myusername    1  20    0   213M 12224K kqread  4 0:01   0.00% uwsgi
   596 myusername    1  20    0   211M  4112K kqread  6 0:00   0.00% uwsgi
   532 myusername    1  20    0   100M  4036K kqread  0 0:51   0.00% uwsgi
   538 myusername    1  20    0   100M  3556K kqread  1 0:51   0.00% uwsgi
92090 myusername    1  20    0 86480K  5576K select  2 0:00   0.00% sshd
84665 myusername    1  20    0 86480K  5460K select  4 0:00   0.00% sshd
84249 myusername    1  20    0 86480K  5456K select  1 0:00   0.00% sshd
72867 myusername    1  20    0 86480K  5348K select  2 0:00   0.00% sshd
75956 myusername    1  20    0 86480K  5328K select  7 0:00   0.00% sshd
92075 root          1  21    0 86480K  5220K select  7 0:00   0.00% sshd
84653 root          1  21    0 86480K  5132K select  7 0:00   0.00% sshd
84175 root          1  20    0 86480K  5124K select  7 0:00   0.00% sshd
72863 root          1  20    0 86480K  4980K select  4 0:00   0.00% sshd
75950 root          1  20    0 86480K  4952K select  5 0:00   0.00% sshd
   653 root          1  20    0 61212K  1756K select  7 0:03   0.00% sshd
92133 myusername    1  20    0 47720K  2100K wait    4 0:00   0.00% su
84828 myusername    1  20    0 47720K  2068K wait    4 0:00   0.00% su
84275 myusername    1  20    0 47720K  2068K wait    3 0:00   0.00% su
83806 myusername    1  20    0 47720K  2052K wait    0 0:00   0.00% su
72875 myusername    1  20    0 47720K  1968K wait    2 0:00   0.00% su
83852 root          1  20    0 47708K  2032K wait    2 0:00   0.00% su
84923 root          1  20    0 47708K  2032K wait    7 0:00   0.00% su
  6080 myusername    1  20    0 46496K 10540K select  7 11:47   0.00% tmux
75866 pgsql         1  20    0 37304K  4964K select  1 1:56   0.00% postgres
   360 unbound       1  20    0 33016K  1652K select  6 0:00   0.00% unbound
68658 myusername    1  20    0 28408K  2300K ttyin   0 0:00   0.00% psql
   656 root          1  20    0 24112K  2104K select  2 0:13   0.00%
sendmail
   659 smmsp         1  20    0 24112K  1932K pause   1 0:00   0.00%
sendmail
92160 root          1  20    0 23572K  3560K ttyin   2 0:00   0.00% csh
84847 root          1  20    0 23572K  3540K pause   4 0:00   0.00% csh
83809 root          1  20    0 23572K  3516K pause   7 0:00   0.00% csh
84294 root          1  20    0 23572K  3424K pause   6 0:00   0.00% csh
72876 root          1  43    0 23572K  3316K ttyin   0 0:00   0.00% csh
  7276 root          1  20    0 21920K  2264K CPU4    4 0:00   0.00% top
83853 pgsql         1  47    0 17068K  2404K ttyin   6 0:00   0.00% sh
84924 pgsql         1  20    0 17068K  2384K wait    5 0:00   0.00% sh
   580 _ntp          1  20  -20 16740K  1056K select  2 0:00   0.00% ntpd
   579 root          1  20  -20 16732K  1036K select  6 0:00   0.00% ntpd
   582 _ntp          1  52    0 16732K   904K select  4 0:00   0.00% ntpd
   663 root          1  20    0 16596K  1064K nanslp  5 0:06   0.00% cron
92095 myusername    1  20    0 15668K  2940K wait    7 0:00   0.00% bash
84255 myusername    1  20    0 15668K  2932K wait    6 0:00   0.00% bash
84675 myusername    1  20    0 15668K  2932K wait    3 0:00   0.00% bash
75957 myusername    1  20    0 15668K  2820K wait    6 0:00   0.00% bash
72869 myusername    1  20    0 15668K  2772K wait    6 0:00   0.00% bash
68644 myusername    1  20    0 15668K  1620K wait    2 0:00   0.00% bash
  7109 myusername    1  20    0 15668K  1000K wait    3 0:00   0.00% bash
  7317 myusername    1  31    0 15668K   956K ttyin   2 0:00   0.00% bash
  6120 myusername    1  20    0 15668K   868K wait    4 0:00   0.00% bash
32681 myusername    1  20    0 15668K   780K ttyin   2 0:00   0.00% bash
84934 pgsql         1  52    0 14716K  2556K nanslp  3 0:02   0.00% cmdwatch
   405 root          1  20    0 14504K   984K select  5 68:40   0.00%
syslogd
   712 root          1  52    0 14492K   808K ttyin   1 0:00   0.00% getty
   711 root          1  52    0 14492K   808K ttyin   5 0:00   0.00% getty
   716 root          1  52    0 14492K   808K ttyin   2 0:00   0.00% getty
   710 root          1  52    0 14492K   808K ttyin   7 0:00   0.00% getty
   714 root          1  52    0 14492K   808K ttyin   5 0:00   0.00% getty
   713 root          1  52    0 14492K   808K ttyin   0 0:00   0.00% getty
   715 root          1  52    0 14492K   808K ttyin   3 0:00   0.00% getty
   709 root          1  52    0 14492K   808K ttyin   2 0:00   0.00% getty
   316 root          1  20    0 13164K   508K select  4 0:00   0.00% devd
  7277 root          1  20    0 12372K  1760K piperd  1 0:00   0.00% sed
     1 root          1  20    0  9472K   116K wait    4 0:00   0.00% init
    12 root         18 -84    -     0K   288K WAIT    0 91:43   0.00% intr
     0 root         12  -8    0     0K   192K -       0 131:24   0.00%
kernel
    15 root         12 -68    -     0K   192K -       7 1:16   0.00% usb
    13 root          3  -8    -     0K    48K -       1 64:25   0.00% geom
     2 root          3 -16    -     0K    48K -       0 49:12   0.00% cam
     9 root          2  20    -     0K    32K sdflus  7 1:43   0.00%
bufdaemon
     6 root          1 -16    -     0K    16K psleep  1 149:47   0.00%
pagedaemon
     5 root          1  -8    -     0K    16K m:w1    5 45:03   0.00%
g_mirror gm0
    14 root          1 -16    -     0K    16K -       3 31:12   0.00%
rand_harvestq
    17 root          1  16    -     0K    16K syncer  5 10:25   0.00% syncer
    16 root          1 -16    -     0K    16K vlruwt  5 0:03   0.00% vnlru
     4 root          1 -16    -     0K    16K idle    7 0:00   0.00%
enc_daemon0
     8 root          1 155 ki31     0K    16K pgzero  7 0:00   0.00%
pagezero
     3 root          1 -16    -     0K    16K waitin  7 0:00   0.00%
sctp_iterator
     7 root          1 -16    -     0K    16K psleep  2 0:00   0.00%
vmdaemon
    10 root          1 -16    -     0K    16K audit_  0 0:00   0.00% audit

================================================================================================================================================================

#!/usr/bin/env bash

while [ 1 ]; do
   date +%Y.%m.%d.%H.%M.%S
   echo "SELECT pid,state,now()-xact_start AS time FROM pg_stat_activity
WHERE state <> 'idle' AND pg_backend_pid()<>pid ORDER BY pid" | psql
postgres
   sleep 1
done

2015.12.13.19.54.34
   pid  | state  |      time
-------+--------+-----------------
  76179 | active | 00:00:00.001182
(1 row)

2015.12.13.19.54.35
  pid | state | time
-----+-------+------
(0 rows)

2015.12.13.19.54.36
   pid  | state  |       time
-------+--------+------------------
  73479 | active | 00:00:00.115812
  75868 | active | -00:00:00.000506
(2 rows)

2015.12.13.19.54.37
  pid | state | time
-----+-------+------
(0 rows)

2015.12.13.19.54.38
   pid  | state  |      time
-------+--------+-----------------
  74206 | active | 00:00:00.750855
(1 row)

2015.12.13.19.54.39
   pid  | state  |      time
-------+--------+-----------------
  77941 | active | 00:00:00.003457
  79569 | active | 00:00:00.061027
(2 rows)

2015.12.13.19.54.40
   pid  | state  |     time
-------+--------+---------------
  74207 | active | 00:00:00.2614
(1 row)

================================================================================================================================================================



pgsql-general by date:

Previous
From: Tom Lane
Date:
Subject: Re: Memory Leak executing small queries without closing the connection - FreeBSD
Next
From: Bill Moran
Date:
Subject: Re: Memory Leak executing small queries without closing the connection - FreeBSD