10 Analysis How Should We Step by Step Find the Root Cause of Memory Leaks #
Hello, I am Shao Yafang.
Based on our previous introduction and case studies, you should have gained some understanding of memory leaks. In this chapter, I will discuss a systematic approach to analyze memory leak issues. In other words, when faced with a memory leak, we will explore step by step how to identify the root cause.
However, I will not delve into the specific implementation details of programming languages or specific business code logic. Instead, I will start with some general analysis methods applicable to Linux systems. This way, regardless of the programming language you use or the project you are working on, these methods will provide you with some assistance.
How to identify who is consuming memory? #
The external manifestation of memory leaks is usually insufficient system memory, which can lead to OOM (Out of Memory) and even system crashes. So, what is the usual approach to analyze these phenomena?
First, we need to find out who is consuming the memory, and /proc/meminfo can help us quickly locate the problem.
There are many items in /proc/meminfo, and we don’t need to memorize them all. However, some items are relatively easy to cause problems and need to be investigated when encountering memory-related issues. I have listed these items in a table, along with troubleshooting suggestions for each item.
In summary, if there is a problem with a process’s memory, it can be observed using top. If there is no issue with the process’s memory, you can start analyzing it step by step using /proc/meminfo.
Next, let’s analyze an actual case to see what causes the memory leak in a process.
How to analyze the cause of a memory leak in a process? #
This is a memory leak problem that I helped a friend analyze many years ago. This friend had already used top to identify abnormal memory usage in the business process, but was unsure how to further analyze the issue.
The anomaly he encountered was that the virtual address space (VIRT) of the business process was consuming a large amount of memory, but the physical memory (RES) usage was very low. Therefore, he suspected that there was a memory leak in the virtual address space of the process.
In our “Lesson 06” we also discussed that in such cases, we can use the top command to observe (the following is a production environment information saved at that time, with some sensitive information redacted):
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
31108 app 20 0 285g 4.0g 19m S 60.6 12.7 10986:15 app_server
You can see that the program app_server has a large virtual address space (VIRT), with 285GB.
How can we trace where exactly the issue is with app_server?
We can use the pidstat command (you can refer to man pidstat) to trace the memory behavior of the process and see if we can discover any patterns:
$ pidstat -r -p 31108 1
04:47:00 PM 31108 353.00 0.00 299029776 4182152 12.73 app_server
...
04:47:59 PM 31108 149.00 0.00 299029776 4181052 12.73 app_server
04:48:00 PM 31108 191.00 0.00 299040020 4181188 12.73 app_server
...
04:48:59 PM 31108 179.00 0.00 299040020 4181400 12.73 app_server
04:49:00 PM 31108 183.00 0.00 299050264 4181524 12.73 app_server
...
04:49:59 PM 31108 157.00 0.00 299050264 4181456 12.73 app_server
04:50:00 PM 31108 207.00 0.00 299060508 4181560 12.73 app_server
...
04:50:59 PM 31108 127.00 0.00 299060508 4180816 12.73 app_server
04:51:00 PM 31108 172.00 0.00 299070752 4180956 12.73 app_server
As shown above, the VSZ increases by 10244KB at every whole minute, which seems to be a regular pattern. Next, let’s see what this increased memory region actually is by checking /proc/PID/smaps (you can refer back to our lesson “Lesson 05” for information about /proc):
The increased memory region is as follows:
$ cat /proc/31108/smaps
...
7faae0e49000-7faae1849000 rw-p 00000000 00:00 0
Size: 10240 kB
Rss: 80 kB
Pss: 80 kB
Shared_Clean: 0 kB
```
Shared_Dirty: 0 kB
Private_Clean: 0 kB
Private_Dirty: 80 kB
Referenced: 60 kB
Anonymous: 80 kB
AnonHugePages: 0 kB
Swap: 0 kB
KernelPageSize: 4 kB
MMUPageSize: 4 kB
7faae1849000-7faae184a000 ---p 00000000 00:00 0
Size: 4 kB
Rss: 0 kB
Pss: 0 kB
Shared_Clean: 0 kB
Shared_Dirty: 0 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Referenced: 0 kB
Anonymous: 0 kB
AnonHugePages: 0 kB
Swap: 0 kB
KernelPageSize: 4 kB
MMUPageSize: 4 kB
```
It can be seen that it includes: a private address space, which can be seen from the `rw-p` attribute of `private`; and a guard page, which can be seen from the `-p` attribute, i.e., the process cannot access it. For experienced developers, they can guess that it should be related to thread stacks based on this 4K guard page.
Let's track the purpose of the process requesting this address space by using the `strace` command. Since the increase of VIRT, its system call function is nothing more than `mmap` or `brk`, so we only need to look at `mmap` or `brk` in the result of `strace`.
Track it with `strace` as follows:
```
$ strace -t -f -p 31108 -o 31108.strace
```
There are many threads, and if you use `-f` to track threads, the amount of information to be tracked will also be large. It is dazzling to search each `mmap` or `brk` in the log one by one, so let's `grep` this size (10489856, which is 10244KB) and then filter it:
```
$ cat 31108.strace | grep 10489856
31152 23:00:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31151 23:01:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31157 23:02:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31158 23:03:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31165 23:04:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31163 23:05:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31153 23:06:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31155 23:07:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31149 23:08:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31147 23:09:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31159 23:10:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31157 23:11:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
```
31148 23:12:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31150 23:13:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31173 23:14:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
From this log, we can see that the system call in question is mmap(). Let’s take a look at the purpose of this mmap memory:
31151 23:01:00 mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0 <unfinished ...>
31151 23:01:00 mprotect(0x7fa94bbc0000, 4096, PROT_NONE <unfinished ...> <<< Creating a protected page
31151 23:01:00 clone( <unfinished ...> <<< Creating a thread
31151 23:01:00 <... clone resumed> child_stack=0x7fa94c5afe50, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND
|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID
|CLONE_CHILD_CLEARTID, parent_tidptr=0x7fa94c5c09d0, tls=0x7fa94c5c0700, child_tidptr=0x7fa94c5c09d0) = 20610
It can be seen that this is a thread stack allocated during cloning. You might have a question: since the thread stack consumes so much memory, there should be many of them, right?
However, in reality, there aren’t many app_server threads in the system, so why is that? The answer is actually quite simple: the threads exit shortly after they are created, but the mmap thread stack is not released.
Let’s write a simple program to reproduce this phenomenon. Reproducing the problem is important. If a complex problem can be reproduced with a simple program, it would be the best outcome.
The following is a simple reproduction program: mmap a 40K thread stack, and the thread performs a simple execution and then exits.
#include <stdio.h>
#include <unistd.h>
#include <sys/mman.h>
#include <sys/types.h>
#include <sys/wait.h>
#define _SCHED_H
#define __USE_GNU
#include <bits/sched.h>
#define STACK_SIZE 40960
int func(void *arg)
{
printf("thread enter.\n");
sleep(1);
printf("thread exit.\n");
return 0;
}
int main()
{
int thread_pid;
int status;
int w;
while (1) {
void *addr = mmap(NULL, STACK_SIZE, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0);
if (addr == NULL) {
perror("mmap");
goto error;
}
printf("create new thread...\n");
thread_pid = clone(&func, addr + STACK_SIZE, CLONE_SIGHAND|CLONE_FS|CLONE_VM|CLONE_FILES, NULL);
printf("Done! Thread pid: %d\n", thread_pid);
if (thread_pid != -1) {
do {
w = waitpid(-1, NULL, __WCLONE | __WALL);
if (w == -1) {
perror("waitpid");
goto error;
}
} while (!WIFEXITED(status) && !WIFSIGNALED(status));
}
sleep(10);
}
error:
return 0;
}
Then let’s use pidstat to observe the execution of this process. We can see that its behavior is consistent with the problem in the production environment:
$ pidstat -r -p 535 5
11:56:51 PM UID PID minflt/s majflt/s VSZ RSS %MEM Command
11:56:56 PM 0 535 0.20 0.00 4364 360 0.00 a.out
11:57:01 PM 0 535 0.00 0.00 4364 360 0.00 a.out
11:57:06 PM 0 535 0.20 0.00 4404 360 0.00 a.out
11:57:11 PM 0 535 0.00 0.00 4404 360 0.00 a.out
11:57:16 PM 0 535 0.20 0.00 4444 360 0.00 a.out
11:57:21 PM 0 535 0.00 0.00 4444 360 0.00 a.out
11:57:26 PM 0 535 0.20 0.00 4484 360 0.00 a.out
11:57:31 PM 0 535 0.00 0.00 4484 360 0.00 a.out
11:57:36 PM 0 535 0.20 0.00 4524 360 0.00 a.out
^C
Average: 0 535 0.11 0.00 4435 360 0.00 a.out
As you can see, VSZ increases by 40K every 10 seconds, but the added thread only exists for 1 second before disappearing.
Therefore, we can infer that there is a problem with the app_server code, and our teammate quickly fixed the bug.
Of course, memory leak issues in applications can be diverse, and the analysis methods may vary. We shared this case to demonstrate some general analysis techniques. With these techniques, we can often deal with various situations.
Class Summary #
In this class, we discussed the systematic analysis method for memory leak issues on Linux. The key points are as follows:
- The top tool and /proc/meminfo file are the first steps in analyzing memory leak issues on Linux, and even all memory-related issues. We first identify which process or which item is abnormal, and then analyze it specifically.
- Memory leaks in applications can be diverse, so you need to master some general analysis techniques. Once you have mastered these techniques, you can adapt to various situations. However, mastering these techniques requires a solid foundation of knowledge. You need to be proficient in the basic knowledge taught in this series of courses in order to excel.
Homework #
Please write a program that causes a memory leak, and then observe the changes in /proc/[pid]/maps and smaps (pid refers to the pid of the program causing the memory leak). Feel free to discuss with me in the comments.
Thank you for reading. If you found this lesson helpful, please consider sharing it with your friends. See you in the next lesson.