Skip to contentSkip to conversation

System freezes when RAM is full (64-bit)

DISCUSSION Ivan Danov 3 participants 17 messages Apr 1, 2013 – May 14, 2013 Memory management

lore
Share & tools
lore

Ivan Danov

author
#0 lore raw

The system freezes when RAM gets completely full. By using MATLAB, I can get all 8GB RAM of my laptop full and it immediately freezes, needing restart using the hardware button. Other people have reported the bug at since 2007. It seems that only the 64-bit version is affected and people have reported that enabling DMA in BIOS settings solve the problem. However, my laptop lacks such an option in the BIOS settings, so I am unable to test it. More information about the bug could be found at: https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1162073 and https://bugs.launchpad.net/ubuntu/+source/linux/+bug/159356.

Best Regards,
Ivan

#1 lore raw
Quoted 3 lines · Ivan Danov

The system freezes when RAM gets completely full. By using MATLAB, I can get all 8GB RAM of my laptop full and it immediately freezes, needing restart using the hardware button.

Do you use swap (file/partition)? How big? Could you collect /proc/meminfo and /proc/vmstat (every few seconds)[1]?
What does it mean when you say the system freezes? No new processes can be started or desktop environment doesn't react on your input? Do you see anything in the kernel log? OOM killer e.g.
In case no new processes could be started what does sysrq+m say when the system is frozen?

What is your kernel config?

Quoted 9 lines

Other people have
reported the bug at since 2007. It seems that only the 64-bit version is affected and people have reported that enabling DMA in BIOS settings solve the problem. However, my laptop lacks such an option in the BIOS settings, so I am unable to test it. More information about the bug could be found at:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1162073 and
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/159356.

Quoted 3 lines

Best Regards,
Ivan

---
[1] E.g. by
while true
do
STAMP=date +%s
cat /proc/meminfo > meminfo.$STAMP
cat /proc/vmscan > meminfo.$STAMP
sleep 2s
done

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
#2 lore raw
Quoted 26 lines · Michal Hocko
Quoted 3 lines · Ivan Danov

The system freezes when RAM gets completely full. By using MATLAB, I can get all 8GB RAM of my laptop full and it immediately freezes, needing restart using the hardware button.

Do you use swap (file/partition)? How big? Could you collect /proc/meminfo and /proc/vmstat (every few seconds)[1]?
What does it mean when you say the system freezes? No new processes can be started or desktop environment doesn't react on your input? Do you see anything in the kernel log? OOM killer e.g.
In case no new processes could be started what does sysrq+m say when the system is frozen?

What is your kernel config?

Quoted 9 lines

Other people have
reported the bug at since 2007. It seems that only the 64-bit version is affected and people have reported that enabling DMA in BIOS settings solve the problem. However, my laptop lacks such an option in the BIOS settings, so I am unable to test it. More information about the bug could be found at:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1162073 and
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/159356.

Quoted 3 lines

Best Regards,
Ivan

Quoted 7 lines

---
[1] E.g. by
while true
do
STAMP=date +%s
cat /proc/meminfo > meminfo.$STAMP
cat /proc/vmscan > meminfo.$STAMP

s/vmscan/vmstat

Quoted 2 lines

sleep 2s
done

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

#3 lore raw
Quoted 35 lines · Simon Jeons
Quoted 26 lines · Michal Hocko
Quoted 3 lines · Ivan Danov

The system freezes when RAM gets completely full. By using MATLAB, I can get all 8GB RAM of my laptop full and it immediately freezes, needing restart using the hardware button.

Do you use swap (file/partition)? How big? Could you collect /proc/meminfo and /proc/vmstat (every few seconds)[1]?
What does it mean when you say the system freezes? No new processes can be started or desktop environment doesn't react on your input? Do you see anything in the kernel log? OOM killer e.g.
In case no new processes could be started what does sysrq+m say when the system is frozen?

What is your kernel config?

Quoted 9 lines

Other people have
reported the bug at since 2007. It seems that only the 64-bit version is affected and people have reported that enabling DMA in BIOS settings solve the problem. However, my laptop lacks such an option in the BIOS settings, so I am unable to test it. More information about the bug could be found at:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1162073 and
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/159356.

Quoted 3 lines

Best Regards,
Ivan

Quoted 7 lines

---
[1] E.g. by
while true
do
STAMP=date +%s
cat /proc/meminfo > meminfo.$STAMP
cat /proc/vmscan > meminfo.$STAMP

Quoted 1 line

s/vmscan/vmstat

Right. Sorry about the typo and thanks for pointing out Simon.

Quoted 4 lines
Quoted 3 lines

sleep 2s
done

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
author
#4 lore raw

Hi Michal,

Yes, I use swap partition (2GB), but I have applied some things for keeping the life of the SSD hard drive longer. All the things I have done are under point 3. at http://www.rileybrandt.com/2012/11/18/linux-ultrabook/. By system freezes, I mean that the desktop environment doesn't react on my input. Just sometimes the mouse is reacting very very choppy and slowly, but most of the times it is not reacting at all. In the attached file, I have the output of the script and the content of dmesg for all levels from warn to emerg, as well as my kernel config.

Best,
Ivan
--

Quoted 40 lines · Michal Hocko
Quoted 27 lines · Simon Jeons
Quoted 26 lines · Michal Hocko
Quoted 3 lines · Ivan Danov

The system freezes when RAM gets completely full. By using MATLAB, I can get all 8GB RAM of my laptop full and it immediately freezes, needing restart using the hardware button.

Do you use swap (file/partition)? How big? Could you collect /proc/meminfo and /proc/vmstat (every few seconds)[1]?
What does it mean when you say the system freezes? No new processes can be started or desktop environment doesn't react on your input? Do you see anything in the kernel log? OOM killer e.g.
In case no new processes could be started what does sysrq+m say when the system is frozen?

What is your kernel config?

Quoted 12 lines

Other people have
reported the bug at since 2007. It seems that only the 64-bit version is affected and people have reported that enabling DMA in BIOS settings solve the problem. However, my laptop lacks such an option in the BIOS settings, so I am unable to test it. More information about the bug could be found at:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1162073 and
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/159356.

Best Regards,
Ivan

Quoted 8 lines
Quoted 7 lines

---
[1] E.g. by
while true
do
STAMP=date +%s
cat /proc/meminfo > meminfo.$STAMP
cat /proc/vmscan > meminfo.$STAMP

s/vmscan/vmstat

Right. Sorry about the typo and thanks for pointing out Simon.

Quoted 2 lines
Quoted 2 lines

sleep 2s
done

#5 lore raw
Quoted 6 lines · Ivan Danov

Hi Michal,

Yes, I use swap partition (2GB), but I have applied some things for keeping the life of the SSD hard drive longer. All the things I have done are under point 3. at
http://www.rileybrandt.com/2012/11/18/linux-ultrabook/.

OK, I guess I know what's going on here.
So you did set vm.swappiness=0 which (for some time) means that there is almost no swapping going on (although you have plenty of swap as you are mentioning above).
This shouldn't be a big deal normally but you are also backing your /tmp on tmpfs which is in-memory filesystem. This means that if you are writing to /tmp a lot then this content will fill up your memory which is not swapped out until the memory reclaim is getting into real troubles - most of the page cache is dropped by that time so your system starts trashing.

I would encourage you to set swappiness to a more reasonable value (I would use the default value which is 60). I understand that you are concerned about your SSD lifetime but your user experience sounds like a bigger priority ;)

Quoted 5 lines

By system freezes, I mean that the desktop environment doesn't react on my input. Just sometimes the mouse is reacting very very choppy and slowly, but most of the times it is not reacting at all. In the attached file, I have the output of the script and the content of dmesg for all levels from warn to emerg, as well as my kernel config.

I haven't checked your attached data but you should get an overview from Shmem line from /proc/meminfo which tells you how much shmem/tmpfs memory you are using and grep "^Swap" /proc/meminfo will tell you more about your swap usage.

