Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1585166 > unrolled thread

Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone

Started byMichal Hocko <mhocko@kernel.org>
First post2017-02-21 10:50 +0100
Last post2017-02-26 07:40 +0100
Articles 6 — 2 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages  per zone Michal Hocko <mhocko@kernel.org> - 2017-02-21 10:50 +0100
    Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> - 2017-02-21 15:40 +0100
      Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages  per zone Michal Hocko <mhocko@kernel.org> - 2017-02-21 17:00 +0100
        Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> - 2017-02-22 03:10 +0100
          Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages  per zone Michal Hocko <mhocko@kernel.org> - 2017-02-22 09:00 +0100
            Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> - 2017-02-26 07:40 +0100

#1585166 — Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone

FromMichal Hocko <mhocko@kernel.org>
Date2017-02-21 10:50 +0100
SubjectRe: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone
Message-ID<tdff4-Kd-11@gated-at.bofh.it>
On Fri 03-02-17 19:57:39, Tetsuo Handa wrote:
> Michal Hocko wrote:
> > On Mon 30-01-17 09:55:46, Michal Hocko wrote:
> > > On Sun 29-01-17 00:27:27, Tetsuo Handa wrote:
> > [...]
> > > > Regarding [1], it helped avoiding the too_many_isolated() issue. I can't
> > > > tell whether it has any negative effect, but I got on the first trial that
> > > > all allocating threads are blocked on wait_for_completion() from flush_work()
> > > > in drain_all_pages() introduced by "mm, page_alloc: drain per-cpu pages from
> > > > workqueue context". There was no warn_alloc() stall warning message afterwords.
> > > 
> > > That patch is buggy and there is a follow up [1] which is not sitting in the
> > > mmotm (and thus linux-next) yet. I didn't get to review it properly and
> > > I cannot say I would be too happy about using WQ from the page
> > > allocator. I believe even the follow up needs to have WQ_RECLAIM WQ.
> > > 
> > > [1] http://lkml.kernel.org/r/20170125083038.rzb5f43nptmk7aed@techsingularity.net
> > 
> > Did you get chance to test with this follow up patch? It would be
> > interesting to see whether OOM situation can still starve the waiter.
> > The current linux-next should contain this patch.
> 
> So far I can't reproduce problems except two listed below (cond_resched() trap
> in printk() and IDLE priority trap are excluded from the list).

OK, so it seems that all the distractions are handled now and linux-next
should provide a reasonable base for testing. You said you weren't able
to reproduce the original long stalls on too_many_isolated(). I would be
still interested to see those oom reports and potential anomalies in the
isolated counts before I send the patch for inclusion so your further
testing would be more than appreciated. Also stalls > 10s without any
previous occurrences would be interesting.

Thanks!
-- 
Michal Hocko
SUSE Labs

[toc] | [next] | [standalone]

#1585384 — Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone

FromTetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date2017-02-21 15:40 +0100
SubjectRe: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone
Message-ID<tdjLI-3P2-5@gated-at.bofh.it>
In reply to#1585166
Michal Hocko wrote:
> OK, so it seems that all the distractions are handled now and linux-next
> should provide a reasonable base for testing. You said you weren't able
> to reproduce the original long stalls on too_many_isolated(). I would be
> still interested to see those oom reports and potential anomalies in the
> isolated counts before I send the patch for inclusion so your further
> testing would be more than appreciated. Also stalls > 10s without any
> previous occurrences would be interesting.

I confirmed that linux-next-20170221 with kmallocwd applied can reproduce
infinite too_many_isolated() loop problem. Please send your patches to linux-next.

