Re: Debugging shared memory issues on CentOS

On Tue, Dec 10, 2013 at 8:54 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Mack Talcott <mack.talcott@gmail.com> writes:
>> I am trying to debug some shared memory issues with Postgres 9.3.1 and
>> CentOS release 6.3 (Final).  I have a database machine that probably has
>> some misconfigured shared memory settings.  It's getting into 2+ GB of
>> swap.  Restarting postgres frees all of the memory, but after a few hours
>> of normal usage it will go back into swap.
>
> Are you sure the kernel isn't just swapping out some idle processes
> because it feels like it?  These numbers don't exactly look like a
> machine under stress:
>
>> top - 09:38:16 up 1 day, 21:21,  3 users,  load average: 0.40, 0.54, 0.45
>> Tasks: 253 total,   2 running, 251 sleeping,   0 stopped,   0 zombie
>> Cpu(s):  0.7%us,  0.2%sy,  0.0%ni, 97.8%id,  1.2%wa,  0.0%hi,  0.0%si,
>>  0.0%st
>> Mem:   6998260k total,  6849048k used,   149212k free,      248k buffers
>> Swap: 440478516k total,  1981912k used, 438496604k free,  1541356k cached
>
> In particular, you've got 1.5 gig of filesystem cache, so you're hardly
> out of memory.  I don't know where the other 5.5 gig of RAM went, but
> it doesn't look like postgres is eating it; what else is running on
> this box?
>
> These lines look absolutely normal, assuming that you've configured
> shared_buffers somewhere in the neighborhood of 1GB:
>
>>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>  3534 postgres  20   0 2330m 1.4g 1.1g S  0.0 20.4   1:06.99 postgres:
>> deploy mtalcott 10.222.154.172(53495) idle
>>  9143 postgres  20   0 2221m 1.1g 983m S  0.0 16.9   0:14.75 postgres:
>> deploy mtalcott 10.222.154.167(35811) idle
>>  6026 postgres  20   0 2341m 1.1g 864m S  0.0 16.4   0:46.56 postgres:
>> deploy mtalcott 10.222.154.167(37110) idle
>> 18538 postgres  20   0 2327m 1.1g 865m S  0.0 16.1   2:06.59 postgres:
>> deploy mtalcott 10.222.154.172(47796) idle
>>  1575 postgres  20   0 2358m 1.1g 858m S  0.0 15.9   1:41.76 postgres:
>> deploy mtalcott 10.222.154.172(52560) idle
>
> The key thing to realize about that is that the SHR column is *shared*
> memory, ie all these processes are referencing the same chunk of about 1GB
> worth of memory.  The process-specific memory is RES minus SHR, and none
> of those processes seem tremendously out of line on that measure.  (Note:
> the fact that the SHR values aren't all exactly the same is because top
> doesn't count a shared page until the process has physically touched that
> page.  Even the guy with 1.1g of SHR might not have touched all of the
> shared storage yet.)
>
> I'm not sure you have a problem here.  If you do, these figures aren't
> showing it.  Having some stuff shoved out to swap is not a problem unless
> you have a problem with the swap I/O rate.  You might try watching "vmstat
> 1" for awhile to see if the si/so columns show significant activity.
>
>                         regards, tom lane

Thanks for your reply.  I've included the rest of the top output
below.  This is a dedicated postgres box, so nothing else is running.

shared_buffers is set to 1.8g, to accommodate some of our larger
operations.  It looks like this could be lowered a bit, since the max
shared usage is only 1.1g.