Quoted 3 lines

Best,
Ivan

HTH

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
author
#6 lore raw

Tried with vm.swappiness=60, but the only improvement is that now the mouse input is less choppy than before, but still the problem remains - the computer is not usable at all, one could not even stop the program, causing the problem.

Best,
Ivan
--

Quoted 28 lines · Michal Hocko
Quoted 6 lines · Ivan Danov

Hi Michal,

Yes, I use swap partition (2GB), but I have applied some things for keeping the life of the SSD hard drive longer. All the things I have done are under point 3. at
http://www.rileybrandt.com/2012/11/18/linux-ultrabook/.

OK, I guess I know what's going on here.
So you did set vm.swappiness=0 which (for some time) means that there is almost no swapping going on (although you have plenty of swap as you are mentioning above).
This shouldn't be a big deal normally but you are also backing your /tmp on tmpfs which is in-memory filesystem. This means that if you are writing to /tmp a lot then this content will fill up your memory which is not swapped out until the memory reclaim is getting into real troubles - most of the page cache is dropped by that time so your system starts trashing.

I would encourage you to set swappiness to a more reasonable value (I would use the default value which is 60). I understand that you are concerned about your SSD lifetime but your user experience sounds like a bigger priority ;)

Quoted 5 lines

By system freezes, I mean that the desktop environment doesn't react on my input. Just sometimes the mouse is reacting very very choppy and slowly, but most of the times it is not reacting at all. In the attached file, I have the output of the script and the content of dmesg for all levels from warn to emerg, as well as my kernel config.

Quoted 8 lines

I haven't checked your attached data but you should get an overview from Shmem line from /proc/meminfo which tells you how much shmem/tmpfs memory you are using and grep "^Swap" /proc/meminfo will tell you more about your swap usage.

Quoted 2 lines

Best,
Ivan

HTH

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

#7 lore raw
Quoted 4 lines · Ivan Danov

Tried with vm.swappiness=60, but the only improvement is that now the mouse input is less choppy than before, but still the problem remains - the computer is not usable at all, one could not even stop the program, causing the problem.

OK, could you collect /proc/vmstat and /proc/meminfo during that load?

Quoted 41 lines

Best,
Ivan
--

Quoted 36 lines · Michal Hocko
Quoted 6 lines · Ivan Danov

Hi Michal,

Yes, I use swap partition (2GB), but I have applied some things for keeping the life of the SSD hard drive longer. All the things I have done are under point 3. at
http://www.rileybrandt.com/2012/11/18/linux-ultrabook/.

OK, I guess I know what's going on here.
So you did set vm.swappiness=0 which (for some time) means that there is almost no swapping going on (although you have plenty of swap as you are mentioning above).
This shouldn't be a big deal normally but you are also backing your /tmp on tmpfs which is in-memory filesystem. This means that if you are writing to /tmp a lot then this content will fill up your memory which is not swapped out until the memory reclaim is getting into real troubles - most of the page cache is dropped by that time so your system starts trashing.

I would encourage you to set swappiness to a more reasonable value (I would use the default value which is 60). I understand that you are concerned about your SSD lifetime but your user experience sounds like a bigger priority ;)

Quoted 5 lines

By system freezes, I mean that the desktop environment doesn't react on my input. Just sometimes the mouse is reacting very very choppy and slowly, but most of the times it is not reacting at all. In the attached file, I have the output of the script and the content of dmesg for all levels from warn to emerg, as well as my kernel config.

I haven't checked your attached data but you should get an overview from Shmem line from /proc/meminfo which tells you how much shmem/tmpfs memory you are using and grep "^Swap" /proc/meminfo will tell you more about your swap usage.

Quoted 2 lines

Best,
Ivan

HTH

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
author
#8 lore raw

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file. --

Quoted 47 lines · Michal Hocko
Quoted 4 lines · Ivan Danov

Tried with vm.swappiness=60, but the only improvement is that now the mouse input is less choppy than before, but still the problem remains - the computer is not usable at all, one could not even stop the program, causing the problem.

OK, could you collect /proc/vmstat and /proc/meminfo during that load?

Quoted 40 lines

Best,
Ivan
--

Quoted 36 lines · Michal Hocko
Quoted 6 lines · Ivan Danov

Hi Michal,

Yes, I use swap partition (2GB), but I have applied some things for keeping the life of the SSD hard drive longer. All the things I have done are under point 3. at
http://www.rileybrandt.com/2012/11/18/linux-ultrabook/.

OK, I guess I know what's going on here.
So you did set vm.swappiness=0 which (for some time) means that there is almost no swapping going on (although you have plenty of swap as you are mentioning above).
This shouldn't be a big deal normally but you are also backing your /tmp on tmpfs which is in-memory filesystem. This means that if you are writing to /tmp a lot then this content will fill up your memory which is not swapped out until the memory reclaim is getting into real troubles - most of the page cache is dropped by that time so your system starts trashing.

I would encourage you to set swappiness to a more reasonable value (I would use the default value which is 60). I understand that you are concerned about your SSD lifetime but your user experience sounds like a bigger priority ;)

Quoted 5 lines

By system freezes, I mean that the desktop environment doesn't react on my input. Just sometimes the mouse is reacting very very choppy and slowly, but most of the times it is not reacting at all. In the attached file, I have the output of the script and the content of dmesg for all levels from warn to emerg, as well as my kernel config.

I haven't checked your attached data but you should get an overview from Shmem line from /proc/meminfo which tells you how much shmem/tmpfs memory you are using and grep "^Swap" /proc/meminfo will tell you more about your swap usage.

Quoted 2 lines

Best,
Ivan

HTH

#9 lore raw

[CCing Mel and Johannes]

Quoted 4 lines · Ivan Danov

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file.

Sorry for the late reply:

$ grep MemFree: meminfo.1365194* | awk 'BEGIN{min=9999999}{val=$2; if(val<min)min=val; if(val>max)max=val; sum+=val; n++}END{printf "min:%d max:%d avg:%.2f\n", min, max, sum/n}'
min:165256 max:3254516 avg:1642475.35

So the free memory dropped down to 165M at minimum. This doesn't sound terribly low and the average free memory was even above 1.5G. But maybe the memory consumption peak was very short between 2 measured moments.

The peak seems to be around this time:

meminfo.1365194083:MemFree:          650792 kB
meminfo.1365194085:MemFree:          664920 kB
meminfo.1365194087:MemFree:          165256 kB  <<<
meminfo.1365194089:MemFree:          822968 kB
meminfo.1365194094:MemFree:          666940 kB

Let's have a look at the memory reclaim activity
vmstat.1365194085:pgscan_kswapd_dma32 760
vmstat.1365194085:pgscan_kswapd_normal 10444

vmstat.1365194087:pgscan_kswapd_dma32 760
vmstat.1365194087:pgscan_kswapd_normal 10444

vmstat.1365194089:pgscan_kswapd_dma32 5855
vmstat.1365194089:pgscan_kswapd_normal 80621

vmstat.1365194094:pgscan_kswapd_dma32 54333
vmstat.1365194094:pgscan_kswapd_normal 285562

[...]
vmstat.1365194098:pgscan_kswapd_dma32 54333
vmstat.1365194098:pgscan_kswapd_normal 285562

vmstat.1365194100:pgscan_kswapd_dma32 55760
vmstat.1365194100:pgscan_kswapd_normal 289493

vmstat.1365194102:pgscan_kswapd_dma32 55760
vmstat.1365194102:pgscan_kswapd_normal 289493

So the background reclaim was active only twice for a short amount of time:
- 1365194087 - 1365194094 - 53573 pages in dma32 and 275118 in normal zone
- 1365194098 - 1365194100 - 1427 pages in dma32 and 3931 in normal zone

The second one looks sane so we can ignore it for now but the first one scanned 1074M in normal zone and 209M in the dma32 zone. Either kswapd had hard time to find something to reclaim or it couldn't cope with the ongoing memory pressure.