Complete log is at http://I-love.SAKURA.ne.jp/tmp/serial-20170221.txt.xz .
----------------------------------------
[ 1160.162013] Out of memory: Kill process 7523 (a.out) score 998 or sacrifice child
[ 1160.164422] Killed process 7523 (a.out) total-vm:4168kB, anon-rss:84kB, file-rss:0kB, shmem-rss:0kB
[ 1160.169699] oom_reaper: reaped process 7523 (a.out), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
[ 1209.781787] MemAlloc-Info: stalling=32 dying=1 exiting=0 victim=1 oom_count=45896
[ 1209.790966] MemAlloc: kswapd0(67) flags=0xa60840 switches=51139 uninterruptible
[ 1209.799726] kswapd0         D10936    67      2 0x00000000
[ 1209.807326] Call Trace:
[ 1209.812581]  __schedule+0x336/0xe00
[ 1209.818599]  schedule+0x3d/0x90
[ 1209.823907]  schedule_timeout+0x26a/0x510
[ 1209.827218]  ? trace_hardirqs_on+0xd/0x10
[ 1209.830535]  __down_common+0xfb/0x131
[ 1209.833801]  ? _xfs_buf_find+0x2cb/0xc10 [xfs]
[ 1209.837372]  __down+0x1d/0x1f
[ 1209.840331]  down+0x41/0x50
[ 1209.843243]  xfs_buf_lock+0x64/0x370 [xfs]
[ 1209.846597]  _xfs_buf_find+0x2cb/0xc10 [xfs]
[ 1209.850031]  ? _xfs_buf_find+0xa4/0xc10 [xfs]
[ 1209.853514]  xfs_buf_get_map+0x2a/0x480 [xfs]
[ 1209.855831]  xfs_buf_read_map+0x2c/0x400 [xfs]
[ 1209.857388]  ? free_debug_processing+0x27d/0x2af
[ 1209.859037]  xfs_trans_read_buf_map+0x186/0x830 [xfs]
[ 1209.860707]  xfs_read_agf+0xc8/0x2b0 [xfs]
[ 1209.862184]  xfs_alloc_read_agf+0x7a/0x300 [xfs]
[ 1209.863728]  ? xfs_alloc_space_available+0x7b/0x120 [xfs]
[ 1209.865385]  xfs_alloc_fix_freelist+0x3bc/0x490 [xfs]
[ 1209.866974]  ? __radix_tree_lookup+0x84/0xf0
[ 1209.868374]  ? xfs_perag_get+0x1a0/0x310 [xfs]
[ 1209.869798]  ? xfs_perag_get+0x5/0x310 [xfs]
[ 1209.871288]  xfs_alloc_vextent+0x161/0xda0 [xfs]
[ 1209.872757]  xfs_bmap_btalloc+0x46c/0x8b0 [xfs]
[ 1209.874182]  ? save_stack_trace+0x1b/0x20
[ 1209.875542]  xfs_bmap_alloc+0x17/0x30 [xfs]
[ 1209.876847]  xfs_bmapi_write+0x74e/0x11d0 [xfs]
[ 1209.878190]  xfs_iomap_write_allocate+0x199/0x3a0 [xfs]
[ 1209.879632]  xfs_map_blocks+0x2cc/0x5a0 [xfs]
[ 1209.880909]  xfs_do_writepage+0x215/0x920 [xfs]
[ 1209.882255]  ? clear_page_dirty_for_io+0xb4/0x310
[ 1209.883598]  xfs_vm_writepage+0x3b/0x70 [xfs]
[ 1209.884841]  pageout.isra.54+0x1a4/0x460
[ 1209.886210]  shrink_page_list+0xa86/0xcf0
[ 1209.887441]  shrink_inactive_list+0x1c5/0x660
[ 1209.888682]  shrink_node_memcg+0x535/0x7f0
[ 1209.889975]  ? mem_cgroup_iter+0x14d/0x720
[ 1209.891197]  shrink_node+0xe1/0x310
[ 1209.892288]  kswapd+0x362/0x9b0
[ 1209.893308]  kthread+0x10f/0x150
[ 1209.894383]  ? mem_cgroup_shrink_node+0x3b0/0x3b0
[ 1209.895703]  ? kthread_create_on_node+0x70/0x70
[ 1209.896956]  ret_from_fork+0x31/0x40
[ 1209.898117] MemAlloc: systemd-journal(526) flags=0x400900 switches=33248 seq=121659 gfp=0x14201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD) order=0 delay=52772 uninterruptible
[ 1209.902154] systemd-journal D11240   526      1 0x00000000
[ 1209.903642] Call Trace:
[ 1209.904574]  __schedule+0x336/0xe00
[ 1209.905734]  schedule+0x3d/0x90
[ 1209.906817]  schedule_timeout+0x20d/0x510
[ 1209.908025]  ? prepare_to_wait+0x2b/0xc0
[ 1209.909268]  ? lock_timer_base+0xa0/0xa0
[ 1209.910460]  io_schedule_timeout+0x1e/0x50
[ 1209.911681]  congestion_wait+0x86/0x260
[ 1209.912853]  ? remove_wait_queue+0x60/0x60
[ 1209.914115]  shrink_inactive_list+0x5b4/0x660
[ 1209.915385]  ? __list_lru_count_one.isra.2+0x22/0x80
[ 1209.916768]  shrink_node_memcg+0x535/0x7f0
[ 1209.918173]  shrink_node+0xe1/0x310
[ 1209.919288]  do_try_to_free_pages+0xe1/0x300
[ 1209.920548]  try_to_free_pages+0x131/0x3f0
[ 1209.921827]  __alloc_pages_slowpath+0x3ec/0xd95
[ 1209.923137]  __alloc_pages_nodemask+0x3e4/0x460
[ 1209.924454]  ? __radix_tree_lookup+0x84/0xf0
[ 1209.925790]  alloc_pages_current+0x97/0x1b0
[ 1209.927021]  ? find_get_entry+0x5/0x300
[ 1209.928189]  __page_cache_alloc+0x15d/0x1a0
[ 1209.929471]  ? pagecache_get_page+0x2c/0x2b0
[ 1209.930716]  filemap_fault+0x4df/0x8b0
[ 1209.931867]  ? filemap_fault+0x373/0x8b0
[ 1209.933111]  ? xfs_ilock+0x22c/0x360 [xfs]
[ 1209.934510]  ? xfs_filemap_fault+0x64/0x1e0 [xfs]
[ 1209.935857]  ? down_read_nested+0x7b/0xc0
[ 1209.937123]  ? xfs_ilock+0x22c/0x360 [xfs]
[ 1209.938373]  xfs_filemap_fault+0x6c/0x1e0 [xfs]
[ 1209.939691]  __do_fault+0x1e/0xa0
[ 1209.940807]  ? _raw_spin_unlock+0x27/0x40
[ 1209.942002]  __handle_mm_fault+0xbb1/0xf40
[ 1209.943228]  ? mutex_unlock+0x12/0x20
[ 1209.944410]  ? devkmsg_read+0x15c/0x330
[ 1209.945912]  handle_mm_fault+0x16b/0x390
[ 1209.947297]  ? handle_mm_fault+0x49/0x390
[ 1209.948868]  __do_page_fault+0x24a/0x530
[ 1209.950351]  do_page_fault+0x30/0x80
[ 1209.951615]  page_fault+0x28/0x30
[ 1209.952724] RIP: 0033:0x556f398d623f
[ 1209.953834] RSP: 002b:00007fff1da75710 EFLAGS: 00010206
[ 1209.955273] RAX: 0000556f3b12b9d0 RBX: 0000000000000009 RCX: 0000000000000020
[ 1209.957117] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 1209.958849] RBP: 00007fff1da759b0 R08: 0000000000000000 R09: 0000000000000000
[ 1209.960659] R10: 00000000ffffffc0 R11: 00007fdc0df4ef10 R12: 00007fff1da75f30
[ 1209.962397] R13: 00007fff1da78810 R14: 0000000000000009 R15: 0000000000000006
[ 1209.964204] MemAlloc: auditd(563) flags=0x400900 switches=6443 seq=774 gfp=0x142134a(GFP_NOFS|__GFP_HIGHMEM|__GFP_COLD|__GFP_NOWARN|__GFP_NORETRY|__GFP_HARDWALL|__GFP_MOVABLE) order=0 delay=16511 uninterruptible
[ 1209.969005] auditd          D12280   563      1 0x00000000
[ 1209.970503] Call Trace:
[ 1209.971436]  __schedule+0x336/0xe00
[ 1209.972621]  schedule+0x3d/0x90
[ 1209.973696]  schedule_timeout+0x20d/0x510
[ 1209.974910]  ? prepare_to_wait+0x2b/0xc0
[ 1209.976155]  ? lock_timer_base+0xa0/0xa0
[ 1209.977350]  io_schedule_timeout+0x1e/0x50
[ 1209.978597]  congestion_wait+0x86/0x260
[ 1209.979795]  ? remove_wait_queue+0x60/0x60
[ 1209.981020]  shrink_inactive_list+0x5b4/0x660
[ 1209.982290]  ? __list_lru_count_one.isra.2+0x22/0x80
[ 1209.983748]  shrink_node_memcg+0x535/0x7f0
[ 1209.985041]  ? mem_cgroup_iter+0x14d/0x720
[ 1209.986267]  shrink_node+0xe1/0x310
[ 1209.987424]  do_try_to_free_pages+0xe1/0x300
[ 1209.988705]  try_to_free_pages+0x131/0x3f0
[ 1209.989935]  __alloc_pages_slowpath+0x3ec/0xd95
[ 1209.991274]  __alloc_pages_nodemask+0x3e4/0x460
[ 1209.992601]  alloc_pages_current+0x97/0x1b0
[ 1209.993845]  __page_cache_alloc+0x15d/0x1a0
[ 1209.995120]  __do_page_cache_readahead+0x118/0x410
[ 1209.996535]  ? __do_page_cache_readahead+0x191/0x410
[ 1209.997946]  filemap_fault+0x35f/0x8b0
[ 1209.999199]  ? xfs_ilock+0x22c/0x360 [xfs]
[ 1210.000473]  ? xfs_filemap_fault+0x64/0x1e0 [xfs]
[ 1210.001843]  ? down_read_nested+0x7b/0xc0
[ 1210.003184]  ? xfs_ilock+0x22c/0x360 [xfs]
[ 1210.004471]  xfs_filemap_fault+0x6c/0x1e0 [xfs]
[ 1210.005792]  __do_fault+0x1e/0xa0
[ 1210.006925]  __handle_mm_fault+0xbb1/0xf40
[ 1210.008241]  ? ep_poll+0x2ea/0x3b0
[ 1210.009373]  handle_mm_fault+0x16b/0x390
[ 1210.010572]  ? handle_mm_fault+0x49/0x390
[ 1210.011818]  __do_page_fault+0x24a/0x530
[ 1210.013059]  ? wake_up_q+0x80/0x80
[ 1210.014176]  do_page_fault+0x30/0x80
[ 1210.015367]  page_fault+0x28/0x30
[ 1210.016473] RIP: 0033:0x7fcb0c838d13
[ 1210.017635] RSP: 002b:00007ffe275b95a0 EFLAGS: 00010293
[ 1210.019120] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007fcb0c838d13
[ 1210.020867] RDX: 0000000000000040 RSI: 0000559240b08d40 RDI: 0000000000000009
[ 1210.022769] RBP: 0000000000000000 R08: 00000000000cf8ba R09: 0000000000000001
[ 1210.024530] R10: 000000000000e95f R11: 0000000000000293 R12: 000055923fbe5e60
[ 1210.026308] R13: 0000000000000000 R14: 0000000000000000 R15: 000055923fbe5e60
[ 1210.028961] MemAlloc: vmtoolsd(723) flags=0x400900 switches=36213 seq=120979 gfp=0x14201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD) order=0 delay=52811 uninterruptible
[ 1210.032683] vmtoolsd        D11240   723      1 0x00000080
[ 1210.034316] Call Trace:
[ 1210.035340]  __schedule+0x336/0xe00
[ 1210.036444]  schedule+0x3d/0x90
[ 1210.037462]  schedule_timeout+0x20d/0x510
[ 1210.038694]  ? prepare_to_wait+0x2b/0xc0
[ 1210.039849]  ? lock_timer_base+0xa0/0xa0
[ 1210.041005]  io_schedule_timeout+0x1e/0x50
[ 1210.042435]  congestion_wait+0x86/0x260
[ 1210.043575]  ? remove_wait_queue+0x60/0x60
[ 1210.044763]  shrink_inactive_list+0x5b4/0x660
[ 1210.046058]  ? __list_lru_count_one.isra.2+0x22/0x80
[ 1210.047419]  shrink_node_memcg+0x535/0x7f0
[ 1210.048609]  shrink_node+0xe1/0x310
[ 1210.049688]  do_try_to_free_pages+0xe1/0x300
[ 1210.051183]  try_to_free_pages+0x131/0x3f0
[ 1210.052421]  __alloc_pages_slowpath+0x3ec/0xd95
[ 1210.053717]  __alloc_pages_nodemask+0x3e4/0x460
[ 1210.055025]  ? __radix_tree_lookup+0x84/0xf0
[ 1210.056264]  alloc_pages_current+0x97/0x1b0
[ 1210.057466]  ? find_get_entry+0x5/0x300
[ 1210.058695]  __page_cache_alloc+0x15d/0x1a0
[ 1210.059894]  ? pagecache_get_page+0x2c/0x2b0
[ 1210.061128]  filemap_fault+0x4df/0x8b0
[ 1210.062340]  ? filemap_fault+0x373/0x8b0
[ 1210.063545]  ? xfs_ilock+0x22c/0x360 [xfs]
[ 1210.064766]  ? xfs_filemap_fault+0x64/0x1e0 [xfs]
[ 1210.066135]  ? down_read_nested+0x7b/0xc0
[ 1210.067405]  ? xfs_ilock+0x22c/0x360 [xfs]
[ 1210.068706]  xfs_filemap_fault+0x6c/0x1e0 [xfs]
[ 1210.070021]  __do_fault+0x1e/0xa0
[ 1210.071102]  __handle_mm_fault+0xbb1/0xf40
[ 1210.072296]  handle_mm_fault+0x16b/0x390
[ 1210.073509]  ? handle_mm_fault+0x49/0x390
[ 1210.074683]  __do_page_fault+0x24a/0x530
[ 1210.075872]  do_page_fault+0x30/0x80
[ 1210.076974]  page_fault+0x28/0x30
[ 1210.078090] RIP: 0033:0x7f12e9fd6420
[ 1210.079193] RSP: 002b:00007ffee98ba498 EFLAGS: 00010202
[ 1210.080605] RAX: 00007f12de02e0fe RBX: 00007ffee98ba4b0 RCX: 00007ffee98ba590
[ 1210.082383] RDX: 00007f12de02e0fe RSI: 0000000000000001 RDI: 00007ffee98ba4b0
[ 1210.084177] RBP: 0000000000000080 R08: 0000000000000000 R09: 000000000000000a
[ 1210.086134] R10: 00007f12eb61a010 R11: 0000000000000000 R12: 0000000000000080
[ 1210.087850] R13: 0000000000000000 R14: 00007f12ea006770 R15: 00005580adf3abc0
(...snipped...)
[ 1210.640170] MemAlloc: a.out(7523) flags=0x420040 switches=90 uninterruptible dying victim
[ 1210.642426] a.out           D11496  7523   7376 0x00100084
[ 1210.643999] Call Trace:
[ 1210.644921]  __schedule+0x336/0xe00
[ 1210.646007]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[ 1210.647328]  schedule+0x3d/0x90
[ 1210.648441]  schedule_timeout+0x26a/0x510
[ 1210.649619]  ? trace_hardirqs_on+0xd/0x10
[ 1210.650792]  __down_common+0xfb/0x131
[ 1210.652188]  ? _xfs_buf_find+0x2cb/0xc10 [xfs]
[ 1210.653480]  __down+0x1d/0x1f
[ 1210.654483]  down+0x41/0x50
[ 1210.655462]  xfs_buf_lock+0x64/0x370 [xfs]
[ 1210.656618]  _xfs_buf_find+0x2cb/0xc10 [xfs]
[ 1210.657823]  ? _xfs_buf_find+0xa4/0xc10 [xfs]
[ 1210.659028]  xfs_buf_get_map+0x2a/0x480 [xfs]
[ 1210.660284]  xfs_buf_read_map+0x2c/0x400 [xfs]
[ 1210.661490]  ? del_timer_sync+0xb5/0xe0
[ 1210.662630]  xfs_trans_read_buf_map+0x186/0x830 [xfs]
[ 1210.664009]  xfs_read_agf+0xc8/0x2b0 [xfs]
[ 1210.665171]  xfs_alloc_read_agf+0x7a/0x300 [xfs]
[ 1210.666441]  ? xfs_alloc_space_available+0x7b/0x120 [xfs]
[ 1210.667923]  xfs_alloc_fix_freelist+0x3bc/0x490 [xfs]
[ 1210.669402]  ? __radix_tree_lookup+0x84/0xf0
[ 1210.670645]  ? xfs_perag_get+0x1a0/0x310 [xfs]
[ 1210.671949]  ? xfs_perag_get+0x5/0x310 [xfs]
[ 1210.673145]  xfs_alloc_vextent+0x161/0xda0 [xfs]
[ 1210.674402]  xfs_bmap_btalloc+0x46c/0x8b0 [xfs]
[ 1210.675774]  ? save_stack_trace+0x1b/0x20
[ 1210.676961]  xfs_bmap_alloc+0x17/0x30 [xfs]
[ 1210.678202]  xfs_bmapi_write+0x74e/0x11d0 [xfs]
[ 1210.679544]  xfs_iomap_write_allocate+0x199/0x3a0 [xfs]
[ 1210.680995]  xfs_map_blocks+0x2cc/0x5a0 [xfs]
[ 1210.682245]  xfs_do_writepage+0x215/0x920 [xfs]
[ 1210.683742]  ? clear_page_dirty_for_io+0xb4/0x310
[ 1210.685125]  write_cache_pages+0x2cb/0x6b0
[ 1210.686408]  ? xfs_map_blocks+0x5a0/0x5a0 [xfs]
[ 1210.687774]  ? xfs_vm_writepages+0x48/0xa0 [xfs]
[ 1210.689111]  xfs_vm_writepages+0x6b/0xa0 [xfs]
[ 1210.690529]  do_writepages+0x21/0x40
[ 1210.691680]  __filemap_fdatawrite_range+0xc6/0x100
[ 1210.693021]  filemap_write_and_wait_range+0x2d/0x70
[ 1210.694444]  xfs_file_fsync+0x8b/0x310 [xfs]
[ 1210.695728]  vfs_fsync_range+0x3d/0xb0
[ 1210.696874]  ? __do_page_fault+0x272/0x530
[ 1210.698102]  do_fsync+0x3d/0x70
[ 1210.699200]  SyS_fsync+0x10/0x20
[ 1210.700267]  do_syscall_64+0x6c/0x200
[ 1210.701498]  entry_SYSCALL64_slow_path+0x25/0x25
[ 1210.702861] RIP: 0033:0x7f504b072d30
[ 1210.704014] RSP: 002b:00007fffcb8f7898 EFLAGS: 00000246 ORIG_RAX: 000000000000004a
[ 1210.705994] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f504b072d30
[ 1210.707857] RDX: 000000000000000a RSI: 0000000000000000 RDI: 0000000000000003
[ 1210.709647] RBP: 0000000000000003 R08: 00007f504afcc938 R09: 000000000000000e
[ 1210.711632] R10: 00007fffcb8f7620 R11: 0000000000000246 R12: 0000000000400912
[ 1210.713520] R13: 00007fffcb8f79a0 R14: 0000000000000000 R15: 0000000000000000
(...snipped...)
[ 1212.195351] MemAlloc-Info: stalling=32 dying=1 exiting=0 victim=1 oom_count=45896
[ 1242.551629] MemAlloc-Info: stalling=36 dying=1 exiting=0 victim=1 oom_count=45896
(...snipped...)
[ 1245.149165] MemAlloc-Info: stalling=36 dying=1 exiting=0 victim=1 oom_count=45896
[ 1275.319189] MemAlloc-Info: stalling=40 dying=1 exiting=0 victim=1 oom_count=45896
(...snipped...)
[ 1278.241813] MemAlloc-Info: stalling=40 dying=1 exiting=0 victim=1 oom_count=45896
[ 1289.804580] sysrq: SysRq : Kill All Tasks
----------------------------------------

