Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

I observe the following behavior that I cannot explain: the amount of free physical memory reported by a server increases, while the 'Res' memory reported by the most memory-hungry processes (web server processes) is almost flat.

What I mainly want to understand is: how is is possible for the physical memory use to increase while the resident memory reported by the processes is constant. What could be happening inside these processes to cause that observable behavior, especially without producing much load?

In other words: what can happen inside a process such that 'memory' that was first reported as 'resident', but didn't actually occupy any physical memory changes in such a way that it is still reported as 'resident', but now also actually occupies physical memory?

Example: I have a virtual server with 2GB of memory. Yesterday at 12:00, around 800MB (40%) was in use, as reported by top/free[1]. Most is used by a few processes, which together reported around 1.2GB of resident memory used[2].

I then started a few tests (performing large amounts of HTTP requests served by these processes), which cranked up the physical memory usage to 1.2GB (60%) and increased the resident memory used by the processes to 3.2GB. After that, I didn't touch the server at all and it's not publicly available: the load was < 0.03 afterwards.

Nevertheless, while the resident memory reported by the processes was flat at 3.2GB, the physical memory usage slowly increased and at some point exceeded 90% (1.8GB), causing flags to be raised. Within these web server processes, nothing was going on at that time (as evidenced by the load) and there aren't any special jobs running.

A graph of the scenario above can be seen here. What the upper graph shows is exactly what top/free reports as the free physical memory. What the lower graphs shows is exactly what top reports in the 'Res' column. Note that the area marked Ruby is the total of 6 processes.

[1] Typically on these servers, all memory is marked as 'Used' and all free memory is used for caches. By all I mean: up to the last byte. All other numbers in top and free are 0.

[2] I understand that the sum of resident memory reported by several processes can exceed the used physical memory, but I don't think I know all of the ways in which this can happen.

share|improve this question
1  
@SamiLaine That is entirely irrelevant to my question. The point of footnote [1] is that all numbers apart from 'Used' and 'Cached' are 0, which is not a regular situation and has to do with the VM-nature of this server. My whole question acknowledges that 'Cached' is equivalent to 'Free for use by other processes'. –  Confusion Dec 5 '13 at 11:35
    
Could you possibly supply top output for before/after your test so we can see the differences? Examples are very useful. –  Nathan C Dec 5 '13 at 12:28
    
Let's see your actual output that you're referring to. –  Michael Hampton Dec 5 '13 at 19:23
    
I added a graph of our NewRelic monitoring during that time. I was closely watching the machine during the day, which I why I have enough data points to know for sure their data exactly matches what top reports. I don't have any captures of top itself and recreating those would be a pain, which I don't think adds much. –  Confusion Dec 5 '13 at 19:46

2 Answers 2

This happens because RSS is not an authoritative value that tells you how much of that memory being used by that program. Its an authoritative value as to how much resident memory is mapped by that program. And there is a difference.

RSS can at best be only used as a hint to how much memory you are utilizing.

The kernel has a lot of tricks up its sleeve to save memory. Processes may share lots of memory, especially processes that fork.

If you have a parent that allocates 100M of memory, then spawns a child both of these processes will share that area of memory, both the parent and the child will claim to have an RSS value of >= 100M, because they both map to the same region of memory. Technically this is correct, the RSS for the parent process is >= 100M as thats how much memory the process has mapped, and the child process also has RSS >= 100M because that process also has that much mapped, just it happens to be that both processes share (mostly) the same mappings.

You can demonstrate this with some simple python.

#!/usr/bin/python
import os,sys,signal

HOG = 'A' * 104857600 ## 100 MB

try:
  for i in range(100):
    pid = os.fork()
    if pid:
      continue
    else:
      break
  signal.pause()
except KeyboardInterrupt:
   sys.exit(0)

This program creates a 100M area of memory, and fills it with 'A's. It then spawns 100 children (101 total processes) then waits for a ctrl-c.