vmstat.1365194087:pgsteal_kswapd_dma32 373
vmstat.1365194087:pgsteal_kswapd_normal 9057

vmstat.1365194089:pgsteal_kswapd_dma32 3249
vmstat.1365194089:pgsteal_kswapd_normal 56756

vmstat.1365194094:pgsteal_kswapd_dma32 14731
vmstat.1365194094:pgsteal_kswapd_normal 221733

...087-...089
- dma32 scanned 5095, reclaimed 0
- normal scanned 70177, reclaimed 0
...089-...094

	-dma32 scanned 48478, reclaimed 2876
	- normal scanned 204941, reclaimed 164977

This shows that kswapd was not able to reclaim any page at first and then it reclaimed a lot (644M in 5s) but still very ineffectively (5% in dma32 and 80% for normal) although normal zone seems to be doing much better.

The direct reclaim was active during that time as well:
vmstat.1365194089:pgscan_direct_dma32 0 vmstat.1365194089:pgscan_direct_normal 0

vmstat.1365194094:pgscan_direct_dma32 29339
vmstat.1365194094:pgscan_direct_normal 86869

which scanned 29339 in dma32 and 86869 in normal zone while it reclaimed:

vmstat.1365194089:pgsteal_direct_dma32 0
vmstat.1365194089:pgsteal_direct_normal 0

vmstat.1365194094:pgsteal_direct_dma32 6137
vmstat.1365194094:pgsteal_direct_normal 57677

225M in the normal zone but it was still not effective very much (~20% for dma32 and 66% for normal).

vmstat.1365194087:nr_written 9013
vmstat.1365194089:nr_written 9013
vmstat.1365194094:nr_written 15387

Only around 24M have been written out during the massive scanning.

So we have two problems here I guess. First is that there is not much reclaimable memory when the peak consumption starts and then we have hard times to balance dma32 zone.

vmstat.1365194087:nr_shmem 103548
vmstat.1365194089:nr_shmem 102227
vmstat.1365194094:nr_shmem 100679

This tells us that you didn't have that many shmem pages allocated at the time (only 404M). So the /tmp backed by tmpfs shouldn't be the primary issue here.

We still have a lot of anonymous memory though:
vmstat.1365194087:nr_anon_pages 1430922
vmstat.1365194089:nr_anon_pages 1317009
vmstat.1365194094:nr_anon_pages 1540460

which is around 5.5G. It is interesting that the number of these pages even drops first and then starts growing again (between 089..094 by 870M while we reclaimed around the same amount). This would suggest that the load started trashing on swap but:

meminfo.1365194087:SwapFree:        1999868 kB
meminfo.1365194089:SwapFree:        1999808 kB
meminfo.1365194094:SwapFree:        1784544 kB

tells us that we swapped out only 210M after 1365194089. So we had to reclaim a lot of page cache during that time while the anonymous memory pressure was really high.

vmstat.1365194087:nr_file_pages 428632
vmstat.1365194089:nr_file_pages 378132
vmstat.1365194094:nr_file_pages 192009

the page cache pages dropped down by 920M which covers the anon increase.

This all suggests that the workload is simply too aggressive and the memory reclaim doesn't cope with it.

Let's check the active and inactive lists (maybe we are not aging pages properly):
meminfo.1365194087:Active(anon): 5613412 kB
meminfo.1365194087:Active(file): 261180 kB

meminfo.1365194089:Active(anon): 4794472 kB
meminfo.1365194089:Active(file): 348396 kB

meminfo.1365194094:Active(anon): 5424684 kB
meminfo.1365194094:Active(file): 77364 kB

meminfo.1365194087:Inactive(anon): 496092 kB
meminfo.1365194087:Inactive(file): 1033184 kB

meminfo.1365194089:Inactive(anon): 853608 kB
meminfo.1365194089:Inactive(file): 749564 kB

meminfo.1365194094:Inactive(anon): 1313648 kB
meminfo.1365194094:Inactive(file): 82008 kB

While the file LRUs looks good active Anon LRUs seem to be too big. This either suggests a bug in aging or the working set is really that big. Considering the previous data (increase during the memory pressure) I would be inclined to the second option.

Just out of curiosity what is the vm_swappiness setting? You've said that you have changed that from 0 but it seems like we would swap much more. It almost looks like the swappiness is 0. Could you double check?

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
author
#10 lore raw
$ cat /proc/sys/vm/swappiness
60

I have increased my swap partition from nearly 2GB to around 16GB, but the problem remains. Here I attach the logs for the larger swap partition. I use a MATLAB script to simulate the problem, but it also works in Octave:
X = ones(100000,10000);

I have tried to simulate the problem on a desktop installation with 4GB of RAM, 10GB of swap partition, installed Ubuntu Lucid and then upgraded to 12.04, the problem isn't there, but the input is still quite choppy during the load. After the script finishes, everything looks fine. For the desktop installation the hard drive is not an SSD hard drive.

Quoted 165 lines · Michal Hocko

[CCing Mel and Johannes]

Quoted 4 lines · Ivan Danov

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file.

Sorry for the late reply:

$ grep MemFree: meminfo.1365194* | awk 'BEGIN{min=9999999}{val=$2; if(val<min)min=val; if(val>max)max=val; sum+=val; n++}END{printf "min:%d max:%d avg:%.2f\n", min, max, sum/n}'
min:165256 max:3254516 avg:1642475.35

So the free memory dropped down to 165M at minimum. This doesn't sound terribly low and the average free memory was even above 1.5G. But maybe the memory consumption peak was very short between 2 measured moments.

The peak seems to be around this time:

meminfo.1365194083:MemFree:          650792 kB
meminfo.1365194085:MemFree:          664920 kB
meminfo.1365194087:MemFree:          165256 kB  <<<
meminfo.1365194089:MemFree:          822968 kB
meminfo.1365194094:MemFree:          666940 kB

Let's have a look at the memory reclaim activity
vmstat.1365194085:pgscan_kswapd_dma32 760
vmstat.1365194085:pgscan_kswapd_normal 10444

vmstat.1365194087:pgscan_kswapd_dma32 760
vmstat.1365194087:pgscan_kswapd_normal 10444

vmstat.1365194089:pgscan_kswapd_dma32 5855
vmstat.1365194089:pgscan_kswapd_normal 80621

vmstat.1365194094:pgscan_kswapd_dma32 54333
vmstat.1365194094:pgscan_kswapd_normal 285562

[...]
vmstat.1365194098:pgscan_kswapd_dma32 54333
vmstat.1365194098:pgscan_kswapd_normal 285562

vmstat.1365194100:pgscan_kswapd_dma32 55760
vmstat.1365194100:pgscan_kswapd_normal 289493

vmstat.1365194102:pgscan_kswapd_dma32 55760
vmstat.1365194102:pgscan_kswapd_normal 289493

So the background reclaim was active only twice for a short amount of time:
- 1365194087 - 1365194094 - 53573 pages in dma32 and 275118 in normal zone
- 1365194098 - 1365194100 - 1427 pages in dma32 and 3931 in normal zone

The second one looks sane so we can ignore it for now but the first one scanned 1074M in normal zone and 209M in the dma32 zone. Either kswapd had hard time to find something to reclaim or it couldn't cope with the ongoing memory pressure.

vmstat.1365194087:pgsteal_kswapd_dma32 373
vmstat.1365194087:pgsteal_kswapd_normal 9057

vmstat.1365194089:pgsteal_kswapd_dma32 3249
vmstat.1365194089:pgsteal_kswapd_normal 56756

vmstat.1365194094:pgsteal_kswapd_dma32 14731
vmstat.1365194094:pgsteal_kswapd_normal 221733

...087-...089
- dma32 scanned 5095, reclaimed 0
- normal scanned 70177, reclaimed 0
...089-...094

	-dma32 scanned 48478, reclaimed 2876
	- normal scanned 204941, reclaimed 164977