[toc] | [prev] | [next] | [standalone]

#1585462

FromMichal Hocko <mhocko@kernel.org>
Date2017-02-21 17:00 +0100
Message-ID<tdl19-4zS-19@gated-at.bofh.it>
In reply to#1585384
On Tue 21-02-17 23:35:07, Tetsuo Handa wrote:
> Michal Hocko wrote:
> > OK, so it seems that all the distractions are handled now and linux-next
> > should provide a reasonable base for testing. You said you weren't able
> > to reproduce the original long stalls on too_many_isolated(). I would be
> > still interested to see those oom reports and potential anomalies in the
> > isolated counts before I send the patch for inclusion so your further
> > testing would be more than appreciated. Also stalls > 10s without any
> > previous occurrences would be interesting.
> 
> I confirmed that linux-next-20170221 with kmallocwd applied can reproduce
> infinite too_many_isolated() loop problem. Please send your patches to linux-next.

So I assume that you didn't see the lockup with the patch applied and
the OOM killer has resolved the situation by killing other tasks, right?
Can I assume your Tested-by?

Thanks for your testing!
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1585864 — Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone

FromTetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date2017-02-22 03:10 +0100
SubjectRe: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone
Message-ID<tduxs-2Ly-7@gated-at.bofh.it>
In reply to#1585462
Michal Hocko wrote:
> On Tue 21-02-17 23:35:07, Tetsuo Handa wrote:
> > Michal Hocko wrote:
> > > OK, so it seems that all the distractions are handled now and linux-next
> > > should provide a reasonable base for testing. You said you weren't able
> > > to reproduce the original long stalls on too_many_isolated(). I would be
> > > still interested to see those oom reports and potential anomalies in the
> > > isolated counts before I send the patch for inclusion so your further
> > > testing would be more than appreciated. Also stalls > 10s without any
> > > previous occurrences would be interesting.
> > 
> > I confirmed that linux-next-20170221 with kmallocwd applied can reproduce
> > infinite too_many_isolated() loop problem. Please send your patches to linux-next.
> 
> So I assume that you didn't see the lockup with the patch applied and
> the OOM killer has resolved the situation by killing other tasks, right?
> Can I assume your Tested-by?

