Re: How to favor memory allocations for WQ_MEM_RECLAIM threads?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Tue, Mar 07, 2017 at 01:08:24AM +0900, Tetsuo Handa wrote:
> Brian Foster wrote:
> > As noted in my previous reply, I'm not sure there's enough here to point
> > at allocation failure as the root cause. E.g., kswapd is stuck here:
> > 
> > [ 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
> > 
> > ... which is waiting on an inode flush lock. It can't get the lock
> > (presumably) because xfsaild has it:
> > 
> > [ 1041.772095] xfsaild/sda1    D13216   457      2 0x00000000
> > [ 1041.773726] Call Trace:
> > [ 1041.774734]  __schedule+0x336/0xe00
> > [ 1041.775956]  schedule+0x3d/0x90
> > [ 1041.777105]  schedule_timeout+0x26a/0x510
> > [ 1041.778426]  ? wait_for_completion+0x4c/0x190
> > [ 1041.779824]  wait_for_completion+0x12c/0x190
> > [ 1041.781273]  ? wake_up_q+0x80/0x80
> > [ 1041.782597]  ? _xfs_buf_read+0x44/0x90 [xfs]
> > [ 1041.784086]  xfs_buf_submit_wait+0xe9/0x5c0 [xfs]
> > [ 1041.785659]  _xfs_buf_read+0x44/0x90 [xfs]
> > [ 1041.787067]  xfs_buf_read_map+0xfa/0x400 [xfs]
> > [ 1041.788501]  ? xfs_trans_read_buf_map+0x186/0x830 [xfs]
> > [ 1041.790103]  xfs_trans_read_buf_map+0x186/0x830 [xfs]
> > [ 1041.791672]  xfs_imap_to_bp+0x71/0x110 [xfs]
> > [ 1041.793090]  xfs_iflush+0x122/0x3b0 [xfs]
> > [ 1041.794444]  xfs_inode_item_push+0x108/0x1c0 [xfs]
> > [ 1041.795956]  xfsaild_push+0x1d8/0xb70 [xfs]
> > [ 1041.797344]  xfsaild+0x150/0x270 [xfs]
> > [ 1041.798623]  kthread+0x10f/0x150
> > [ 1041.799819]  ? xfsaild_push+0xb70/0xb70 [xfs]
> > [ 1041.801217]  ? kthread_create_on_node+0x70/0x70
> > [ 1041.802652]  ret_from_fork+0x31/0x40
> > 
> > xfsaild is flushing an inode, but is waiting on a read of the underlying
> > inode cluster buffer such that it can flush out the in-core inode data
> > structure. I cannot tell if the read had actually completed and is
> > blocked somewhere else before running the completion. As Dave notes
> > earlier, buffer I/O completion relies on the xfs-buf wq. What is evident
> > from the logs is that xfs-buf has a rescuer thread that is sitting idle:
> > 
> > [ 1041.555227] xfs-buf/sda1    S14904   450      2 0x00000000
> > [ 1041.556813] Call Trace:
> > [ 1041.557796]  __schedule+0x336/0xe00
> > [ 1041.558983]  schedule+0x3d/0x90
> > [ 1041.560085]  rescuer_thread+0x322/0x3d0
> > [ 1041.561333]  kthread+0x10f/0x150
> > [ 1041.562464]  ? worker_thread+0x4b0/0x4b0
> > [ 1041.563732]  ? kthread_create_on_node+0x70/0x70
> > [ 1041.565123]  ret_from_fork+0x31/0x40
> > 
> > So AFAICT if the buffer I/O completion would run, it would allow xfsaild
> > to progress, which would eventually flush the underlying buffer, write
> > it, release the flush lock and allow kswapd to continue. The question is
> > has the actually I/O completed? If so, is the xfs-buf workqueue stuck
> > (waiting on an allocation perhaps)? And if that is the case, why is the
> > xfs-buf rescuer thread not doing anything?
> 
> [ 1116.803780] workqueue xfs-data/sda1: flags=0xc
> [ 1116.805324]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=27/256 MAYDAY
> [ 1116.807272]     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]
> [ 1116.812145]     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]
> [ 1116.820988]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=21/256 MAYDAY
> [ 1116.823105]     in-flight: 535:xfs_end_io [xfs], 7416:xfs_end_io [xfs], 7415:xfs_end_io [xfs], 65:xfs_end_io [xfs]
> [ 1116.826062]     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]
> [ 1116.834549]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=4/256 MAYDAY
> [ 1116.837139]     in-flight: 5357:xfs_end_io [xfs], 193:xfs_end_io [xfs], 52:xfs_end_io [xfs], 5358:xfs_end_io [xfs]
> [ 1116.840182]   pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256
> [ 1116.842297]     in-flight: 2486:xfs_end_io [xfs]
> [ 1116.844230] workqueue xfs-reclaim/sda1: flags=0xc
> [ 1116.846168]   pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256
> [ 1116.848323]     pending: xfs_reclaim_worker [xfs]
> [ 1116.850280] workqueue xfs-eofblocks/sda1: flags=0xc
> [ 1116.852358]   pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=1/256
> [ 1116.854601]     in-flight: 456(RESCUER):xfs_eofblocks_worker [xfs]
> 
> As listed below, all in-flight workqueues for processing xfs_end_io (PID = 5356,
> 451(RESCUER), 10498, 6386, 535, 7416, 7415, 65, 5357, 193, 52, 5358, 2486) are
> stuck at memory allocation, and thus cannot call complete() when xfsaild/sda1
> (PID = 457) is waiting at wait_for_completion(&bp->b_iowait) in xfs_buf_submit_wait().
> 