This shows that kswapd was not able to reclaim any page at first and then it reclaimed a lot (644M in 5s) but still very ineffectively (5% in dma32 and 80% for normal) although normal zone seems to be doing much better.

The direct reclaim was active during that time as well:
vmstat.1365194089:pgscan_direct_dma32 0 vmstat.1365194089:pgscan_direct_normal 0

vmstat.1365194094:pgscan_direct_dma32 29339
vmstat.1365194094:pgscan_direct_normal 86869

which scanned 29339 in dma32 and 86869 in normal zone while it reclaimed:

vmstat.1365194089:pgsteal_direct_dma32 0
vmstat.1365194089:pgsteal_direct_normal 0

vmstat.1365194094:pgsteal_direct_dma32 6137
vmstat.1365194094:pgsteal_direct_normal 57677

225M in the normal zone but it was still not effective very much (~20% for dma32 and 66% for normal).

vmstat.1365194087:nr_written 9013
vmstat.1365194089:nr_written 9013
vmstat.1365194094:nr_written 15387

Only around 24M have been written out during the massive scanning.

So we have two problems here I guess. First is that there is not much reclaimable memory when the peak consumption starts and then we have hard times to balance dma32 zone.

vmstat.1365194087:nr_shmem 103548
vmstat.1365194089:nr_shmem 102227
vmstat.1365194094:nr_shmem 100679

This tells us that you didn't have that many shmem pages allocated at the time (only 404M). So the /tmp backed by tmpfs shouldn't be the primary issue here.

We still have a lot of anonymous memory though:
vmstat.1365194087:nr_anon_pages 1430922
vmstat.1365194089:nr_anon_pages 1317009
vmstat.1365194094:nr_anon_pages 1540460

which is around 5.5G. It is interesting that the number of these pages even drops first and then starts growing again (between 089..094 by 870M while we reclaimed around the same amount). This would suggest that the load started trashing on swap but:

meminfo.1365194087:SwapFree:        1999868 kB
meminfo.1365194089:SwapFree:        1999808 kB
meminfo.1365194094:SwapFree:        1784544 kB

tells us that we swapped out only 210M after 1365194089. So we had to reclaim a lot of page cache during that time while the anonymous memory pressure was really high.

vmstat.1365194087:nr_file_pages 428632
vmstat.1365194089:nr_file_pages 378132
vmstat.1365194094:nr_file_pages 192009

the page cache pages dropped down by 920M which covers the anon increase.

This all suggests that the workload is simply too aggressive and the memory reclaim doesn't cope with it.

Let's check the active and inactive lists (maybe we are not aging pages properly):
meminfo.1365194087:Active(anon): 5613412 kB
meminfo.1365194087:Active(file): 261180 kB

meminfo.1365194089:Active(anon): 4794472 kB
meminfo.1365194089:Active(file): 348396 kB

meminfo.1365194094:Active(anon): 5424684 kB
meminfo.1365194094:Active(file): 77364 kB

meminfo.1365194087:Inactive(anon): 496092 kB
meminfo.1365194087:Inactive(file): 1033184 kB

meminfo.1365194089:Inactive(anon): 853608 kB
meminfo.1365194089:Inactive(file): 749564 kB

meminfo.1365194094:Inactive(anon): 1313648 kB
meminfo.1365194094:Inactive(file): 82008 kB

While the file LRUs looks good active Anon LRUs seem to be too big. This either suggests a bug in aging or the working set is really that big. Considering the previous data (increase during the memory pressure) I would be inclined to the second option.

Just out of curiosity what is the vm_swappiness setting? You've said that you have changed that from 0 but it seems like we would swap much more. It almost looks like the swappiness is 0. Could you double check?

#11 lore raw
Quoted 2 lines · Ivan Danov
$ cat /proc/sys/vm/swappiness
60

OK, thanks for confirming this. It is really strange that we do not swap almost at all, then.

Quoted 2 lines

I have increased my swap partition from nearly 2GB to around 16GB, but the problem remains.

Increasing the swap partition will not help much as it almost unused with 2G already (at least last data shown that).

Quoted 3 lines

Here I attach the logs for the larger swap partition. I use a MATLAB script to simulate the problem, but it also works in Octave:
X = ones(100000,10000);

AFAIU this will create a matrix with 10^9 elements and initialize them to 1. I am not familiar with octave but do you happen to know what is the data type used for the element? 8B? It would be also interesting to know how is the matrix organized and initialized. Does it fit into memory at all?

Quoted 6 lines

I have tried to simulate the problem on a desktop installation with 4GB of RAM, 10GB of swap partition, installed Ubuntu Lucid and then upgraded to 12.04, the problem isn't there, but the input is still quite choppy during the load. After the script finishes, everything looks fine. For the desktop installation the hard drive is not an SSD hard drive.

What is the kernel version used here?

Quoted 167 lines · Michal Hocko
Quoted 165 lines

[CCing Mel and Johannes]

Quoted 4 lines · Ivan Danov

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file.

Sorry for the late reply:

$ grep MemFree: meminfo.1365194* | awk 'BEGIN{min=9999999}{val=$2; if(val<min)min=val; if(val>max)max=val; sum+=val; n++}END{printf "min:%d max:%d avg:%.2f\n", min, max, sum/n}'
min:165256 max:3254516 avg:1642475.35

So the free memory dropped down to 165M at minimum. This doesn't sound terribly low and the average free memory was even above 1.5G. But maybe the memory consumption peak was very short between 2 measured moments.

The peak seems to be around this time:

meminfo.1365194083:MemFree:          650792 kB
meminfo.1365194085:MemFree:          664920 kB
meminfo.1365194087:MemFree:          165256 kB  <<<
meminfo.1365194089:MemFree:          822968 kB
meminfo.1365194094:MemFree:          666940 kB

Let's have a look at the memory reclaim activity
vmstat.1365194085:pgscan_kswapd_dma32 760
vmstat.1365194085:pgscan_kswapd_normal 10444

vmstat.1365194087:pgscan_kswapd_dma32 760
vmstat.1365194087:pgscan_kswapd_normal 10444

vmstat.1365194089:pgscan_kswapd_dma32 5855
vmstat.1365194089:pgscan_kswapd_normal 80621

vmstat.1365194094:pgscan_kswapd_dma32 54333
vmstat.1365194094:pgscan_kswapd_normal 285562

[...]
vmstat.1365194098:pgscan_kswapd_dma32 54333
vmstat.1365194098:pgscan_kswapd_normal 285562

vmstat.1365194100:pgscan_kswapd_dma32 55760
vmstat.1365194100:pgscan_kswapd_normal 289493

vmstat.1365194102:pgscan_kswapd_dma32 55760
vmstat.1365194102:pgscan_kswapd_normal 289493

So the background reclaim was active only twice for a short amount of time:
- 1365194087 - 1365194094 - 53573 pages in dma32 and 275118 in normal zone
- 1365194098 - 1365194100 - 1427 pages in dma32 and 3931 in normal zone

The second one looks sane so we can ignore it for now but the first one scanned 1074M in normal zone and 209M in the dma32 zone. Either kswapd had hard time to find something to reclaim or it couldn't cope with the ongoing memory pressure.

vmstat.1365194087:pgsteal_kswapd_dma32 373
vmstat.1365194087:pgsteal_kswapd_normal 9057

vmstat.1365194089:pgsteal_kswapd_dma32 3249
vmstat.1365194089:pgsteal_kswapd_normal 56756

vmstat.1365194094:pgsteal_kswapd_dma32 14731
vmstat.1365194094:pgsteal_kswapd_normal 221733

...087-...089
- dma32 scanned 5095, reclaimed 0
- normal scanned 70177, reclaimed 0
...089-...094

	-dma32 scanned 48478, reclaimed 2876
	- normal scanned 204941, reclaimed 164977