No. I tested linux-next-20170221 which does not include your patch.
I didn't test linux-next-20170221 with your patch applied. Your patch will
avoid infinite too_many_isolated() loop problem in shrink_inactive_list().
But we need to test different workloads by other people. Thus, I suggest
you to send your patches to linux-next without my testing.

> 
> Thanks for your testing!
> -- 
> Michal Hocko
> SUSE Labs
>

[toc] | [prev] | [next] | [standalone]

#1585974

FromMichal Hocko <mhocko@kernel.org>
Date2017-02-22 09:00 +0100
Message-ID<tdA09-6IQ-1@gated-at.bofh.it>
In reply to#1585864
On Wed 22-02-17 11:02:21, Tetsuo Handa wrote:
> Michal Hocko wrote:
> > On Tue 21-02-17 23:35:07, Tetsuo Handa wrote:
> > > Michal Hocko wrote:
> > > > OK, so it seems that all the distractions are handled now and linux-next
> > > > should provide a reasonable base for testing. You said you weren't able
> > > > to reproduce the original long stalls on too_many_isolated(). I would be
> > > > still interested to see those oom reports and potential anomalies in the
> > > > isolated counts before I send the patch for inclusion so your further
> > > > testing would be more than appreciated. Also stalls > 10s without any
> > > > previous occurrences would be interesting.
> > > 
> > > I confirmed that linux-next-20170221 with kmallocwd applied can reproduce
> > > infinite too_many_isolated() loop problem. Please send your patches to linux-next.
> > 
> > So I assume that you didn't see the lockup with the patch applied and
> > the OOM killer has resolved the situation by killing other tasks, right?
> > Can I assume your Tested-by?
> 
> No. I tested linux-next-20170221 which does not include your patch.
> I didn't test linux-next-20170221 with your patch applied. Your patch will
> avoid infinite too_many_isolated() loop problem in shrink_inactive_list().
> But we need to test different workloads by other people. Thus, I suggest
> you to send your patches to linux-next without my testing.