This is the scenario before.

$ top -bn1 -u matthew
top - 21:03:04 up 11 min,  1 user,  load average: 0.04, 0.08, 0.09
Tasks: 212 total,   1 running, 211 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.7 us,  0.3 sy,  0.0 ni, 98.7 id,  0.2 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:  16124248 total,  1513728 used, 14610520 free,    78268 buffers
KiB Swap:  8069116 total,        0 used,  8069116 free,   578148 cached

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 1837 matthew   20   0  767916   5072   3400 S   0.0  0.0   0:00.06 gnome-keyr+
 1880 matthew   20   0   13920    608    468 S   0.0  0.0   0:00.00 dbus-launch
 1949 matthew   20   0  307180   2804   2312 S   0.0  0.0   0:00.01 gvfsd
 2051 matthew   20   0  337684   2908   2436 S   0.0  0.0   0:00.00 at-spi-bus+
 2059 matthew   20   0  127260   2920   2360 S   0.0  0.0   0:00.05 at-spi2-re+
 2082 matthew    9 -11  486316   7044   4376 S   0.0  0.0   0:00.09 pulseaudio
 2121 matthew   20   0  317660   2952   2324 S   0.0  0.0   0:00.00 gvfs-gphot+
 2132 matthew   20   0 1440732 105732  30156 S   0.0  0.7   0:09.64 gnome-shell
 2145 matthew   20   0  513076   3996   3064 S   0.0  0.0   0:00.00 gsd-printer
 2160 matthew   20   0  313300   3488   2940 S   0.0  0.0   0:00.00 ibus-dconf
 2172 matthew   20   0  775428  14000  10348 S   0.0  0.1   0:00.05 gnome-shel+
 2182 matthew   20   0  319120   7120   5444 S   0.0  0.0   0:00.07 mission-co+
 2196 matthew   20   0  232848   2708   2164 S   0.0  0.0   0:00.00 gvfsd-meta+
 2206 matthew   20   0  408000  11828   8084 S   0.0  0.1   0:00.06 abrt-applet
 2209 matthew   20   0  761072  15120  10680 S   0.0  0.1   0:00.13 nm-applet
 2216 matthew   20   0  873088  14956  10600 S   0.0  0.1   0:00.09 evolution-+
 2224 matthew   20   0 1357640  29248  14052 S   0.0  0.2   0:00.26 evolution-+
 2403 matthew   20   0  295036   6680   3876 S   0.0  0.0   0:00.01 telepathy-+
 2475 matthew   20   0  380916   2756   2264 S   0.0  0.0   0:00.00 gvfsd-burn
 2486 matthew   20   0    8460    736    608 S   0.0  0.0   0:00.00 gnome-pty-+
 2617 matthew   20   0  116412   3068   1596 S   0.0  0.0   0:00.04 bash
 2888 matthew   20   0  457196   9868   5164 S   0.0  0.1   0:00.05 telepathy-+
 3347 matthew   20   0  123648   1400   1020 R   0.0  0.0   0:00.00 top

Top shows 14610520 KB free memory.

Lets run our program:

$ python trick_rss.py & top -bn1 -u matthew
[2] 3465
top - 21:04:54 up 13 min,  1 user,  load average: 0.05, 0.07, 0.08
Tasks: 415 total,   1 running, 414 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.7 us,  0.3 sy,  0.0 ni, 98.8 id,  0.2 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:  16124248 total,  1832040 used, 14292208 free,    78320 buffers
KiB Swap:  8069116 total,        0 used,  8069116 free,   578144 cached

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 3465 matthew   20   0  227652 106676   1792 S  31.7  0.7   0:00.05 python
 2483 matthew   20   0  641568  18736  11656 S   6.3  0.1   0:01.26 gnome-term+
 1837 matthew   20   0  767916   5072   3400 S   0.0  0.0   0:00.06 gnome-keyr+
 1880 matthew   20   0   13920    608    468 S   0.0  0.0   0:00.00 dbus-launch
 1949 matthew   20   0  307180   2804   2312 S   0.0  0.0   0:00.01 gvfsd
 2051 matthew   20   0  337684   2908   2436 S   0.0  0.0   0:00.00 at-spi-bus+
 2059 matthew   20   0  127260   2920   2360 S   0.0  0.0   0:00.05 at-spi2-re+
 2082 matthew    9 -11  486316   7044   4376 S   0.0  0.0   0:00.09 pulseaudio
 2121 matthew   20   0  317660   2952   2324 S   0.0  0.0   0:00.00 gvfs-gphot+
 2136 matthew   20   0  178692   2588   1788 S   0.0  0.0   0:00.00 dconf-serv+
 2145 matthew   20   0  513076   3996   3064 S   0.0  0.0   0:00.00 gsd-printer
 2160 matthew   20   0  313300   3488   2940 S   0.0  0.0   0:00.00 ibus-dconf
 2172 matthew   20   0  775428  14000  10348 S   0.0  0.1   0:00.05 gnome-shel+
 2182 matthew   20   0  319120   7120   5444 S   0.0  0.0   0:00.07 mission-co+
 2196 matthew   20   0  232848   2708   2164 S   0.0  0.0   0:00.00 gvfsd-meta+
 2206 matthew   20   0  408000  11828   8084 S   0.0  0.1   0:00.06 abrt-applet
 2209 matthew   20   0  761072  15120  10680 S   0.0  0.1   0:00.14 nm-applet
 2216 matthew   20   0  873088  14956  10600 S   0.0  0.1   0:00.10 evolution-+
 2224 matthew   20   0 1357640  29248  14052 S   0.0  0.2   0:00.26 evolution-+
 2403 matthew   20   0  295036   6680   3876 S   0.0  0.0   0:00.01 telepathy-+
 2475 matthew   20   0  380916   2756   2264 S   0.0  0.0   0:00.00 gvfsd-burn
 2487 matthew   20   0  116544   3316   1716 S   0.0  0.0   0:00.09 bash
 2804 matthew   20   0 1239196 275576  41432 S   0.0  1.7   0:25.54 firefox
 2890 matthew   20   0  436688  15932   7288 S   0.0  0.1   0:00.05 telepathy-+
 3360 matthew   20   0  227652 106680   1792 S   0.0  0.7   0:00.05 python
 3366 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3368 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3370 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3372 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3374 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3376 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3378 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3380 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3382 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3384 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3386 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3388 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3390 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3392 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3394 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3396 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3398 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3400 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3402 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3404 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3406 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3408 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3410 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3412 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3414 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3416 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3418 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3420 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3422 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3424 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3426 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3428 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3430 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3432 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3434 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3436 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3438 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3440 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3442 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3444 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3446 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3448 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3450 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3452 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3454 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3456 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3458 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3460 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3462 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3464 matthew   20   0  227652 105096    208 S   0.0  0.7   0:00.00 python
 3467 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3469 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3471 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3473 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3475 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3477 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3479 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3481 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3483 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3485 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3487 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3489 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3491 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3493 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3495 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3497 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3499 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3501 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3503 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3505 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3507 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3509 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3511 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3513 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3515 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3517 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3519 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3521 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3523 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3525 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3527 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3529 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3531 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3533 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3535 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3537 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3539 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3541 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3543 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3545 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3547 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3549 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3551 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3553 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3555 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3557 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3559 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3561 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3563 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python
 3565 matthew   20   0  227652 105092    208 S   0.0  0.7   0:00.00 python

I have 14292208 Kb free. About 300M of memory has been used up. But, if I go by what RSS is telling me I've actually used 10GB of memory!

Finally, if you take a look at the process mappings, you can see that the virtual memory addresses are the same as one another.