This shows that kswapd was not able to reclaim any page at first and then it reclaimed a lot (644M in 5s) but still very ineffectively (5% in dma32 and 80% for normal) although normal zone seems to be doing much better.

The direct reclaim was active during that time as well:
vmstat.1365194089:pgscan_direct_dma32 0 vmstat.1365194089:pgscan_direct_normal 0

vmstat.1365194094:pgscan_direct_dma32 29339
vmstat.1365194094:pgscan_direct_normal 86869

which scanned 29339 in dma32 and 86869 in normal zone while it reclaimed:

vmstat.1365194089:pgsteal_direct_dma32 0
vmstat.1365194089:pgsteal_direct_normal 0

vmstat.1365194094:pgsteal_direct_dma32 6137
vmstat.1365194094:pgsteal_direct_normal 57677

225M in the normal zone but it was still not effective very much (~20% for dma32 and 66% for normal).

vmstat.1365194087:nr_written 9013
vmstat.1365194089:nr_written 9013
vmstat.1365194094:nr_written 15387

Only around 24M have been written out during the massive scanning.

So we have two problems here I guess. First is that there is not much reclaimable memory when the peak consumption starts and then we have hard times to balance dma32 zone.

vmstat.1365194087:nr_shmem 103548
vmstat.1365194089:nr_shmem 102227
vmstat.1365194094:nr_shmem 100679

This tells us that you didn't have that many shmem pages allocated at the time (only 404M). So the /tmp backed by tmpfs shouldn't be the primary issue here.

We still have a lot of anonymous memory though:
vmstat.1365194087:nr_anon_pages 1430922
vmstat.1365194089:nr_anon_pages 1317009
vmstat.1365194094:nr_anon_pages 1540460

which is around 5.5G. It is interesting that the number of these pages even drops first and then starts growing again (between 089..094 by 870M while we reclaimed around the same amount). This would suggest that the load started trashing on swap but:

meminfo.1365194087:SwapFree:        1999868 kB
meminfo.1365194089:SwapFree:        1999808 kB
meminfo.1365194094:SwapFree:        1784544 kB

tells us that we swapped out only 210M after 1365194089. So we had to reclaim a lot of page cache during that time while the anonymous memory pressure was really high.

vmstat.1365194087:nr_file_pages 428632
vmstat.1365194089:nr_file_pages 378132
vmstat.1365194094:nr_file_pages 192009

the page cache pages dropped down by 920M which covers the anon increase.

This all suggests that the workload is simply too aggressive and the memory reclaim doesn't cope with it.

Let's check the active and inactive lists (maybe we are not aging pages properly):
meminfo.1365194087:Active(anon): 5613412 kB
meminfo.1365194087:Active(file): 261180 kB

meminfo.1365194089:Active(anon): 4794472 kB
meminfo.1365194089:Active(file): 348396 kB

meminfo.1365194094:Active(anon): 5424684 kB
meminfo.1365194094:Active(file): 77364 kB

meminfo.1365194087:Inactive(anon): 496092 kB
meminfo.1365194087:Inactive(file): 1033184 kB

meminfo.1365194089:Inactive(anon): 853608 kB
meminfo.1365194089:Inactive(file): 749564 kB

meminfo.1365194094:Inactive(anon): 1313648 kB
meminfo.1365194094:Inactive(file): 82008 kB

While the file LRUs looks good active Anon LRUs seem to be too big. This either suggests a bug in aging or the working set is really that big. Considering the previous data (increase during the memory pressure) I would be inclined to the second option.

Just out of curiosity what is the vm_swappiness setting? You've said that you have changed that from 0 but it seems like we would swap much more. It almost looks like the swappiness is 0. Could you double check?

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
author
#12 lore raw
Quoted 11 lines · Michal Hocko
Quoted 2 lines · Ivan Danov
$ cat /proc/sys/vm/swappiness
60

OK, thanks for confirming this. It is really strange that we do not swap almost at all, then.

Quoted 2 lines

I have increased my swap partition from nearly 2GB to around 16GB, but the problem remains.

Increasing the swap partition will not help much as it almost unused with 2G already (at least last data shown that).

Quoted 8 lines
Quoted 3 lines

Here I attach the logs for the larger swap partition. I use a MATLAB script to simulate the problem, but it also works in Octave:
X = ones(100000,10000);

AFAIU this will create a matrix with 10^9 elements and initialize them to 1. I am not familiar with octave but do you happen to know what is the data type used for the element? 8B? It would be also interesting to know how is the matrix organized and initialized. Does it fit into memory at all?

Yes, 8B each, so it will be almost 8GB and it should fit into the memory. I don't know details how it actually works, but if it cannot create the matrix, MATLAB complains about that. Since it starts complaining even after 2000 more in the second dimension, maybe it needs the RAM to create it all. However on the desktop machine, both RAM and swap are being used (quite a lot of them both).

Quoted 8 lines
Quoted 7 lines

I have tried to simulate the problem on a desktop installation with 4GB of RAM, 10GB of swap partition, installed Ubuntu Lucid and then upgraded to 12.04, the problem isn't there, but the input is still quite choppy during the load. After the script finishes, everything looks fine. For the desktop installation the hard drive is not an SSD hard drive.

What is the kernel version used here?

$ uname -a
Linux ivan 3.2.0-40-generic #64-Ubuntu SMP Mon Mar 25 21:22:10 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
Quoted 159 lines
Quoted 159 lines · Michal Hocko
Quoted 157 lines

[CCing Mel and Johannes]

Quoted 4 lines · Ivan Danov

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file.

Sorry for the late reply:

$ grep MemFree: meminfo.1365194* | awk 'BEGIN{min=9999999}{val=$2; if(val<min)min=val; if(val>max)max=val; sum+=val; n++}END{printf "min:%d max:%d avg:%.2f\n", min, max, sum/n}'
min:165256 max:3254516 avg:1642475.35

So the free memory dropped down to 165M at minimum. This doesn't sound terribly low and the average free memory was even above 1.5G. But maybe the memory consumption peak was very short between 2 measured moments.

The peak seems to be around this time:

meminfo.1365194083:MemFree:          650792 kB
meminfo.1365194085:MemFree:          664920 kB
meminfo.1365194087:MemFree:          165256 kB  <<<
meminfo.1365194089:MemFree:          822968 kB
meminfo.1365194094:MemFree:          666940 kB

Let's have a look at the memory reclaim activity
vmstat.1365194085:pgscan_kswapd_dma32 760
vmstat.1365194085:pgscan_kswapd_normal 10444

vmstat.1365194087:pgscan_kswapd_dma32 760
vmstat.1365194087:pgscan_kswapd_normal 10444

vmstat.1365194089:pgscan_kswapd_dma32 5855
vmstat.1365194089:pgscan_kswapd_normal 80621

vmstat.1365194094:pgscan_kswapd_dma32 54333
vmstat.1365194094:pgscan_kswapd_normal 285562

[...]
vmstat.1365194098:pgscan_kswapd_dma32 54333
vmstat.1365194098:pgscan_kswapd_normal 285562

vmstat.1365194100:pgscan_kswapd_dma32 55760
vmstat.1365194100:pgscan_kswapd_normal 289493

vmstat.1365194102:pgscan_kswapd_dma32 55760
vmstat.1365194102:pgscan_kswapd_normal 289493

So the background reclaim was active only twice for a short amount of time:
- 1365194087 - 1365194094 - 53573 pages in dma32 and 275118 in normal zone
- 1365194098 - 1365194100 - 1427 pages in dma32 and 3931 in normal zone

The second one looks sane so we can ignore it for now but the first one scanned 1074M in normal zone and 209M in the dma32 zone. Either kswapd had hard time to find something to reclaim or it couldn't cope with the ongoing memory pressure.

vmstat.1365194087:pgsteal_kswapd_dma32 373
vmstat.1365194087:pgsteal_kswapd_normal 9057