I will send the patch to Andrew later after merge window closes. It
would be really helpful, though, to see how it handles your workload
which is known to reproduce the oom starvation.
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1588282 — Re: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone

FromTetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date2017-02-26 07:40 +0100
SubjectRe: [RFC PATCH 1/2] mm, vmscan: account the number of isolated pages per zone
Message-ID<tf0EV-2Xz-5@gated-at.bofh.it>
In reply to#1585974
Michal Hocko wrote:
> On Wed 22-02-17 11:02:21, Tetsuo Handa wrote:
> > Michal Hocko wrote:
> > > On Tue 21-02-17 23:35:07, Tetsuo Handa wrote:
> > > > Michal Hocko wrote:
> > > > > OK, so it seems that all the distractions are handled now and linux-next
> > > > > should provide a reasonable base for testing. You said you weren't able
> > > > > to reproduce the original long stalls on too_many_isolated(). I would be
> > > > > still interested to see those oom reports and potential anomalies in the
> > > > > isolated counts before I send the patch for inclusion so your further
> > > > > testing would be more than appreciated. Also stalls > 10s without any
> > > > > previous occurrences would be interesting.
> > > > 
> > > > I confirmed that linux-next-20170221 with kmallocwd applied can reproduce
> > > > infinite too_many_isolated() loop problem. Please send your patches to linux-next.
> > > 
> > > So I assume that you didn't see the lockup with the patch applied and
> > > the OOM killer has resolved the situation by killing other tasks, right?
> > > Can I assume your Tested-by?
> > 
> > No. I tested linux-next-20170221 which does not include your patch.
> > I didn't test linux-next-20170221 with your patch applied. Your patch will
> > avoid infinite too_many_isolated() loop problem in shrink_inactive_list().
> > But we need to test different workloads by other people. Thus, I suggest
> > you to send your patches to linux-next without my testing.
> 
> I will send the patch to Andrew later after merge window closes. It
> would be really helpful, though, to see how it handles your workload
> which is known to reproduce the oom starvation.