The pattern I am seeing is that postgres processes keep growing in
shared (this makes sense as they access more of the shared memory, as
you've pointed out) but also process-specific memory as they run more
queries.  The largest ones are using around 300mb of process-specific
memory, even when they're idle and outside of any transactions.

As for CentOS using 1.5g for disk caching, I'm at a loss.  I have
played with the 'swappiness', setting it down to 10 from the default
of 60 with sysctl.  It didn't have any effect.

Once 70-80% of memory is reached, the machine starts using swap, and
it keeps growing.  At first, queries become slightly slower.  Then
some larger selects start taking 10, then 20, then 30 seconds.  During
this, vmstat shows 5-20 procs waiting on both CPU and I/O.  All of a
sudden, generally after some large transaction, about 1g of swap is
released and the number of blocked procs jumps to 50-80.  Everything
grinds to a halt for a few minutes.  Sometimes my app can recover, and
sometimes it needs a little kick.

As expected, resetting the connection clears the process-specific
memory.  The same number of connections on the same machine only use
20% of memory (with 0 swap) when I periodically reconnect.  What kind
of information are these processes holding on to?  I would expect
long-running, idle postgres processes to have similar memory usage to
brand new, idle ones.

One thing worth mentioning is that I am heavily using schemas.  On
every request, I am setting and resetting search_path.

This top was captured just before swap was released
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 3534 postgres  20   0 2330m 1.4g 1.1g S  0.0 20.4   1:06.99 postgres:
deploy mtalcott 10.222.155.179(53495) idle
 9143 postgres  20   0 2221m 1.1g 983m S  0.0 16.9   0:14.75 postgres:
deploy mtalcott 10.222.155.164(35811) idle
 6026 postgres  20   0 2341m 1.1g 864m S  0.0 16.4   0:46.56 postgres:
deploy mtalcott 10.222.155.164(37110) idle
18538 postgres  20   0 2327m 1.1g 865m S  0.0 16.1   2:06.59 postgres:
deploy mtalcott 10.222.155.179(47796) idle
 1575 postgres  20   0 2358m 1.1g 858m S  0.0 15.9   1:41.76 postgres:
deploy mtalcott 10.222.155.179(52560) idle
17931 postgres  20   0 2343m 1.1g 834m S  0.0 15.8   2:04.61 postgres:
deploy mtalcott 10.222.155.164(54439) idle
18286 postgres  20   0 2363m 1.0g 797m S  1.3 15.6   1:54.97 postgres:
deploy mtalcott 10.222.155.179(47588) idle
 4541 postgres  20   0 2343m 1.0g 783m S  0.0 15.2   1:20.75 postgres:
deploy mtalcott 10.222.155.179(53938) idle
18763 postgres  20   0 2347m 1.0g 772m S  0.0 14.9   1:49.83 postgres:
deploy mtalcott 10.222.155.164(32853) idle
 1088 postgres  20   0 2336m 1.0g 778m S  0.3 14.9   1:35.40 postgres:
deploy mtalcott 10.222.155.179(52312) idle
17933 postgres  20   0 2343m 996m 800m S  0.0 14.6   2:11.68 postgres:
deploy mtalcott 10.222.155.164(54443) idle
 1089 postgres  20   0 2310m 970m 776m S  1.7 14.2   1:18.34 postgres:
deploy mtalcott 10.222.155.164(46130) idle
 3535 postgres  20   0 2354m 950m 779m S  0.0 13.9   1:18.44 postgres:
deploy mtalcott 10.222.155.164(33599) idle
 1708 postgres  20   0 2308m 940m 760m S  0.0 13.8   1:08.72 postgres:
deploy mtalcott 10.222.155.164(49552) idle
18540 postgres  20   0 2337m 932m 784m S  0.7 13.6   1:50.66 postgres:
deploy mtalcott 10.222.155.164(59856) idle
 8471 postgres  20   0 2312m 683m 429m S  0.0 10.0   0:54.35 postgres:
deploy mtalcott 10.222.155.179(57867) idle
 5931 postgres  20   0 2327m 589m 340m S  0.0  8.6   0:40.07 postgres:
deploy mtalcott 10.222.155.179(55092) idle
 6070 postgres  20   0 2306m 568m 358m S  0.0  8.3   0:42.56 postgres:
deploy mtalcott 10.222.155.179(55307) idle
 9135 postgres  20   0 2235m 523m 341m S  0.0  7.7   0:19.65 postgres:
deploy mtalcott 10.222.155.164(35140) idle
10996 postgres  20   0 2103m 229m 169m S  0.0  3.4   0:01.65 postgres:
deploy mtalcott 10.222.155.179(60798) idle
11001 postgres  20   0 2062m 163m 144m S  0.7  2.4   0:01.90 postgres:
deploy mtalcott 10.222.155.164(44039) idle
17697 postgres  20   0 2038m 151m 150m S  0.0  2.2   0:09.82 postgres:
checkpointer process
10869 postgres  20   0 2045m  82m  76m S  3.3  1.2   0:12.19 postgres:
deploy mtalcott 10.197.52.158(43556) idle in transaction
10994 postgres  20   0 2052m  61m  50m S  0.0  0.9   0:00.77 postgres:
deploy mtalcott 10.222.155.179(60757) idle
17680 postgres  20   0 2037m  37m  37m S  0.0  0.6   0:03.34
/usr/local/pgsql9.3/bin/postgres -D /db/pgsql/9.3/data
17698 postgres  20   0 2038m  36m  35m S  0.0  0.5   0:02.85 postgres:
writer process
10993 postgres  20   0 2045m  29m  22m S  0.0  0.4   0:00.26 postgres:
deploy mtalcott 10.222.155.164(42908) idle
17701 postgres  20   0  134m  21m  272 S  0.0  0.3   1:21.61 postgres:
stats collector process
 4905 postgres  20   0 2045m  13m 8408 S  0.0  0.2   0:00.44 postgres:
deploy mtalcott 10.222.155.164(47193) idle
 5041 postgres  20   0 2044m  13m 8124 S  0.0  0.2   0:00.54 postgres:
deploy mtalcott 10.222.155.164(49813) idle
 5036 postgres  20   0 2044m  12m 7808 S  0.0  0.2   0:00.50 postgres:
deploy mtalcott 10.222.155.164(49380) idle
 6452 postgres  20   0 2044m  10m 6112 S  0.0  0.2   0:00.26 postgres:
deploy mtalcott 10.222.155.164(44313) idle
 5023 postgres  20   0 2044m  10m 5868 S  0.0  0.2   0:00.50 postgres:
deploy mtalcott 10.222.155.164(47882) idle
 5029 postgres  20   0 2045m  10m 6732 S  0.0  0.1   0:00.81 postgres:
deploy mtalcott 10.222.155.164(48498) idle
 5808 postgres  20   0 2044m 9408 7040 S  0.0  0.1   0:00.30 postgres:
deploy mtalcott 10.222.155.164(33987) idle
17700 postgres  20   0 2039m 4728 4432 S  0.0  0.1   0:00.71 postgres:
autovacuum launcher process
10567 deploy    20   0 97820 1372  432 S  0.0  0.0   0:00.02 sshd: deploy@pts/2
10564 root      20   0 97820 1192  284 S  0.0  0.0   0:00.04 sshd: deploy [priv]
10998 deploy    20   0 15168 1044  604 R  0.7  0.0   0:00.59 top -c