[Bug 1013629] New: 100% CPU usage on kswapd0 only on EC2 HVM
http://bugzilla.suse.com/show_bug.cgi?id=1013629 Bug ID: 1013629 Summary: 100% CPU usage on kswapd0 only on EC2 HVM Classification: openSUSE Product: openSUSE Distribution Version: Leap 42.2 Hardware: Other OS: Other Status: NEW Severity: Normal Priority: P5 - None Component: Kernel Assignee: kernel-maintainers@forge.provo.novell.com Reporter: hguo@suse.com QA Contact: qa-bugs@suse.de Found By: --- Blocker: --- The server is a HVM micro instance running 42.2 on Amazon EC2. The server has 485MB of system memory, it runs several small daemon programs that together cause memory usage to raise to 260MB as indicated by "free". There is a 1GB swap file in / which is on ext4. The load indicator almost always stays below 0.1 and memory usage almost always stays at ~260MB, except when doing zypper update that causes memory usage to climb over 300MB and swap usage climbs to ~10MB. The server has been running smoothly ever since 42.2 release, but beginning from yesterday, even tiny bit of memory pressure such as zypper update will trigger kswap0 to use 100% cpu. Temporary remedy "echo 1 > /proc/sys/vm/drop_caches" helps for a while, until the memory usage gets pressured once again via zypper update. The issue however does not occur, under these circumstances: - An identical server setup on GCE that has 587MB rather than 487MB of memory. - Swap file is turned off. sysctl VM parameters are the following: vm.admin_reserve_kbytes = 8192 vm.block_dump = 0 vm.compact_unevictable_allowed = 1 vm.dirty_background_bytes = 0 vm.dirty_background_ratio = 10 vm.dirty_bytes = 0 vm.dirty_expire_centisecs = 3000 vm.dirty_ratio = 40 vm.dirty_writeback_centisecs = 500 vm.dirtytime_expire_seconds = 43200 vm.drop_caches = 1 vm.extfrag_threshold = 500 vm.hugepages_treat_as_movable = 0 vm.hugetlb_shm_group = 0 vm.laptop_mode = 0 vm.legacy_va_layout = 0 vm.lowmem_reserve_ratio = 256 256 32 1 vm.max_map_count = 65530 vm.memory_failure_early_kill = 0 vm.memory_failure_recovery = 1 vm.min_free_kbytes = 65536 vm.min_slab_ratio = 5 vm.min_unmapped_ratio = 1 vm.mmap_min_addr = 65536 vm.nr_hugepages = 0 vm.nr_hugepages_mempolicy = 0 vm.nr_overcommit_hugepages = 0 vm.nr_pdflush_threads = 0 vm.numa_zonelist_order = default vm.oom_dump_tasks = 1 vm.oom_kill_allocating_task = 0 vm.overcommit_kbytes = 0 vm.overcommit_memory = 0 vm.overcommit_ratio = 50 vm.page-cluster = 3 vm.pagecache_limit_ignore_dirty = 1 vm.pagecache_limit_mb = 0 vm.panic_on_oom = 0 vm.percpu_pagelist_fraction = 0 vm.stat_interval = 1 vm.swappiness = 10 vm.user_reserve_kbytes = 8650 vm.vfs_cache_pressure = 100 vm.watermark_scale_factor = 10 vm.zone_reclaim_mode = 1 -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c1
Michal Hocko
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c2
Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c3
--- Comment #3 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c4
Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c5
--- Comment #5 from Michal Hocko
Created attachment 705801 [details] /proc/vmstat
this seems to be a single snapshot of the file. This won't help very much because I would need to see how those counters evolve over time. Could you do something like mkdir logs cd logs while true do cp /proc/vmstat vmstat.$(date +%s) sleep 1s done and note the time when the kswapd starts pegging the cpu? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c6
--- Comment #6 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c7
--- Comment #7 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c8
--- Comment #8 from Michal Hocko
Created attachment 705814 [details] experiment-1
[...]
The files in experiment-1.tgz are captured from the following sequence of events: - Leave the memory consuming daemons running, so that system memory usage is ~ 250MB/485MB. - Observe that kswapd is not using 100% CPU. - Run "zypper dup" and observe that kswapd begins consuming 100% CPU (at 1481275470) - Zypper soon finishes (no update to install), and kswapd stops consuming 100% CPU.
Yes, the only reclaim activity I can see is between base diff pgscan_kswapd_dma32 523489 9743 pgscan_kswapd_dma 20067723 233 pgsteal_kswapd_dma32 434292 6407 pgsteal_kswapd_dma 11695 129 kswapd_inodesteal 147565 382 kswapd_high_wmark_hit_quickly 16706938 34227 Apart from quite a large kswapd_high_wmark_hit_quickly nothing really suspicious here. It suggests that the kswapd wanted to go to sleep but it couldn't because there was still some work to be done.
According to the first experiment, kswapd0 does not always stay at 100% memory usage after memory is pressured. Three days ago I observed that kswapd0 stayed at 100% CPU usage even after memory pressure is relieved.
I would be interested in vmstat from those runs. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c9
--- Comment #9 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c10
--- Comment #10 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c11
--- Comment #11 from Michal Hocko
Created attachment 706892 [details] /proc/vmstat under sustained 100% kswap cpu usage
Here you are Michal. This one is collected minutes after kswap is under sustained 100% CPU usage.
this is just one snapshot of the file again which is not very helpful. I need to watch those counters over time to deduce what is going on. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c12
--- Comment #12 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c13
--- Comment #13 from Michal Hocko
Created attachment 707817 [details] vmstat over period of 30 seconds
Merry Christmas and happy new year!
The fault did not happen until earlier today. Attached tgz contains capture of vmstat file over a period of 30 seconds.
are you sure that kswapd was hogging the CPU during that time period? I do not see basically any kswapd activity during that 30s time period base diff pgscan_kswapd_normal 55 0 pgscan_kswapd_dma32 1316447 0 pgsteal_kswapd_normal 7 0 pgsteal_kswapd_dma32 1156969 0 slabs_scanned 8149055 4720 kswapd_inodesteal 1226481 4517 kswapd_high_wmark_hit_quickly 393623726 53777 So we have reclaimed some inodes, didn't scan a single LRU page. kswapd_high_wmark_hit_quickly is quite high so the kswapd was woken up quite often but didn't do anything really. The number of LRU pages is more or less stable. One reason for that might be a source of high order allocations. THP come to mind but there is activity there base diff thp_collapse_alloc_failed 2165 1 maybe there is other source of high order requests. All in all I really do not see anything that would cause kswapd to hog the CPU. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c14
--- Comment #14 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c15
--- Comment #15 from Michal Hocko
Of course kswapd was using 100% CPU, consequently a simple cp and `sleep 1` together would take 2 seconds to complete, which is why the vmstat file timestamps aren't consecutive.
this is really strange. I simply do not see thi in counters...
Should I disable THP and monitor for its occurrence?
I do not think this would help as the thp counters suggest that there is no THP activity. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c16
Vlastimil Babka
Of course kswapd was using 100% CPU, consequently a simple cp and `sleep 1` together would take 2 seconds to complete, which is why the vmstat file timestamps aren't consecutive.
You could try perf sampling to see where kswapd spends the cpu: perf record -a -g (let it run for e.g. a minute, then ctrl^c perf report -g
Should I disable THP and monitor for its occurrence?
-- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c17
--- Comment #17 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c18
--- Comment #18 from Michal Hocko
Created attachment 710593 [details] perf data
perf output is attached.
Could you attach perf report output please? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c19
--- Comment #19 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c20
--- Comment #20 from Michal Hocko
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c21
--- Comment #21 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c22
--- Comment #22 from Michal Hocko
I didn't capture vmstat files, but I don't think they'll be any different from the previously captured ones.
without that information I can hardly make a picture of what is going on here. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c23
--- Comment #23 from Howard Guo
http://bugzilla.suse.com/show_bug.cgi?id=1013629
http://bugzilla.suse.com/show_bug.cgi?id=1013629#c24
Michal Hocko
participants (1)
-
bugzilla_noreply＠novell.com