I tested http://lkml.kernel.org/r/20170119112336.GN30786@dhcp22.suse.cz
on top of linux-next-20170221 with kmallocwd applied.

I did not hit too_many_isolated() loop problem. But I hit an "unable to invoke
the OOM killer due to !__GFP_FS allocation" lockup problem shown below.

Complete log is at http://I-love.SAKURA.ne.jp/tmp/serial-20170226.txt.xz .
----------
[  444.281177] Killed process 9477 (a.out) total-vm:4168kB, anon-rss:84kB, file-rss:0kB, shmem-rss:0kB
[  444.287046] oom_reaper: reaped process 9477 (a.out), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
[  484.810225] BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 38s!
[  484.812907] BUG: workqueue lockup - pool cpus=2 node=0 flags=0x0 nice=0 stuck for 41s!
[  484.815546] Showing busy workqueues and worker pools:
[  484.817595] workqueue events: flags=0x0
[  484.819456]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=3/256
[  484.821666]     pending: vmpressure_work_fn, vmstat_shepherd, vmw_fb_dirty_flush [vmwgfx]
[  484.824356]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=2/256
[  484.826582]     pending: drain_local_pages_wq BAR(9595), e1000_watchdog [e1000]
[  484.829091]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256
[  484.831325]     in-flight: 7418:rht_deferred_worker
[  484.833336]     pending: rht_deferred_worker
[  484.835346] workqueue events_long: flags=0x0
[  484.837343]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=1/256
[  484.839566]     pending: gc_worker [nf_conntrack]
[  484.841691] workqueue events_power_efficient: flags=0x80
[  484.843873]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=1/256
[  484.846103]     pending: fb_flashcursor
[  484.847928]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256
[  484.850149]     pending: neigh_periodic_work, neigh_periodic_work
[  484.852403] workqueue events_freezable_power_: flags=0x84
[  484.854534]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  484.856666]     in-flight: 27:disk_events_workfn
[  484.858621] workqueue writeback: flags=0x4e
[  484.860347]   pwq 256: cpus=0-127 flags=0x4 nice=0 active=2/256
[  484.862415]     in-flight: 8444:wb_workfn wb_workfn
[  484.864602] workqueue vmstat: flags=0xc
[  484.866291]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  484.868307]     pending: vmstat_update
[  484.869876]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256
[  484.871864]     pending: vmstat_update
[  484.874058] workqueue mpt_poll_0: flags=0x8
[  484.875698]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  484.877602]     pending: mpt_fault_reset_work [mptbase]
[  484.879502] workqueue xfs-buf/sda1: flags=0xc
[  484.881148]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/1
[  484.883011]     pending: xfs_buf_ioend_work [xfs]
[  484.884706] workqueue xfs-data/sda1: flags=0xc
[  484.886367]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=27/256 MAYDAY
[  484.888410]     in-flight: 5356:xfs_end_io [xfs], 451(RESCUER):xfs_end_io [xfs] xfs_end_io [xfs] xfs_end_io [xfs] xfs_end_io [xfs] xfs_end_io [xfs], 10498:xfs_end_io [xfs], 6386:xfs_end_io [xfs]
[  484.893483]     pending: xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs]
[  484.902636]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=21/256 MAYDAY
[  484.904848]     in-flight: 535:xfs_end_io [xfs], 7416:xfs_end_io [xfs], 7415:xfs_end_io [xfs], 65:xfs_end_io [xfs]
[  484.907863]     pending: xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs]
[  484.916767]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=4/256 MAYDAY
[  484.919024]     in-flight: 5357:xfs_end_io [xfs], 193:xfs_end_io [xfs], 52:xfs_end_io [xfs], 5358:xfs_end_io [xfs]
[  484.922143]   pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256
[  484.924291]     in-flight: 2486:xfs_end_io [xfs]
[  484.926248] workqueue xfs-reclaim/sda1: flags=0xc
[  484.928216]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  484.930362]     pending: xfs_reclaim_worker [xfs]
[  484.932312] pool 0: cpus=0 node=0 flags=0x0 nice=0 hung=0s workers=3 idle: 3 6387
[  484.934766] pool 2: cpus=1 node=0 flags=0x0 nice=0 hung=38s workers=6 manager: 19
[  484.937206] pool 4: cpus=2 node=0 flags=0x0 nice=0 hung=41s workers=6 manager: 157
[  484.939629] pool 6: cpus=3 node=0 flags=0x0 nice=0 hung=41s workers=4 manager: 10499
[  484.942303] pool 256: cpus=0-127 flags=0x4 nice=0 hung=38s workers=3 idle: 425 426
[  518.090012] MemAlloc-Info: stalling=184 dying=1 exiting=0 victim=1 oom_count=8441307
(...snipped...)
[  518.900038] MemAlloc: kswapd0(69) flags=0xa40840 switches=23883 uninterruptible
[  518.902095] kswapd0         D10776    69      2 0x00000000
[  518.903784] Call Trace:
[  518.904849]  __schedule+0x336/0xe00
[  518.906118]  schedule+0x3d/0x90
[  518.907314]  io_schedule+0x16/0x40
[  518.908622]  __xfs_iflock+0x129/0x140 [xfs]
[  518.910027]  ? autoremove_wake_function+0x60/0x60
[  518.911559]  xfs_reclaim_inode+0x162/0x440 [xfs]
[  518.913068]  xfs_reclaim_inodes_ag+0x2cf/0x4f0 [xfs]
[  518.914611]  ? xfs_reclaim_inodes_ag+0xf2/0x4f0 [xfs]
[  518.916148]  ? trace_hardirqs_on+0xd/0x10
[  518.917465]  ? try_to_wake_up+0x59/0x7a0
[  518.918758]  ? wake_up_process+0x15/0x20
[  518.920067]  xfs_reclaim_inodes_nr+0x33/0x40 [xfs]
[  518.921560]  xfs_fs_free_cached_objects+0x19/0x20 [xfs]
[  518.923114]  super_cache_scan+0x181/0x190
[  518.924435]  shrink_slab+0x29f/0x6d0
[  518.925683]  shrink_node+0x2fa/0x310
[  518.926909]  kswapd+0x362/0x9b0
[  518.928061]  kthread+0x10f/0x150
[  518.929218]  ? mem_cgroup_shrink_node+0x3b0/0x3b0
[  518.930953]  ? kthread_create_on_node+0x70/0x70
[  518.932380]  ret_from_fork+0x31/0x40
(...snipped...)
[  553.070829] MemAlloc-Info: stalling=184 dying=1 exiting=0 victim=1 oom_count=10318507
[  575.432697] BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 129s!
[  575.435276] BUG: workqueue lockup - pool cpus=2 node=0 flags=0x0 nice=0 stuck for 131s!
[  575.437863] Showing busy workqueues and worker pools:
[  575.439837] workqueue events: flags=0x0
[  575.441605]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=4/256
[  575.443717]     pending: vmpressure_work_fn, vmstat_shepherd, vmw_fb_dirty_flush [vmwgfx], check_corruption
[  575.446622]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=2/256
[  575.448763]     pending: drain_local_pages_wq BAR(9595), e1000_watchdog [e1000]
[  575.451173]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256
[  575.453323]     in-flight: 7418:rht_deferred_worker
[  575.455243]     pending: rht_deferred_worker
[  575.457100] workqueue events_long: flags=0x0
[  575.458960]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=1/256
[  575.461099]     pending: gc_worker [nf_conntrack]
[  575.463043] workqueue events_power_efficient: flags=0x80
[  575.465110]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=1/256
[  575.467252]     pending: fb_flashcursor
[  575.468966]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256
[  575.471109]     pending: neigh_periodic_work, neigh_periodic_work
[  575.473289] workqueue events_freezable_power_: flags=0x84
[  575.475378]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  575.477526]     in-flight: 27:disk_events_workfn
[  575.479489] workqueue writeback: flags=0x4e
[  575.481257]   pwq 256: cpus=0-127 flags=0x4 nice=0 active=2/256
[  575.483368]     in-flight: 8444:wb_workfn wb_workfn
[  575.485505] workqueue vmstat: flags=0xc
[  575.487196]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256
[  575.489242]     pending: vmstat_update
[  575.491403] workqueue mpt_poll_0: flags=0x8
[  575.493106]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  575.495115]     pending: mpt_fault_reset_work [mptbase]
[  575.497086] workqueue xfs-buf/sda1: flags=0xc
[  575.498764]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/1
[  575.500654]     pending: xfs_buf_ioend_work [xfs]
[  575.502372] workqueue xfs-data/sda1: flags=0xc
[  575.504024]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=27/256 MAYDAY
[  575.506060]     in-flight: 5356:xfs_end_io [xfs], 451(RESCUER):xfs_end_io [xfs] xfs_end_io [xfs] xfs_end_io [xfs] xfs_end_io [xfs] xfs_end_io [xfs], 10498:xfs_end_io [xfs], 6386:xfs_end_io [xfs]
[  575.511096]     pending: xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs]
[  575.520157]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=21/256 MAYDAY
[  575.522340]     in-flight: 535:xfs_end_io [xfs], 7416:xfs_end_io [xfs], 7415:xfs_end_io [xfs], 65:xfs_end_io [xfs]
[  575.525387]     pending: xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs], xfs_end_io [xfs]
[  575.534089]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=4/256 MAYDAY
[  575.536407]     in-flight: 5357:xfs_end_io [xfs], 193:xfs_end_io [xfs], 52:xfs_end_io [xfs], 5358:xfs_end_io [xfs]
[  575.539496]   pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256
[  575.541648]     in-flight: 2486:xfs_end_io [xfs]
[  575.543591] workqueue xfs-reclaim/sda1: flags=0xc
[  575.545540]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
[  575.547675]     pending: xfs_reclaim_worker [xfs]
[  575.549719] workqueue xfs-log/sda1: flags=0x1c
[  575.551591]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=1/256
[  575.553750]     pending: xfs_log_worker [xfs]
[  575.555552] pool 0: cpus=0 node=0 flags=0x0 nice=0 hung=0s workers=3 idle: 3 6387
[  575.557979] pool 2: cpus=1 node=0 flags=0x0 nice=0 hung=129s workers=6 manager: 19
[  575.560399] pool 4: cpus=2 node=0 flags=0x0 nice=0 hung=131s workers=6 manager: 157
[  575.562843] pool 6: cpus=3 node=0 flags=0x0 nice=0 hung=132s workers=4 manager: 10499
[  575.565450] pool 256: cpus=0-127 flags=0x4 nice=0 hung=129s workers=3 idle: 425 426
(...snipped...)
[  616.394649] MemAlloc-Info: stalling=186 dying=1 exiting=0 victim=1 oom_count=13908219
(...snipped...)
[  642.266252] MemAlloc-Info: stalling=186 dying=1 exiting=0 victim=1 oom_count=15180673
(...snipped...)
[  702.412189] MemAlloc-Info: stalling=187 dying=1 exiting=0 victim=1 oom_count=18732529
(...snipped...)
[  736.787879] MemAlloc-Info: stalling=187 dying=1 exiting=0 victim=1 oom_count=20565244
(...snipped...)
[  800.715759] MemAlloc-Info: stalling=188 dying=1 exiting=0 victim=1 oom_count=24411576
(...snipped...)
[  837.571405] MemAlloc-Info: stalling=188 dying=1 exiting=0 victim=1 oom_count=26463562
(...snipped...)
[  899.021495] MemAlloc-Info: stalling=189 dying=1 exiting=0 victim=1 oom_count=30144879
(...snipped...)
[  936.282709] MemAlloc-Info: stalling=189 dying=1 exiting=0 victim=1 oom_count=32129234
(...snipped...)
[  997.328119] MemAlloc-Info: stalling=190 dying=1 exiting=0 victim=1 oom_count=35657983
(...snipped...)
[ 1033.977265] MemAlloc-Info: stalling=190 dying=1 exiting=0 victim=1 oom_count=37659912
(...snipped...)
[ 1095.630961] MemAlloc-Info: stalling=190 dying=1 exiting=0 victim=1 oom_count=40639677
(...snipped...)
[ 1095.632984] MemAlloc: kswapd0(69) flags=0xa40840 switches=23883 uninterruptible
[ 1095.632985] kswapd0         D10776    69      2 0x00000000
[ 1095.632988] Call Trace:
[ 1095.632991]  __schedule+0x336/0xe00
[ 1095.632994]  schedule+0x3d/0x90
[ 1095.632996]  io_schedule+0x16/0x40
[ 1095.633017]  __xfs_iflock+0x129/0x140 [xfs]
[ 1095.633021]  ? autoremove_wake_function+0x60/0x60
[ 1095.633051]  xfs_reclaim_inode+0x162/0x440 [xfs]
[ 1095.633072]  xfs_reclaim_inodes_ag+0x2cf/0x4f0 [xfs]
[ 1095.633106]  ? xfs_reclaim_inodes_ag+0xf2/0x4f0 [xfs]
[ 1095.633114]  ? trace_hardirqs_on+0xd/0x10
[ 1095.633116]  ? try_to_wake_up+0x59/0x7a0
[ 1095.633120]  ? wake_up_process+0x15/0x20
[ 1095.633156]  xfs_reclaim_inodes_nr+0x33/0x40 [xfs]
[ 1095.633178]  xfs_fs_free_cached_objects+0x19/0x20 [xfs]
[ 1095.633180]  super_cache_scan+0x181/0x190
[ 1095.633183]  shrink_slab+0x29f/0x6d0
[ 1095.633189]  shrink_node+0x2fa/0x310
[ 1095.633193]  kswapd+0x362/0x9b0
[ 1095.633200]  kthread+0x10f/0x150
[ 1095.633201]  ? mem_cgroup_shrink_node+0x3b0/0x3b0
[ 1095.633202]  ? kthread_create_on_node+0x70/0x70
[ 1095.633205]  ret_from_fork+0x31/0x40
(...snipped...)
[ 1095.821248] MemAlloc-Info: stalling=190 dying=1 exiting=0 victim=1 oom_count=40646791
(...snipped...)
[ 1125.236970] sysrq: SysRq : Resetting
[ 1125.238669] ACPI MEMORY or I/O RESET_REG.
----------