These are all in xfs_end_io(), which means they are either the xfs-data
or xfs-conv workqueues. ->b_iowait is ultimately triggered via
xfs_buf_ioend() by the xfs-buf workqueue (or xfs-log for log buffers).
None of the following use xfs-buf.

Brian

> [ 1095.644936] MemAlloc: kworker/3:3(5356) flags=0x4228860 switches=29192 seq=6 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652086
> [ 1095.644937] kworker/3:3     R  running task    12760  5356      2 0x00000080
> [ 1095.644959] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.644960] Call Trace:
> [ 1095.644962]  __schedule+0x336/0xe00
> [ 1095.644965]  preempt_schedule_common+0x1f/0x31
> [ 1095.644966]  _cond_resched+0x1c/0x30
> [ 1095.644968]  shrink_slab+0x339/0x6d0
> [ 1095.644973]  shrink_node+0x2fa/0x310
> [ 1095.644977]  do_try_to_free_pages+0xe1/0x300
> [ 1095.644979]  try_to_free_pages+0x131/0x3f0
> [ 1095.644984]  __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.644985]  ? cpuacct_charge+0xf3/0x1e0
> [ 1095.644986]  ? cpuacct_charge+0x38/0x1e0
> [ 1095.644992]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.644995]  alloc_pages_current+0x97/0x1b0
> [ 1095.644998]  new_slab+0x4cb/0x6b0
> [ 1095.645001]  ___slab_alloc+0x3a3/0x620
> [ 1095.645023]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645026]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.645027]  ? trace_hardirqs_on+0xd/0x10
> [ 1095.645058]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645066]  __slab_alloc+0x46/0x7d
> [ 1095.645069]  __kmalloc+0x301/0x3b0
> [ 1095.645088]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645089]  ? kfree+0x1fa/0x330
> [ 1095.645110]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.645132]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.645151]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.645169]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.645188]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.645204]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.645221]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.645223]  process_one_work+0x22b/0x760
> [ 1095.645224]  ? process_one_work+0x194/0x760
> [ 1095.645228]  worker_thread+0x137/0x4b0
> [ 1095.645231]  kthread+0x10f/0x150
> [ 1095.645232]  ? process_one_work+0x760/0x760
> [ 1095.645233]  ? kthread_create_on_node+0x70/0x70
> [ 1095.645236]  ret_from_fork+0x31/0x40
> 
> [ 1095.633625] MemAlloc: xfs-data/sda1(451) flags=0x4228060 switches=45509 seq=1 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652073
> [ 1095.633626] xfs-data/sda1   R  running task    12696   451      2 0x00000000
> [ 1095.633663] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.633665] Call Trace:
> [ 1095.633668]  __schedule+0x336/0xe00
> [ 1095.633671]  schedule+0x3d/0x90
> [ 1095.633672]  schedule_timeout+0x20d/0x510
> [ 1095.633675]  ? lock_timer_base+0xa0/0xa0
> [ 1095.633678]  schedule_timeout_uninterruptible+0x2a/0x30
> [ 1095.633680]  __alloc_pages_slowpath+0x2b5/0xd95
> [ 1095.633687]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.633699]  alloc_pages_current+0x97/0x1b0
> [ 1095.633702]  new_slab+0x4cb/0x6b0
> [ 1095.633706]  ___slab_alloc+0x3a3/0x620
> [ 1095.633728]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.633730]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.633732]  ? cpuacct_charge+0x38/0x1e0
> [ 1095.633767]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.633770]  __slab_alloc+0x46/0x7d
> [ 1095.633773]  __kmalloc+0x301/0x3b0
> [ 1095.633802]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.633804]  ? kfree+0x1fa/0x330
> [ 1095.633842]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.633864]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.633883]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.633901]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.633936]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.633954]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.633971]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.633973]  process_one_work+0x22b/0x760
> [ 1095.633975]  ? process_one_work+0x194/0x760
> [ 1095.633997]  rescuer_thread+0x1f2/0x3d0
> [ 1095.634002]  kthread+0x10f/0x150
> [ 1095.634003]  ? worker_thread+0x4b0/0x4b0
> [ 1095.634004]  ? kthread_create_on_node+0x70/0x70
> [ 1095.634007]  ret_from_fork+0x31/0x40
> 
> [ 1095.806606] MemAlloc: kworker/3:0(10498) flags=0x4228060 switches=16222 seq=1 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652087
> [ 1095.806607] kworker/3:0     R  running task    11352 10498      2 0x00000080
> [ 1095.806631] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.806633] Call Trace:
> [ 1095.806636]  __schedule+0x336/0xe00
> [ 1095.806640]  schedule+0x3d/0x90
> [ 1095.806641]  schedule_timeout+0x20d/0x510
> [ 1095.806644]  ? lock_timer_base+0xa0/0xa0
> [ 1095.806649]  schedule_timeout_uninterruptible+0x2a/0x30
> [ 1095.806651]  __alloc_pages_slowpath+0x2b5/0xd95
> [ 1095.806652]  ? cpuacct_charge+0xf3/0x1e0
> [ 1095.806654]  ? cpuacct_charge+0x38/0x1e0
> [ 1095.806663]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.806667]  alloc_pages_current+0x97/0x1b0
> [ 1095.806671]  new_slab+0x4cb/0x6b0
> [ 1095.806675]  ___slab_alloc+0x3a3/0x620
> [ 1095.806698]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.806701]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.806721]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.806724]  __slab_alloc+0x46/0x7d
> [ 1095.806727]  __kmalloc+0x301/0x3b0
> [ 1095.806747]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.806749]  ? kfree+0x1fa/0x330
> [ 1095.806771]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.806794]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.806813]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.806832]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.806852]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.806868]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.806886]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.806889]  process_one_work+0x22b/0x760
> [ 1095.806890]  ? process_one_work+0x194/0x760
> [ 1095.806896]  worker_thread+0x137/0x4b0
> [ 1095.806899]  kthread+0x10f/0x150
> [ 1095.806901]  ? process_one_work+0x760/0x760
> [ 1095.806902]  ? kthread_create_on_node+0x70/0x70
> [ 1095.806904]  ? do_syscall_64+0x195/0x200
> [ 1095.806906]  ret_from_fork+0x31/0x40
> 
> [ 1095.647293] MemAlloc: kworker/3:5(6386) flags=0x4228860 switches=43427 seq=15 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652087
> [ 1095.647294] kworker/3:5     R  running task    11048  6386      2 0x00000080
> [ 1095.647754] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.648203] Call Trace:
> [ 1095.648207]  __schedule+0x336/0xe00
> [ 1095.648504]  preempt_schedule_common+0x1f/0x31
> [ 1095.648806]  _cond_resched+0x1c/0x30
> [ 1095.648952]  shrink_slab+0x339/0x6d0
> [ 1095.649252]  shrink_node+0x2fa/0x310
> [ 1095.649694]  do_try_to_free_pages+0xe1/0x300
> [ 1095.649699]  try_to_free_pages+0x131/0x3f0
> [ 1095.649996]  __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.650296]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.650743]  alloc_pages_current+0x97/0x1b0
> [ 1095.650892]  new_slab+0x4cb/0x6b0
> [ 1095.651193]  ___slab_alloc+0x3a3/0x620
> [ 1095.652087]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.652400]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.653457]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.653901]  __slab_alloc+0x46/0x7d
> [ 1095.654050]  __kmalloc+0x301/0x3b0
> [ 1095.654948]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.655396]  ? kfree+0x1fa/0x330
> [ 1095.656589]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.656919]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.656941]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.656961]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.658006]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.659053]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.660098]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.660846]  process_one_work+0x22b/0x760
> [ 1095.660994]  ? process_one_work+0x194/0x760
> [ 1095.661292]  worker_thread+0x137/0x4b0
> [ 1095.661439]  kthread+0x10f/0x150
> [ 1095.661741]  ? process_one_work+0x760/0x760
> [ 1095.661743]  ? kthread_create_on_node+0x70/0x70
> [ 1095.661891]  ret_from_fork+0x31/0x40
> 
> [ 1095.635223] MemAlloc: kworker/2:3(535) flags=0x4228860 switches=49285 seq=57 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652084
> [ 1095.635224] kworker/2:3     R  running task    12272   535      2 0x00000000
> [ 1095.635246] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.635247] Call Trace:
> [ 1095.635250]  __schedule+0x336/0xe00
> [ 1095.635253]  preempt_schedule_common+0x1f/0x31
> [ 1095.635254]  _cond_resched+0x1c/0x30
> [ 1095.635256]  shrink_slab+0x339/0x6d0
> [ 1095.635263]  shrink_node+0x2fa/0x310
> [ 1095.635267]  do_try_to_free_pages+0xe1/0x300
> [ 1095.635271]  try_to_free_pages+0x131/0x3f0
> [ 1095.635293]  __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.635301]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.635305]  alloc_pages_current+0x97/0x1b0
> [ 1095.635308]  new_slab+0x4cb/0x6b0
> [ 1095.635312]  ___slab_alloc+0x3a3/0x620
> [ 1095.635351]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.635355]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.635375]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.635377]  __slab_alloc+0x46/0x7d
> [ 1095.635380]  __kmalloc+0x301/0x3b0
> [ 1095.635399]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.635400]  ? kfree+0x1fa/0x330
> [ 1095.635421]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.635460]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.635494]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.635529]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.635549]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.635566]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.635583]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.635586]  process_one_work+0x22b/0x760
> [ 1095.635587]  ? process_one_work+0x194/0x760
> [ 1095.635591]  worker_thread+0x137/0x4b0
> [ 1095.635594]  kthread+0x10f/0x150
> [ 1095.635595]  ? process_one_work+0x760/0x760
> [ 1095.635596]  ? kthread_create_on_node+0x70/0x70
> [ 1095.635598]  ret_from_fork+0x31/0x40
> 
> [ 1095.663708] MemAlloc: kworker/2:5(7416) flags=0x4228060 switches=22830 seq=2 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652069 uninterruptible
> [ 1095.663708] kworker/2:5     D12272  7416      2 0x00000080
> [ 1095.663738] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.663740] Call Trace:
> [ 1095.663743]  __schedule+0x336/0xe00
> [ 1095.663746]  schedule+0x3d/0x90
> [ 1095.663747]  schedule_timeout+0x20d/0x510
> [ 1095.663749]  ? lock_timer_base+0xa0/0xa0
> [ 1095.663753]  schedule_timeout_uninterruptible+0x2a/0x30
> [ 1095.663755]  __alloc_pages_slowpath+0x2b5/0xd95
> [ 1095.663761]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.663765]  alloc_pages_current+0x97/0x1b0
> [ 1095.663768]  new_slab+0x4cb/0x6b0
> [ 1095.663771]  ___slab_alloc+0x3a3/0x620
> [ 1095.663793]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.663795]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.663815]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.663817]  __slab_alloc+0x46/0x7d
> [ 1095.663820]  __kmalloc+0x301/0x3b0
> [ 1095.663859]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.663861]  ? kfree+0x1fa/0x330
> [ 1095.663883]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.663905]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.663924]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.663942]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.663961]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.663996]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.664015]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.664017]  process_one_work+0x22b/0x760
> [ 1095.664018]  ? process_one_work+0x194/0x760
> [ 1095.664022]  worker_thread+0x137/0x4b0
> [ 1095.664025]  kthread+0x10f/0x150
> [ 1095.664026]  ? process_one_work+0x760/0x760
> [ 1095.664027]  ? kthread_create_on_node+0x70/0x70
> [ 1095.664030]  ret_from_fork+0x31/0x40
> 
> [ 1095.663334] MemAlloc: kworker/2:4(7415) flags=0x4228060 switches=23221 seq=2 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652078 uninterruptible
> [ 1095.663335] kworker/2:4     D11496  7415      2 0x00000080
> [ 1095.663361] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.663362] Call Trace:
> [ 1095.663366]  __schedule+0x336/0xe00
> [ 1095.663369]  schedule+0x3d/0x90
> [ 1095.663371]  schedule_timeout+0x20d/0x510
> [ 1095.663407]  ? lock_timer_base+0xa0/0xa0
> [ 1095.663412]  schedule_timeout_uninterruptible+0x2a/0x30
> [ 1095.663414]  __alloc_pages_slowpath+0x2b5/0xd95
> [ 1095.663421]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.663425]  alloc_pages_current+0x97/0x1b0
> [ 1095.663428]  new_slab+0x4cb/0x6b0
> [ 1095.663431]  ___slab_alloc+0x3a3/0x620
> [ 1095.663457]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.663459]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.663481]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.663483]  __slab_alloc+0x46/0x7d
> [ 1095.663485]  __kmalloc+0x301/0x3b0
> [ 1095.663505]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.663507]  ? kfree+0x1fa/0x330
> [ 1095.663548]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.663572]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.663591]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.663611]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.663630]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.663647]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.663664]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.663667]  process_one_work+0x22b/0x760
> [ 1095.663668]  ? process_one_work+0x194/0x760
> [ 1095.663672]  worker_thread+0x137/0x4b0
> [ 1095.663674]  kthread+0x10f/0x150
> [ 1095.663676]  ? process_one_work+0x760/0x760
> [ 1095.663696]  ? kthread_create_on_node+0x70/0x70
> [ 1095.663699]  ? do_syscall_64+0x195/0x200
> [ 1095.663701]  ret_from_fork+0x31/0x40
> 
> [ 1095.632604] MemAlloc: kworker/2:1(65) flags=0x4228060 switches=22879 seq=2 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652043
> [ 1095.632604] kworker/2:1     R  running task    12184    65      2 0x00000000
> [ 1095.632641] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.632642] Call Trace:
> [ 1095.632646]  __schedule+0x336/0xe00
> [ 1095.632649]  schedule+0x3d/0x90
> [ 1095.632651]  schedule_timeout+0x20d/0x510
> [ 1095.632654]  ? lock_timer_base+0xa0/0xa0
> [ 1095.632658]  schedule_timeout_uninterruptible+0x2a/0x30
> [ 1095.632660]  __alloc_pages_slowpath+0x2b5/0xd95
> [ 1095.632668]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.632672]  alloc_pages_current+0x97/0x1b0
> [ 1095.632675]  new_slab+0x4cb/0x6b0
> [ 1095.632678]  ___slab_alloc+0x3a3/0x620
> [ 1095.632700]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.632702]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.632704]  ? free_debug_processing+0x27d/0x2af
> [ 1095.632723]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.632725]  __slab_alloc+0x46/0x7d
> [ 1095.632728]  __kmalloc+0x301/0x3b0
> [ 1095.632765]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.632767]  ? kfree+0x1fa/0x330
> [ 1095.632804]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.632828]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.632847]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.632865]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.632884]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.632916]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.632935]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.632938]  process_one_work+0x22b/0x760
> [ 1095.632939]  ? process_one_work+0x194/0x760
> [ 1095.632944]  worker_thread+0x137/0x4b0
> [ 1095.632947]  kthread+0x10f/0x150
> [ 1095.632949]  ? process_one_work+0x760/0x760
> [ 1095.632960]  ? kthread_create_on_node+0x70/0x70
> [ 1095.632963]  ret_from_fork+0x31/0x40
> 
> [ 1095.645241] MemAlloc: kworker/1:3(5357) flags=0x4228860 switches=30893 seq=3 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652084
> [ 1095.645242] kworker/1:3     R  running task    12184  5357      2 0x00000080
> [ 1095.645261] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.645262] Call Trace:
> [ 1095.645263]  ? shrink_node+0x2fa/0x310
> [ 1095.645267]  ? do_try_to_free_pages+0xe1/0x300
> [ 1095.645270]  ? try_to_free_pages+0x131/0x3f0
> [ 1095.645274]  ? __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.645280]  ? __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.645283]  ? alloc_pages_current+0x97/0x1b0
> [ 1095.645286]  ? new_slab+0x4cb/0x6b0
> [ 1095.645289]  ? ___slab_alloc+0x3a3/0x620
> [ 1095.645310]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645312]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.645331]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645333]  ? __slab_alloc+0x46/0x7d
> [ 1095.645335]  ? __kmalloc+0x301/0x3b0
> [ 1095.645355]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645356]  ? kfree+0x1fa/0x330
> [ 1095.645377]  ? xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.645398]  ? __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.645417]  ? xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.645435]  ? __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.645453]  ? xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.645470]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.645486]  ? xfs_end_io+0x81/0x110 [xfs]
> [ 1095.645489]  ? process_one_work+0x22b/0x760
> [ 1095.645490]  ? process_one_work+0x194/0x760
> [ 1095.645493]  ? worker_thread+0x137/0x4b0
> [ 1095.645496]  ? kthread+0x10f/0x150
> [ 1095.645497]  ? process_one_work+0x760/0x760
> [ 1095.645498]  ? kthread_create_on_node+0x70/0x70
> [ 1095.645501]  ? ret_from_fork+0x31/0x40
> 
> [ 1095.633213] MemAlloc: kworker/1:2(193) flags=0x4228860 switches=28494 seq=1 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652084
> [ 1095.633213] kworker/1:2     R  running task    12760   193      2 0x00000000
> [ 1095.633236] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.633237] Call Trace:
> [ 1095.633240]  __schedule+0x336/0xe00
> [ 1095.633260]  preempt_schedule_common+0x1f/0x31
> [ 1095.633261]  _cond_resched+0x1c/0x30
> [ 1095.633263]  shrink_slab+0x339/0x6d0
> [ 1095.633270]  shrink_node+0x2fa/0x310
> [ 1095.633275]  do_try_to_free_pages+0xe1/0x300
> [ 1095.633278]  try_to_free_pages+0x131/0x3f0
> [ 1095.633283]  __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.633292]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.633295]  alloc_pages_current+0x97/0x1b0
> [ 1095.633298]  new_slab+0x4cb/0x6b0
> [ 1095.633318]  ___slab_alloc+0x3a3/0x620
> [ 1095.633349]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.633353]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.633373]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.633375]  __slab_alloc+0x46/0x7d
> [ 1095.633378]  __kmalloc+0x301/0x3b0
> [ 1095.633397]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.633398]  ? kfree+0x1fa/0x330
> [ 1095.633436]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.633464]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.633500]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.633520]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.633538]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.633555]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.633572]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.633575]  process_one_work+0x22b/0x760
> [ 1095.633576]  ? process_one_work+0x194/0x760
> [ 1095.633597]  worker_thread+0x137/0x4b0
> [ 1095.633602]  kthread+0x10f/0x150
> [ 1095.633603]  ? process_one_work+0x760/0x760
> [ 1095.633604]  ? kthread_create_on_node+0x70/0x70
> [ 1095.633607]  ret_from_fork+0x31/0x40
> 
> [ 1095.632186] MemAlloc: kworker/1:1(52) flags=0x4228860 switches=28036 seq=1 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652083
> [ 1095.632186] kworker/1:1     R  running task    12760    52      2 0x00000000
> [ 1095.632209] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.632210] Call Trace:
> [ 1095.632213]  ? _raw_spin_lock+0x69/0x80
> [ 1095.632214]  ? __list_lru_count_one.isra.2+0x22/0x80
> [ 1095.632216]  ? __list_lru_count_one.isra.2+0x22/0x80
> [ 1095.632217]  ? list_lru_count_one+0x23/0x30
> [ 1095.632219]  ? super_cache_count+0x6c/0xe0
> [ 1095.632221]  ? shrink_slab+0x15c/0x6d0
> [ 1095.632241]  ? mem_cgroup_iter+0x14d/0x720
> [ 1095.632244]  ? css_next_child+0x17/0xd0
> [ 1095.632247]  ? shrink_node+0x2fa/0x310
> [ 1095.632251]  ? do_try_to_free_pages+0xe1/0x300
> [ 1095.632254]  ? try_to_free_pages+0x131/0x3f0
> [ 1095.632258]  ? __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.632265]  ? __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.632268]  ? alloc_pages_current+0x97/0x1b0
> [ 1095.632271]  ? new_slab+0x4cb/0x6b0
> [ 1095.632274]  ? ___slab_alloc+0x3a3/0x620
> [ 1095.632313]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.632317]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.632337]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.632339]  ? __slab_alloc+0x46/0x7d
> [ 1095.632341]  ? __kmalloc+0x301/0x3b0
> [ 1095.632371]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.632373]  ? kfree+0x1fa/0x330
> [ 1095.632412]  ? xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.632443]  ? __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.632480]  ? xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.632500]  ? __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.632519]  ? xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.632536]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.632553]  ? xfs_end_io+0x81/0x110 [xfs]
> [ 1095.632556]  ? process_one_work+0x22b/0x760
> [ 1095.632558]  ? process_one_work+0x194/0x760
> [ 1095.632588]  ? worker_thread+0x137/0x4b0
> [ 1095.632591]  ? kthread+0x10f/0x150
> [ 1095.632592]  ? process_one_work+0x760/0x760
> [ 1095.632593]  ? kthread_create_on_node+0x70/0x70
> [ 1095.632596]  ? ret_from_fork+0x31/0x40
> 
> [ 1095.645506] MemAlloc: kworker/1:4(5358) flags=0x4228060 switches=27329 seq=1 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652084
> [ 1095.645506] kworker/1:4     R  running task    12272  5358      2 0x00000080
> [ 1095.645525] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.645526] Call Trace:
> [ 1095.645528]  __schedule+0x336/0xe00
> [ 1095.645531]  schedule+0x3d/0x90
> [ 1095.645532]  schedule_timeout+0x20d/0x510
> [ 1095.645534]  ? lock_timer_base+0xa0/0xa0
> [ 1095.645538]  schedule_timeout_uninterruptible+0x2a/0x30
> [ 1095.645540]  __alloc_pages_slowpath+0x2b5/0xd95
> [ 1095.645546]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.645550]  alloc_pages_current+0x97/0x1b0
> [ 1095.645552]  new_slab+0x4cb/0x6b0
> [ 1095.645555]  ___slab_alloc+0x3a3/0x620
> [ 1095.645576]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645578]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.645597]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645599]  __slab_alloc+0x46/0x7d
> [ 1095.645601]  __kmalloc+0x301/0x3b0
> [ 1095.645620]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.645621]  ? kfree+0x1fa/0x330
> [ 1095.645642]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.645663]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.645681]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.645699]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.646636]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.647249]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.647269]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.647273]  process_one_work+0x22b/0x760
> [ 1095.647274]  ? process_one_work+0x194/0x760
> [ 1095.647277]  worker_thread+0x137/0x4b0
> [ 1095.647280]  kthread+0x10f/0x150
> [ 1095.647281]  ? process_one_work+0x760/0x760
> [ 1095.647283]  ? kthread_create_on_node+0x70/0x70
> [ 1095.647285]  ret_from_fork+0x31/0x40
> 
> [ 1095.638807] MemAlloc: kworker/0:3(2486) flags=0x4228860 switches=76240 seq=10 gfp=0x1604240(GFP_NOFS|__GFP_NOWARN|__GFP_COMP|__GFP_NOTRACK) order=0 delay=652064
> [ 1095.638807] kworker/0:3     R  running task    11608  2486      2 0x00000080
> [ 1095.638829] Workqueue: xfs-data/sda1 xfs_end_io [xfs]
> [ 1095.638830] Call Trace:
> [ 1095.638833]  __schedule+0x336/0xe00
> [ 1095.638837]  preempt_schedule_common+0x1f/0x31
> [ 1095.638838]  _cond_resched+0x1c/0x30
> [ 1095.638839]  shrink_slab+0x339/0x6d0
> [ 1095.638846]  shrink_node+0x2fa/0x310
> [ 1095.638850]  do_try_to_free_pages+0xe1/0x300
> [ 1095.638854]  try_to_free_pages+0x131/0x3f0
> [ 1095.638859]  __alloc_pages_slowpath+0x3ec/0xd95
> [ 1095.638866]  __alloc_pages_nodemask+0x3e4/0x460
> [ 1095.638871]  alloc_pages_current+0x97/0x1b0
> [ 1095.638874]  new_slab+0x4cb/0x6b0
> [ 1095.638878]  ___slab_alloc+0x3a3/0x620
> [ 1095.638900]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.638903]  ? ___slab_alloc+0x5c6/0x620
> [ 1095.638923]  ? kmem_alloc+0x96/0x120 [xfs]
> [ 1095.638925]  __slab_alloc+0x46/0x7d
> [ 1095.638928]  __kmalloc+0x301/0x3b0
> [ 1095.638947]  kmem_alloc+0x96/0x120 [xfs]
> [ 1095.638948]  ? kfree+0x1fa/0x330
> [ 1095.638970]  xfs_log_commit_cil+0x489/0x710 [xfs]
> [ 1095.638992]  __xfs_trans_commit+0x83/0x260 [xfs]
> [ 1095.639011]  xfs_trans_commit+0x10/0x20 [xfs]
> [ 1095.639030]  __xfs_setfilesize+0xdb/0x240 [xfs]
> [ 1095.639066]  xfs_setfilesize_ioend+0x89/0xb0 [xfs]
> [ 1095.639083]  ? xfs_setfilesize_ioend+0x5/0xb0 [xfs]
> [ 1095.639100]  xfs_end_io+0x81/0x110 [xfs]
> [ 1095.639103]  process_one_work+0x22b/0x760
> [ 1095.639104]  ? process_one_work+0x194/0x760
> [ 1095.639108]  worker_thread+0x137/0x4b0
> [ 1095.639111]  kthread+0x10f/0x150
> [ 1095.639112]  ? process_one_work+0x760/0x760
> [ 1095.639113]  ? kthread_create_on_node+0x70/0x70
> [ 1095.639116]  ? do_syscall_64+0x6c/0x200
> [ 1095.639118]  ret_from_fork+0x31/0x40
--
To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [XFS Filesystem Development (older mail)]     [Linux Filesystem Development]     [Linux Audio Users]     [Yosemite Trails]     [Linux Kernel]     [Linux RAID]     [Linux SCSI]


  Powered by Linux