Re: 4.11.0-rc8+/x86_64 desktop lockup until applications closed

From: Michal Hocko
Date: Thu Apr 27 2017 - 05:26:54 EST


On Thu 27-04-17 18:36:38, Arthur Marsh wrote:
[...]
> [55363.482931] QXcbEventReader: page allocation stalls for 10048ms, order:0,
> mode:0x14200ca(GFP_HIGHUSER_MOVABLE), nodemask=(null)

Are there more of these stalls?

[...]
> [55363.483040] Mem-Info:
> [55363.483044] active_anon:1479559 inactive_anon:281161 isolated_anon:299
> active_file:49213 inactive_file:42134 isolated_file:0
> unevictable:4651 dirty:108 writeback:188 unstable:0
> slab_reclaimable:11225 slab_unreclaimable:20186
> mapped:204768 shmem:145888 pagetables:39859 bounce:0
> free:25470 free_pcp:0 free_cma:0

There is still quite some page cache to reclaim on the inactive list. So
a progress should have been made. Maybe there was a peak memory
consumption which holded this request back?

[...]
> [55363.483059] Node 0 DMA32 free:45556kB min:26948kB low:33684kB
> high:40420kB active_anon:2273532kB inactive_anon:542768kB
> active_file:99788kB inactive_file:89940kB unevictable:32kB
> writepending:440kB present:3391168kB managed:3314260kB mlocked:32kB
> slab_reclaimable:8800kB slab_unreclaimable:25976kB kernel_stack:7992kB
> pagetables:68028kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
> [55363.483063] lowmem_reserve[]: 0 0 4734 4734

This zone is not usable due to lowmem_reserve

> [55363.483066] Node 0 Normal free:40420kB min:40500kB low:50624kB
> high:60748kB active_anon:3644668kB inactive_anon:581672kB
> active_file:97068kB inactive_file:78784kB unevictable:18572kB
> writepending:0kB present:4980736kB managed:4848692kB mlocked:18572kB
> slab_reclaimable:36100kB slab_unreclaimable:54768kB kernel_stack:13544kB
> pagetables:91408kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
> [55363.483069] lowmem_reserve[]: 0 0 0 0

and this one is below min watermark already.

> [55363.483106] Free swap = 498568kB
> [55363.483107] Total swap = 4194288kB

Still ~10% of swap is free so not entirely bad.

The question is whether this is reproducible. If yes then I would
suggest watching /proc/vmstat (every second) and if this doesn't show
anything then try to collect vmscan tracepoints

$ mount -t tracefs none /debug/trace/
$ echo 1 > /debug/trace/events/vmscan/enable
$ cat /debug/trace/trace_pipe > log

--
Michal Hocko
SUSE Labs