$ pmap -x 3561
...
00007f05da5e8000  102404  102404  102404 rw---   [ anon ]
...

$ pmap -x 3565
...
00007f05da5e8000  102404  102404  102404 rw---   [ anon ]
...

Lazy Copying

This C program demonstrates lazy copying occurring, in this scenario, all processes map to the same region of memory, but the children have overwritten the contents. In the background the kernel has remapped these pages to different locations in real memory, but show the same virtual address space.

Now, each instance actually does take up memory but the RSS value remains constant.

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <signal.h>
#include <string.h>

int main() {
  int i;
  char c=65;
  pid_t pid;
  signal(SIGCHLD, SIG_IGN);

  /* Allocate some memory */
  char *hog = malloc(104857600);
  memset(hog, c, 104857600);

  for (i=1; i < 4; i++) {
    if (fork())
      continue;
    memset(hog, c+i, 104857600);
    break;
  }
  sleep(3);
  printf("Pid %d shows HOG[1048576] saying %c\n", getpid(), hog[1048576]);
  pause();
}

Compile with gcc -o trick_rss trick_rss.c. And run with free -m; ./trick_rss & sleep 5; free -m.

You get the following result;

$ free -m; ./trick_rss & sleep 5; free -m
             total       used       free     shared    buffers     cached
Mem:         15746       2477      13268          0         79        589
-/+ buffers/cache:       1808      13938
Swap:         7879          0       7879
[3] 4422
Pid 4422 shows HOG[1048576] saying A
Pid 4424 shows HOG[1048576] saying B
Pid 4425 shows HOG[1048576] saying C
Pid 4426 shows HOG[1048576] saying D
             total       used       free     shared    buffers     cached
Mem:         15746       2878      12867          0         79        589
-/+ buffers/cache:       2209      13536
Swap:         7879          0       7879
share|improve this answer
    
That explains why the sum of 'RES' can be much larger than the amount of physically available memory, which I already acknowledge in my second footnote. It doesn't answer the question I am asking: how can RES stay the same, while actually used physical memory increases, even though not much is happening on the machine (as evidenced by the load)? –  Confusion Dec 5 '13 at 21:15
    
Because pages can be copied lazily. I can demonstrate that too, but that requires me to use C to show you. –  Matthew Ife Dec 5 '13 at 21:17
    
Let's assume the observations are explained by 'pages being copied lazily'. Then my followup question is: exactly what Linux or Ruby operation can cause hundreds of MB's of pages to be copied lazily over a period of several hours, while these processes aren't using any CPU and are not processing any input or performing any cron-like jobs? My goal is to understand what is happening to such an extent that I can intervene and prevent this from happening. –  Confusion Dec 5 '13 at 21:25
    
Updated my answer, I have no idea on the way ruby manages its memory to explain why you see this; although I can demonstrate how its possible that this can happen. –  Matthew Ife Dec 5 '13 at 21:36

The amount of physical memory used could grow as the amount of memory shared among the ruby (or other) processes decreases. In your case, however, the system is idle so you wouldn't expect any changes. Possibly the ruby garbage collector is causing the sharing to decrease as this quote from http://www.rubyenterpriseedition.com/faq.html is saying:

A garbage collection cycle will thus result in all objects being written to (or in operating systems jargon: the memory pages of the objects are made dirty). The OS will copy all that memory, thus negating the effect of copy-on-write.

What does the amount of memory shared look like over this time period?

share|improve this answer
    
The amount of shared memory reported by top as SHR is always quite low, ~4000 (kB) and doesn't change significantly. –  Confusion Dec 5 '13 at 21:11
    
Can GC cycles explain hundreds of MB's of pages slowly being written to over a period of several hours? As far as I understand GC, the effect would happen pretty quickly after operations were suspended? Can it also explain the sudden increase in the rate of increase and the decrease that can be noticed? –  Confusion Dec 5 '13 at 21:29

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.