vmstat.1365194089:pgsteal_kswapd_dma32 3249
vmstat.1365194089:pgsteal_kswapd_normal 56756

vmstat.1365194094:pgsteal_kswapd_dma32 14731
vmstat.1365194094:pgsteal_kswapd_normal 221733

...087-...089
- dma32 scanned 5095, reclaimed 0
- normal scanned 70177, reclaimed 0
...089-...094

	-dma32 scanned 48478, reclaimed 2876
	- normal scanned 204941, reclaimed 164977

This shows that kswapd was not able to reclaim any page at first and then it reclaimed a lot (644M in 5s) but still very ineffectively (5% in dma32 and 80% for normal) although normal zone seems to be doing much better.

The direct reclaim was active during that time as well:
vmstat.1365194089:pgscan_direct_dma32 0 vmstat.1365194089:pgscan_direct_normal 0

vmstat.1365194094:pgscan_direct_dma32 29339
vmstat.1365194094:pgscan_direct_normal 86869

which scanned 29339 in dma32 and 86869 in normal zone while it reclaimed:

vmstat.1365194089:pgsteal_direct_dma32 0
vmstat.1365194089:pgsteal_direct_normal 0

vmstat.1365194094:pgsteal_direct_dma32 6137
vmstat.1365194094:pgsteal_direct_normal 57677

225M in the normal zone but it was still not effective very much (~20% for dma32 and 66% for normal).

vmstat.1365194087:nr_written 9013
vmstat.1365194089:nr_written 9013
vmstat.1365194094:nr_written 15387

Only around 24M have been written out during the massive scanning.

So we have two problems here I guess. First is that there is not much reclaimable memory when the peak consumption starts and then we have hard times to balance dma32 zone.

vmstat.1365194087:nr_shmem 103548
vmstat.1365194089:nr_shmem 102227
vmstat.1365194094:nr_shmem 100679

This tells us that you didn't have that many shmem pages allocated at the time (only 404M). So the /tmp backed by tmpfs shouldn't be the primary issue here.

We still have a lot of anonymous memory though:
vmstat.1365194087:nr_anon_pages 1430922
vmstat.1365194089:nr_anon_pages 1317009
vmstat.1365194094:nr_anon_pages 1540460

which is around 5.5G. It is interesting that the number of these pages even drops first and then starts growing again (between 089..094 by 870M while we reclaimed around the same amount). This would suggest that the load started trashing on swap but:

meminfo.1365194087:SwapFree:        1999868 kB
meminfo.1365194089:SwapFree:        1999808 kB
meminfo.1365194094:SwapFree:        1784544 kB

tells us that we swapped out only 210M after 1365194089. So we had to reclaim a lot of page cache during that time while the anonymous memory pressure was really high.

vmstat.1365194087:nr_file_pages 428632
vmstat.1365194089:nr_file_pages 378132
vmstat.1365194094:nr_file_pages 192009

the page cache pages dropped down by 920M which covers the anon increase.

This all suggests that the workload is simply too aggressive and the memory reclaim doesn't cope with it.

Let's check the active and inactive lists (maybe we are not aging pages properly):
meminfo.1365194087:Active(anon): 5613412 kB
meminfo.1365194087:Active(file): 261180 kB

meminfo.1365194089:Active(anon): 4794472 kB
meminfo.1365194089:Active(file): 348396 kB

meminfo.1365194094:Active(anon): 5424684 kB
meminfo.1365194094:Active(file): 77364 kB

meminfo.1365194087:Inactive(anon): 496092 kB
meminfo.1365194087:Inactive(file): 1033184 kB

meminfo.1365194089:Inactive(anon): 853608 kB
meminfo.1365194089:Inactive(file): 749564 kB

meminfo.1365194094:Inactive(anon): 1313648 kB
meminfo.1365194094:Inactive(file): 82008 kB

Quoted 10 lines
Quoted 8 lines
Quoted 8 lines

While the file LRUs looks good active Anon LRUs seem to be too big. This either suggests a bug in aging or the working set is really that big. Considering the previous data (increase during the memory pressure) I would be inclined to the second option.

Just out of curiosity what is the vm_swappiness setting? You've said that you have changed that from 0 but it seems like we would swap much more. It almost looks like the swappiness is 0. Could you double check?

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

#13 lore raw
Quoted 14 lines · Ivan Danov
Quoted 13 lines · Michal Hocko
Quoted 2 lines · Ivan Danov
$ cat /proc/sys/vm/swappiness
60

OK, thanks for confirming this. It is really strange that we do not swap almost at all, then.

Quoted 2 lines

I have increased my swap partition from nearly 2GB to around 16GB, but the problem remains.

Increasing the swap partition will not help much as it almost unused with 2G already (at least last data shown that).

Quoted 3 lines

Here I attach the logs for the larger swap partition. I use a MATLAB script to simulate the problem, but it also works in Octave:
X = ones(100000,10000);

Quoted 7 lines
Quoted 5 lines

AFAIU this will create a matrix with 10^9 elements and initialize them to 1. I am not familiar with octave but do you happen to know what is the data type used for the element? 8B? It would be also interesting to know how is the matrix organized and initialized. Does it fit into memory at all?

Yes, 8B each, so it will be almost 8GB and it should fit into the memory.

It won't fit in because kernel and other processes consume some memory as well. So you have to swap.

Quoted 5 lines

I don't know details how it actually works, but if it cannot create the matrix, MATLAB complains about that. Since it starts complaining even after 2000 more in the second dimension, maybe it needs the RAM to create it all. However on the desktop machine, both RAM and swap are being used (quite a lot of them both).

How much you swap depends on vm.swappiness. I would suggest increasing the value if your workload is really so anononymous memory based. Otherwise a lot of file pages are reclaimed which can lead to problems you are seeing.

Quoted 10 lines
Quoted 7 lines
Quoted 6 lines

I have tried to simulate the problem on a desktop installation with 4GB of RAM, 10GB of swap partition, installed Ubuntu Lucid and then upgraded to 12.04, the problem isn't there, but the input is still quite choppy during the load. After the script finishes, everything looks fine. For the desktop installation the hard drive is not an SSD hard drive.

What is the kernel version used here?

$ uname -a
Linux ivan 3.2.0-40-generic #64-Ubuntu SMP Mon Mar 25 21:22:10 UTC
2013 x86_64 x86_64 x86_64 GNU/Linux

Is there any chance you could test with the latest vanilla kernel and Mel's patches from https://lkml.org/lkml/2013/4/11/516 on top?

[...]

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
#15 lore raw
In reply to Michal Hocko

Hi Michal,

Quoted 60 lines · Michal Hocko

[CCing Mel and Johannes]

Quoted 4 lines · Ivan Danov

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file.

Sorry for the late reply:

$ grep MemFree: meminfo.1365194* | awk 'BEGIN{min=9999999}{val=$2; if(val<min)min=val; if(val>max)max=val; sum+=val; n++}END{printf "min:%d max:%d avg:%.2f\n", min, max, sum/n}'
min:165256 max:3254516 avg:1642475.35

So the free memory dropped down to 165M at minimum. This doesn't sound terribly low and the average free memory was even above 1.5G. But maybe the memory consumption peak was very short between 2 measured moments.

The peak seems to be around this time:

meminfo.1365194083:MemFree:          650792 kB
meminfo.1365194085:MemFree:          664920 kB
meminfo.1365194087:MemFree:          165256 kB  <<<
meminfo.1365194089:MemFree:          822968 kB
meminfo.1365194094:MemFree:          666940 kB

Let's have a look at the memory reclaim activity
vmstat.1365194085:pgscan_kswapd_dma32 760
vmstat.1365194085:pgscan_kswapd_normal 10444

vmstat.1365194087:pgscan_kswapd_dma32 760
vmstat.1365194087:pgscan_kswapd_normal 10444

vmstat.1365194089:pgscan_kswapd_dma32 5855
vmstat.1365194089:pgscan_kswapd_normal 80621

