4

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.

Improve this question
4
  • 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'. Commented Dec 5, 2013 at 11:35
  • Could you possibly supply top output for before/after your test so we can see the differences? Examples are very useful. Commented Dec 5, 2013 at 12:28
  • Let's see your actual output that you're referring to. Commented Dec 5, 2013 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. Commented Dec 5, 2013 at 19:46

2 Answers 2

Reset to default
4

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
Improve this answer
4
  • 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)? Commented Dec 5, 2013 at 21:15
  • Because pages can be copied lazily. I can demonstrate that too, but that requires me to use C to show you. Commented Dec 5, 2013 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. Commented Dec 5, 2013 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. Commented Dec 5, 2013 at 21:36
1

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?

Improve this answer
2
  • The amount of shared memory reported by top as SHR is always quite low, ~4000 (kB) and doesn't change significantly. Commented Dec 5, 2013 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? Commented Dec 5, 2013 at 21:29

You must log in to answer this question.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.