The switches= value (which is "struct task_struct"->nvcsw +
"struct task_struct"->nivcsw ) of kswapd0(69) remained 23883 which means that
kswapd0 was waiting forever at

----------
void
__xfs_iflock(
        struct xfs_inode        *ip)
{
        wait_queue_head_t *wq = bit_waitqueue(&ip->i_flags, __XFS_IFLOCK_BIT);
        DEFINE_WAIT_BIT(wait, &ip->i_flags, __XFS_IFLOCK_BIT);

        do {
                prepare_to_wait_exclusive(wq, &wait.wait, TASK_UNINTERRUPTIBLE);
                if (xfs_isiflocked(ip))
                        io_schedule();      /***** <= This location. *****/
        } while (!xfs_iflock_nowait(ip));

        finish_wait(wq, &wait.wait);
}
----------

while the oom_count= value (which is number of times out_of_memory() was called)
was increasing over time without emitting "Killed process " message.

Reproducer I used is shown below.

----------
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <signal.h>
#include <poll.h>

static char use_delay = 0;

static void sigcld_handler(int unused)
{
        use_delay = 1;
}

int main(int argc, char *argv[])
{
        static char buffer[4096] = { };
        char *buf = NULL;
        unsigned long size;
        int i;
        signal(SIGCLD, sigcld_handler);
        for (i = 0; i < 1024; i++) {
                if (fork() == 0) {
                        int fd = open("/proc/self/oom_score_adj", O_WRONLY);
                        write(fd, "1000", 4);
                        close(fd);
                        sleep(1);
                        if (!i)
                                pause();
                        snprintf(buffer, sizeof(buffer), "/tmp/file.%u", getpid());
                        fd = open(buffer, O_WRONLY | O_CREAT | O_APPEND, 0600);
                        while (write(fd, buffer, sizeof(buffer)) == sizeof(buffer)) {
                                poll(NULL, 0, 10);
                                fsync(fd);
                        }
                        _exit(0);
                }
        }
        for (size = 1048576; size < 512UL * (1 << 30); size <<= 1) {
                char *cp = realloc(buf, size);
                if (!cp) {
                        size >>= 1;
                        break;
                }
                buf = cp;
        }
        sleep(2);
        /* Will cause OOM due to overcommit */
        for (i = 0; i < size; i += 4096)
                buf[i] = 0;
        pause();
        return 0;
}
----------

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web