vmstat.1365194094:pgscan_kswapd_dma32 54333
vmstat.1365194094:pgscan_kswapd_normal 285562

[...]
vmstat.1365194098:pgscan_kswapd_dma32 54333
vmstat.1365194098:pgscan_kswapd_normal 285562

vmstat.1365194100:pgscan_kswapd_dma32 55760
vmstat.1365194100:pgscan_kswapd_normal 289493

vmstat.1365194102:pgscan_kswapd_dma32 55760
vmstat.1365194102:pgscan_kswapd_normal 289493

So the background reclaim was active only twice for a short amount of time:
- 1365194087 - 1365194094 - 53573 pages in dma32 and 275118 in normal zone
- 1365194098 - 1365194100 - 1427 pages in dma32 and 3931 in normal zone

The second one looks sane so we can ignore it for now but the first one scanned 1074M in normal zone and 209M in the dma32 zone. Either kswapd had hard time to find something to reclaim or it couldn't cope with the ongoing memory pressure.

vmstat.1365194087:pgsteal_kswapd_dma32 373
vmstat.1365194087:pgsteal_kswapd_normal 9057

vmstat.1365194089:pgsteal_kswapd_dma32 3249
vmstat.1365194089:pgsteal_kswapd_normal 56756

Quoted 6 lines

vmstat.1365194094:pgsteal_kswapd_dma32 14731
vmstat.1365194094:pgsteal_kswapd_normal 221733

...087-...089
- dma32 scanned 5095, reclaimed 0
- normal scanned 70177, reclaimed 0

This is not correct.
- dma32 scanned 5095, reclaimed 2876, effective = 56%
- normal scanned 70177, reclaimed 47699, effective = 68%

Quoted 3 lines

...089-...094

	-dma32 scanned 48478, reclaimed 2876
	- normal scanned 204941, reclaimed 164977

- dma32 scanned 48478, reclaimed 11482, effective = 23%
- normal scanned 204941, reclaimed 164977, effective = 80%

Quoted 51 lines

This shows that kswapd was not able to reclaim any page at first and then it reclaimed a lot (644M in 5s) but still very ineffectively (5% in dma32 and 80% for normal) although normal zone seems to be doing much better.

The direct reclaim was active during that time as well:
vmstat.1365194089:pgscan_direct_dma32 0 vmstat.1365194089:pgscan_direct_normal 0

vmstat.1365194094:pgscan_direct_dma32 29339
vmstat.1365194094:pgscan_direct_normal 86869

which scanned 29339 in dma32 and 86869 in normal zone while it reclaimed:

vmstat.1365194089:pgsteal_direct_dma32 0
vmstat.1365194089:pgsteal_direct_normal 0

vmstat.1365194094:pgsteal_direct_dma32 6137
vmstat.1365194094:pgsteal_direct_normal 57677

225M in the normal zone but it was still not effective very much (~20% for dma32 and 66% for normal).

vmstat.1365194087:nr_written 9013
vmstat.1365194089:nr_written 9013
vmstat.1365194094:nr_written 15387

Only around 24M have been written out during the massive scanning.

So we have two problems here I guess. First is that there is not much reclaimable memory when the peak consumption starts and then we have hard times to balance dma32 zone.

vmstat.1365194087:nr_shmem 103548
vmstat.1365194089:nr_shmem 102227
vmstat.1365194094:nr_shmem 100679

This tells us that you didn't have that many shmem pages allocated at the time (only 404M). So the /tmp backed by tmpfs shouldn't be the primary issue here.

We still have a lot of anonymous memory though:
vmstat.1365194087:nr_anon_pages 1430922
vmstat.1365194089:nr_anon_pages 1317009
vmstat.1365194094:nr_anon_pages 1540460

which is around 5.5G. It is interesting that the number of these pages even drops first and then starts growing again (between 089..094 by 870M while we reclaimed around the same amount). This would suggest that the load started trashing on swap but:

Quoted 5 lines
meminfo.1365194087:SwapFree:        1999868 kB
meminfo.1365194089:SwapFree:        1999808 kB
meminfo.1365194094:SwapFree:        1784544 kB

tells us that we swapped out only 210M after 1365194089. So we had to

How about set vm.swapiness to 200?

Quoted 31 lines

reclaim a lot of page cache during that time while the anonymous memory pressure was really high.

vmstat.1365194087:nr_file_pages 428632
vmstat.1365194089:nr_file_pages 378132
vmstat.1365194094:nr_file_pages 192009

the page cache pages dropped down by 920M which covers the anon increase.

This all suggests that the workload is simply too aggressive and the memory reclaim doesn't cope with it.

Let's check the active and inactive lists (maybe we are not aging pages properly):
meminfo.1365194087:Active(anon): 5613412 kB
meminfo.1365194087:Active(file): 261180 kB

meminfo.1365194089:Active(anon): 4794472 kB
meminfo.1365194089:Active(file): 348396 kB

meminfo.1365194094:Active(anon): 5424684 kB
meminfo.1365194094:Active(file): 77364 kB

meminfo.1365194087:Inactive(anon): 496092 kB
meminfo.1365194087:Inactive(file): 1033184 kB

meminfo.1365194089:Inactive(anon): 853608 kB
meminfo.1365194089:Inactive(file): 749564 kB

meminfo.1365194094:Inactive(anon): 1313648 kB
meminfo.1365194094:Inactive(file): 82008 kB

Quoted 8 lines

While the file LRUs looks good active Anon LRUs seem to be too big. This either suggests a bug in aging or the working set is really that big. Considering the previous data (increase during the memory pressure) I would be inclined to the second option.

Just out of curiosity what is the vm_swappiness setting? You've said that you have changed that from 0 but it seems like we would swap much more. It almost looks like the swappiness is 0. Could you double check?

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

#16 lore raw
Quoted 65 lines · Simon Jeons

Hi Michal,

Quoted 63 lines · Michal Hocko

[CCing Mel and Johannes]

Quoted 4 lines · Ivan Danov

Here you can find attached the script, collecting the logs and the logs themselves during the described process of freezing. It appeared that the previous logs are corrupted, because both /proc/vmstat and /proc/meminfo have been logging to the same file.

Sorry for the late reply:

$ grep MemFree: meminfo.1365194* | awk 'BEGIN{min=9999999}{val=$2; if(val<min)min=val; if(val>max)max=val; sum+=val; n++}END{printf "min:%d max:%d avg:%.2f\n", min, max, sum/n}'
min:165256 max:3254516 avg:1642475.35

So the free memory dropped down to 165M at minimum. This doesn't sound terribly low and the average free memory was even above 1.5G. But maybe the memory consumption peak was very short between 2 measured moments.

The peak seems to be around this time:

meminfo.1365194083:MemFree:          650792 kB
meminfo.1365194085:MemFree:          664920 kB
meminfo.1365194087:MemFree:          165256 kB  <<<
meminfo.1365194089:MemFree:          822968 kB
meminfo.1365194094:MemFree:          666940 kB

Let's have a look at the memory reclaim activity
vmstat.1365194085:pgscan_kswapd_dma32 760
vmstat.1365194085:pgscan_kswapd_normal 10444

vmstat.1365194087:pgscan_kswapd_dma32 760
vmstat.1365194087:pgscan_kswapd_normal 10444

vmstat.1365194089:pgscan_kswapd_dma32 5855
vmstat.1365194089:pgscan_kswapd_normal 80621

vmstat.1365194094:pgscan_kswapd_dma32 54333
vmstat.1365194094:pgscan_kswapd_normal 285562

[...]
vmstat.1365194098:pgscan_kswapd_dma32 54333
vmstat.1365194098:pgscan_kswapd_normal 285562

vmstat.1365194100:pgscan_kswapd_dma32 55760
vmstat.1365194100:pgscan_kswapd_normal 289493

vmstat.1365194102:pgscan_kswapd_dma32 55760
vmstat.1365194102:pgscan_kswapd_normal 289493

So the background reclaim was active only twice for a short amount of time:
- 1365194087 - 1365194094 - 53573 pages in dma32 and 275118 in normal zone
- 1365194098 - 1365194100 - 1427 pages in dma32 and 3931 in normal zone

The second one looks sane so we can ignore it for now but the first one scanned 1074M in normal zone and 209M in the dma32 zone. Either kswapd had hard time to find something to reclaim or it couldn't cope with the ongoing memory pressure.

vmstat.1365194087:pgsteal_kswapd_dma32 373
vmstat.1365194087:pgsteal_kswapd_normal 9057

vmstat.1365194089:pgsteal_kswapd_dma32 3249
vmstat.1365194089:pgsteal_kswapd_normal 56756

vmstat.1365194094:pgsteal_kswapd_dma32 14731
vmstat.1365194094:pgsteal_kswapd_normal 221733

Quoted 7 lines
Quoted 3 lines

...087-...089
- dma32 scanned 5095, reclaimed 0
- normal scanned 70177, reclaimed 0

This is not correct.
- dma32 scanned 5095, reclaimed 2876, effective = 56%
- normal scanned 70177, reclaimed 47699, effective = 68%

Right you are! I've made a mistake compared wrong timestamps.

Quoted 6 lines
Quoted 3 lines

...089-...094

	-dma32 scanned 48478, reclaimed 2876
	- normal scanned 204941, reclaimed 164977

- dma32 scanned 48478, reclaimed 11482, effective = 23%
- normal scanned 204941, reclaimed 164977, effective = 80%

Same here.

Quoted 52 lines
Quoted 52 lines

This shows that kswapd was not able to reclaim any page at first and then it reclaimed a lot (644M in 5s) but still very ineffectively (5% in dma32 and 80% for normal) although normal zone seems to be doing much better.

The direct reclaim was active during that time as well:
vmstat.1365194089:pgscan_direct_dma32 0 vmstat.1365194089:pgscan_direct_normal 0

vmstat.1365194094:pgscan_direct_dma32 29339
vmstat.1365194094:pgscan_direct_normal 86869

which scanned 29339 in dma32 and 86869 in normal zone while it reclaimed:

vmstat.1365194089:pgsteal_direct_dma32 0
vmstat.1365194089:pgsteal_direct_normal 0

vmstat.1365194094:pgsteal_direct_dma32 6137
vmstat.1365194094:pgsteal_direct_normal 57677

225M in the normal zone but it was still not effective very much (~20% for dma32 and 66% for normal).

vmstat.1365194087:nr_written 9013
vmstat.1365194089:nr_written 9013
vmstat.1365194094:nr_written 15387

Only around 24M have been written out during the massive scanning.

So we have two problems here I guess. First is that there is not much reclaimable memory when the peak consumption starts and then we have hard times to balance dma32 zone.

vmstat.1365194087:nr_shmem 103548
vmstat.1365194089:nr_shmem 102227
vmstat.1365194094:nr_shmem 100679

This tells us that you didn't have that many shmem pages allocated at the time (only 404M). So the /tmp backed by tmpfs shouldn't be the primary issue here.

We still have a lot of anonymous memory though:
vmstat.1365194087:nr_anon_pages 1430922
vmstat.1365194089:nr_anon_pages 1317009
vmstat.1365194094:nr_anon_pages 1540460

which is around 5.5G. It is interesting that the number of these pages even drops first and then starts growing again (between 089..094 by 870M while we reclaimed around the same amount). This would suggest that the load started trashing on swap but:

Quoted 7 lines
Quoted 5 lines
meminfo.1365194087:SwapFree:        1999868 kB
meminfo.1365194089:SwapFree:        1999808 kB
meminfo.1365194094:SwapFree:        1784544 kB

tells us that we swapped out only 210M after 1365194089. So we had to

How about set vm.swapiness to 200?

swappiness is limited to 0 to 100 values. And it treats anon vs. file LRUs equally at 100.

Signature · 8 lines
Michal Hocko
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
author
#14 lore raw
In reply to Michal Hocko

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Quoted 43 lines · Michal Hocko
Quoted 14 lines · Ivan Danov
Quoted 13 lines · Michal Hocko
Quoted 2 lines · Ivan Danov
$ cat /proc/sys/vm/swappiness
60

OK, thanks for confirming this. It is really strange that we do not swap almost at all, then.

Quoted 2 lines

I have increased my swap partition from nearly 2GB to around 16GB, but the problem remains.

Increasing the swap partition will not help much as it almost unused with 2G already (at least last data shown that).

Quoted 3 lines

Here I attach the logs for the larger swap partition. I use a MATLAB script to simulate the problem, but it also works in Octave:
X = ones(100000,10000);

Quoted 7 lines
Quoted 5 lines

AFAIU this will create a matrix with 10^9 elements and initialize them to 1. I am not familiar with octave but do you happen to know what is the data type used for the element? 8B? It would be also interesting to know how is the matrix organized and initialized. Does it fit into memory at all?

Yes, 8B each, so it will be almost 8GB and it should fit into the memory.

It won't fit in because kernel and other processes consume some memory as well. So you have to swap.

Quoted 5 lines

I don't know details how it actually works, but if it cannot create the matrix, MATLAB complains about that. Since it starts complaining even after 2000 more in the second dimension, maybe it needs the RAM to create it all. However on the desktop machine, both RAM and swap are being used (quite a lot of them both).

How much you swap depends on vm.swappiness. I would suggest increasing the value if your workload is really so anononymous memory based. Otherwise a lot of file pages are reclaimed which can lead to problems you are seeing.

Quoted 6 lines
Quoted 6 lines
Quoted 6 lines

I have tried to simulate the problem on a desktop installation with 4GB of RAM, 10GB of swap partition, installed Ubuntu Lucid and then upgraded to 12.04, the problem isn't there, but the input is still quite choppy during the load. After the script finishes, everything looks fine. For the desktop installation the hard drive is not an SSD hard drive.

Quoted 7 lines
Quoted 4 lines
Quoted 1 line

What is the kernel version used here?

$ uname -a
Linux ivan 3.2.0-40-generic #64-Ubuntu SMP Mon Mar 25 21:22:10 UTC
2013 x86_64 x86_64 x86_64 GNU/Linux

Is there any chance you could test with the latest vanilla kernel and Mel's patches from https://lkml.org/lkml/2013/4/11/516 on top?

Sorry for the late comeback, I've been quite busy these days. I will try to compile the kernel in the weekend. However, I will do kernel compiling for first time, so maybe it could take me some time. Btw I have upgraded to Ubuntu 13.04, so my kernel now is:

$ uname -a
Linux ivan 3.8.0-19-generic #30-Ubuntu SMP Wed May 1 16:35:23 UTC 2013
x86_64 x86_64 x86_64 GNU/Linux

The problem is still there.

Quoted 2 lines

[...]

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.12 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQEcBAEBAgAGBQJRkldrAAoJEJ8e6XRVH9TGgAIIAI7hw+YWhtiZ3LAr4SOQRvce xkRcSFUjmhW3FCSm5TERtUY6Ney3hJ9NU7I4yA56WGwOf2E6GnNkG0plewNMsWrM 4ZCFevsm1MoGP5576PUm8F0FF/0EfpFRLLwNNB7dDYDsXdmG8KlOYjlEB5H31lrR Ycx155ZvUgVUQXNg0tthaPoy8Qaw5sGI062d9tRA4f45fh7KFhX58HVHKT+L6LtV caLXwdH5Wkzi+Xshl6h8BGnB57fjQCDCEdltR3f1ddbUnh5kjvXKLGUWvuut7Ish vkbOTfSBbjOPtQly6DJ/xxS8HbSIsdDU4ecfWHGztl6r1lteFJDiqFA+bPsBszU= =oULy
-----END PGP SIGNATURE-----

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>