Google Chrome cause locks held in system (kernel 4.15 rc2)

Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

Hi,

can anybody said what here happens?
And which info needed for fixing it?
Thanks.

[16712.376081] INFO: task tracker-store:27121 blocked for more than 120
seconds.
[16712.376088]       Not tainted 4.15.0-rc2-amd-vega+ #10
[16712.376092] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[16712.376095] tracker-store   D13400 27121   1843 0x00000000
[16712.376102] Call Trace:
[16712.376114]  ? __schedule+0x2e3/0xb90
[16712.376123]  ? wait_for_completion+0x146/0x1e0
[16712.376128]  schedule+0x2f/0x90
[16712.376132]  schedule_timeout+0x236/0x540
[16712.376143]  ? mark_held_locks+0x4e/0x80
[16712.376147]  ? _raw_spin_unlock_irq+0x29/0x40
[16712.376153]  ? wait_for_completion+0x146/0x1e0
[16712.376158]  wait_for_completion+0x16e/0x1e0
[16712.376162]  ? wake_up_q+0x70/0x70
[16712.376204]  ? xfs_buf_read_map+0x134/0x2f0 [xfs]
[16712.376234]  xfs_buf_submit_wait+0xaf/0x520 [xfs]
[16712.376263]  xfs_buf_read_map+0x134/0x2f0 [xfs]
[16712.376293]  ? xfs_trans_read_buf_map+0xc3/0x580 [xfs]
[16712.376325]  xfs_trans_read_buf_map+0xc3/0x580 [xfs]
[16712.376353]  xfs_da_read_buf+0xd3/0x120 [xfs]
[16712.376387]  xfs_dir3_block_read+0x35/0x70 [xfs]
[16712.376413]  xfs_dir2_block_lookup_int+0x4d/0x220 [xfs]
[16712.376444]  xfs_dir2_block_replace+0x4e/0x1d0 [xfs]
[16712.376467]  ? xfs_dir2_isblock+0x2f/0x90 [xfs]
[16712.376492]  xfs_dir_replace+0x10a/0x180 [xfs]
[16712.376526]  xfs_rename+0x586/0xbd0 [xfs]
[16712.376573]  xfs_vn_rename+0xd5/0x140 [xfs]
[16712.376586]  vfs_rename+0x494/0xa00
[16712.376601]  SyS_rename+0x338/0x390
[16712.376618]  entry_SYSCALL_64_fastpath+0x1f/0x96
[16712.376622] RIP: 0033:0x7f02d4a2c167
[16712.376624] RSP: 002b:00007ffd0998cb98 EFLAGS: 00000207 ORIG_RAX:
0000000000000052
[16712.376629] RAX: ffffffffffffffda RBX: 0000000000000001 RCX:
00007f02d4a2c167
[16712.376631] RDX: 0000000000000002 RSI: 0000560149d23fd0 RDI:
0000560149e737b0
[16712.376633] RBP: 000000000000000f R08: 0000560149e73710 R09:
000000000000002c
[16712.376635] R10: 0000000000058a8e R11: 0000000000000207 R12:
0000000000000000
[16712.376638] R13: 0000560149e6c360 R14: 0000560149d23fd0 R15:
0000000000000000
[16712.376828] 
               Showing all locks held in the system:
[16712.376876] 1 lock held by khungtaskd/67:
[16712.376886]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
debug_show_all_locks+0x37/0x190
[16712.377113] 3 locks held by kworker/u16:2/18769:
[16712.377115]  #0:  ((wq_completion)"writeback"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[16712.377128]  #1:  ((work_completion)(&(&wb->dwork)->work)){+.+.},
at: [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[16712.377138]  #2:  (&type->s_umount_key#63){++++}, at:
[<00000000ecbba71d>] trylock_super+0x16/0x50
[16712.377176] 8 locks held by tracker-store/27121:
[16712.377178]  #0:  (sb_writers#17){.+.+}, at: [<0000000063218e58>]
mnt_want_write+0x20/0x50
[16712.377191]  #1:  (&type->i_mutex_dir_key#7/1){+.+.}, at:
[<0000000026b21526>] lock_rename+0xcf/0xf0
[16712.377208]  #2:  (&inode->i_rwsem){++++}, at: [<00000000b63ba570>]
lock_two_nondirectories+0x6d/0x80
[16712.377219]  #3:  (&inode->i_rwsem/4){+.+.}, at:
[<00000000d44f800a>] vfs_rename+0x337/0xa00
[16712.377232]  #4:  (sb_internal){.+.+}, at: [<00000000b5b0ff39>]
xfs_trans_alloc+0xe2/0x120 [xfs]
[16712.377269]  #5:  (&xfs_dir_ilock_class){++++}, at:
[<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
[16712.377306]  #6:  (&xfs_nondir_ilock_class/2){+.+.}, at:
[<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
[16712.377343]  #7:  (&xfs_nondir_ilock_class/3){+.+.}, at:
[<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
[16712.377380] 3 locks held by TaskSchedulerFo/27216:
[16712.377382]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377396]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<0000000086cbd317>] do_truncate+0x66/0xc0
[16712.377408]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
[16712.377443] 3 locks held by TaskSchedulerFo/27217:
[16712.377445]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377457]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<0000000086cbd317>] do_truncate+0x66/0xc0
[16712.377471]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
[16712.377504] 1 lock held by TaskSchedulerFo/27219:
[16712.377506]  #0:  (sb_writers#17){.+.+}, at: [<0000000063218e58>]
mnt_want_write+0x20/0x50
[16712.377521] 3 locks held by TaskSchedulerFo/27287:
[16712.377523]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377535]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<0000000086cbd317>] do_truncate+0x66/0xc0
[16712.377547]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
[16712.377581] 3 locks held by TaskSchedulerFo/27289:
[16712.377583]  #0:  (&f->f_pos_lock){+.+.}, at: [<00000000cb121025>]
__fdget_pos+0x48/0x60
[16712.377594]  #1:  (&type->i_mutex_dir_key#7){++++}, at:
[<00000000a872ed9a>] iterate_dir+0x56/0x180
[16712.377607]  #2:  (&xfs_dir_ilock_class){++++}, at:
[<000000002829e721>] xfs_ilock_data_map_shared+0x2c/0x30 [xfs]
[16712.377641] 3 locks held by TaskSchedulerFo/27292:
[16712.377642]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377655]  #1:  (&inode->i_rwsem){++++}, at: [<0000000086cbd317>]
do_truncate+0x66/0xc0
[16712.377667]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]

[16712.377873] =============================================

[18432.706561] INFO: task htop:2690 blocked for more than 120 seconds.
[18432.706575]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.706581] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.706588] htop            D12280  2690   2565 0x00000000
[18432.706602] Call Trace:
[18432.706622]  ? __schedule+0x2e3/0xb90
[18432.706637]  ? rwsem_down_read_failed+0x147/0x190
[18432.706648]  schedule+0x2f/0x90
[18432.706654]  rwsem_down_read_failed+0x118/0x190
[18432.706662]  ? __lock_acquire+0x2c3/0x1270
[18432.706688]  ? call_rwsem_down_read_failed+0x14/0x30
[18432.706695]  call_rwsem_down_read_failed+0x14/0x30
[18432.706710]  down_read+0x97/0xa0
[18432.706719]  proc_pid_cmdline_read+0xd2/0x4a0
[18432.706731]  ? debug_check_no_obj_freed+0x160/0x248
[18432.706753]  ? __vfs_read+0x33/0x170
[18432.706759]  __vfs_read+0x33/0x170
[18432.706781]  vfs_read+0x9e/0x150
[18432.706792]  SyS_read+0x55/0xc0
[18432.706807]  entry_SYSCALL_64_fastpath+0x1f/0x96
[18432.706814] RIP: 0033:0x7fc2d8f4ae01
[18432.706819] RSP: 002b:00007fffedb1f998 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[18432.706827] RAX: ffffffffffffffda RBX: 000056139647bc10 RCX:
00007fc2d8f4ae01
[18432.706831] RDX: 0000000000001000 RSI: 00007fffedb1fa60 RDI:
0000000000000007
[18432.706835] RBP: 000056139696f483 R08: 000056139696f483 R09:
0000000000000005
[18432.706839] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000007
[18432.706844] R13: 000056139696f3f0 R14: 00005613961bb8a0 R15:
00005613961bc5e0
[18432.707027] INFO: task Chrome_IOThread:27225 blocked for more than
120 seconds.
[18432.707034]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.707039] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.707045] Chrome_IOThread D11304 27225   3654 0x00000000
[18432.707057] Call Trace:
[18432.707070]  ? __schedule+0x2e3/0xb90
[18432.707086]  ? __lock_page+0xa9/0x180
[18432.707095]  schedule+0x2f/0x90
[18432.707102]  io_schedule+0x12/0x40
[18432.707109]  __lock_page+0xe9/0x180
[18432.707121]  ? page_cache_tree_insert+0x130/0x130
[18432.707138]  deferred_split_scan+0x2b6/0x300
[18432.707160]  shrink_slab.part.47+0x1f8/0x590
[18432.707179]  ? percpu_ref_put_many+0x84/0x100
[18432.707197]  shrink_node+0x2f4/0x300
[18432.707219]  do_try_to_free_pages+0xca/0x350
[18432.707236]  try_to_free_pages+0x140/0x350
[18432.707259]  __alloc_pages_slowpath+0x43c/0x1080
[18432.707298]  __alloc_pages_nodemask+0x3ac/0x430
[18432.707316]  alloc_pages_vma+0x7c/0x200
[18432.707331]  __handle_mm_fault+0x8a1/0x1230
[18432.707359]  handle_mm_fault+0x14c/0x310
[18432.707373]  __do_page_fault+0x28c/0x530
[18432.707450]  do_page_fault+0x32/0x270
[18432.707470]  page_fault+0x22/0x30
[18432.707478] RIP: 0033:0x7f9f336ac4ef
[18432.707482] RSP: 002b:00007f9f1533c968 EFLAGS: 00010206
[18432.707491] RAX: 00003d60824b4000 RBX: 00000000000885c8 RCX:
0000000000001040
[18432.707495] RDX: 0000000000001040 RSI: 00003d602692c400 RDI:
00003d60824b4000
[18432.707499] RBP: 00007f9f1533c9a0 R08: 0000000000000089 R09:
00003d602692d440
[18432.707503] R10: 00007f9f1533caf0 R11: 0000000000000000 R12:
00003d602c90f3c0
[18432.707507] R13: 0000000000000010 R14: 00000000000885b8 R15:
00003d60824b4000
[18432.707539] INFO: task TaskSchedulerFo:9369 blocked for more than
120 seconds.
[18432.707546]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.707551] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.707557] TaskSchedulerFo D11224  9369   3654 0x00000000
[18432.707568] Call Trace:
[18432.707581]  ? __schedule+0x2e3/0xb90
[18432.707596]  ? rwsem_down_read_failed+0x147/0x190
[18432.707605]  schedule+0x2f/0x90
[18432.707611]  rwsem_down_read_failed+0x118/0x190
[18432.707618]  ? __lock_acquire+0x2c3/0x1270
[18432.707643]  ? call_rwsem_down_read_failed+0x14/0x30
[18432.707650]  call_rwsem_down_read_failed+0x14/0x30
[18432.707665]  down_read+0x97/0xa0
[18432.707673]  SyS_madvise+0x859/0x920
[18432.707682]  ? SyS_rename+0xfc/0x390
[18432.707695]  ? trace_hardirqs_on_caller+0xed/0x180
[18432.707704]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[18432.707720]  ? entry_SYSCALL_64_fastpath+0x1f/0x96
[18432.707726]  entry_SYSCALL_64_fastpath+0x1f/0x96
[18432.707731] RIP: 0033:0x7f9f3363c4a7
[18432.707735] RSP: 002b:00007f9ebe2805c8 EFLAGS: 00000206 ORIG_RAX:
000000000000001c
[18432.707743] RAX: ffffffffffffffda RBX: 00007f9ebe2806d0 RCX:
00007f9f3363c4a7
[18432.707747] RDX: 0000000000000004 RSI: 0000000000041000 RDI:
00003d6073c5d000
[18432.707751] RBP: 00007f9ebe280600 R08: 0000000000000000 R09:
000000000000018d
[18432.707755] R10: 0000000000000000 R11: 0000000000000206 R12:
0000000000000000
[18432.707759] R13: 0000000000021796 R14: 00000000be280601 R15:
00007f9ebe2806d0
[18432.707998] INFO: task kworker/3:1:10525 blocked for more than 120
seconds.
[18432.708004]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.708009] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.708015] kworker/3:1     D13784 10525      2 0x80000000
[18432.708055] Workqueue: events async_pf_execute [kvm]
[18432.708063] Call Trace:
[18432.708075]  ? __schedule+0x2e3/0xb90
[18432.708094]  schedule+0x2f/0x90
[18432.708100]  io_schedule+0x12/0x40
[18432.708108]  __lock_page_or_retry+0x2e4/0x350
[18432.708121]  ? page_cache_tree_insert+0x130/0x130
[18432.708137]  do_swap_page+0x721/0x9f0
[18432.708149]  ? __lock_acquire+0x2c3/0x1270
[18432.708163]  __handle_mm_fault+0xa5c/0x1230
[18432.708209]  handle_mm_fault+0x14c/0x310
[18432.708222]  __get_user_pages+0x1b0/0x6e0
[18432.708244]  get_user_pages_remote+0x13a/0x200
[18432.708281]  async_pf_execute+0x96/0x280 [kvm]
[18432.708303]  process_one_work+0x25e/0x6c0
[18432.708320]  worker_thread+0x3a/0x390
[18432.708323]  ? process_one_work+0x6c0/0x6c0
[18432.708325]  kthread+0x15d/0x180
[18432.708338]  ? kthread_create_worker_on_cpu+0x70/0x70
[18432.708341]  ret_from_fork+0x24/0x30
[18432.708353] INFO: task kworker/3:2:13474 blocked for more than 120
seconds.
[18432.708355]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.708357] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.708358] kworker/3:2     D14176 13474      2 0x80000000
[18432.708369] Workqueue: events async_pf_execute [kvm]
[18432.708371] Call Trace:
[18432.708384]  ? __schedule+0x2e3/0xb90
[18432.708395]  schedule+0x2f/0x90
[18432.708396]  io_schedule+0x12/0x40
[18432.708399]  __lock_page_or_retry+0x2e4/0x350
[18432.708403]  ? page_cache_tree_insert+0x130/0x130
[18432.708407]  do_swap_page+0x721/0x9f0
[18432.708411]  ? __lock_acquire+0x2c3/0x1270
[18432.708415]  __handle_mm_fault+0xa5c/0x1230
[18432.708425]  handle_mm_fault+0x14c/0x310
[18432.708432]  __get_user_pages+0x1b0/0x6e0
[18432.708443]  get_user_pages_remote+0x13a/0x200
[18432.708457]  async_pf_execute+0x96/0x280 [kvm]
[18432.708464]  process_one_work+0x25e/0x6c0
[18432.708472]  worker_thread+0x3a/0x390
[18432.708478]  ? process_one_work+0x6c0/0x6c0
[18432.708481]  kthread+0x15d/0x180
[18432.708485]  ? kthread_create_worker_on_cpu+0x70/0x70
[18432.708491]  ret_from_fork+0x24/0x30
[18432.708507] 
               Showing all locks held in the system:
[18432.708526] 1 lock held by khungtaskd/67:
[18432.708527]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
debug_show_all_locks+0x37/0x190
[18432.708637] 1 lock held by htop/2690:
[18432.708638]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
proc_pid_cmdline_read+0xd2/0x4a0
[18432.708657] 1 lock held by CPU 0/KVM/3893:
[18432.708658]  #0:  (&vcpu->mutex){+.+.}, at: [<00000000ff3fb7f4>]
vcpu_load+0x17/0x60 [kvm]
[18432.708759] 2 locks held by Chrome_IOThread/27225:
[18432.708760]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18432.708766]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590
[18432.708773] 1 lock held by CacheThread_Blo/27264:
[18432.708774]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708780] 1 lock held by Chrome_HistoryT/27286:
[18432.708781]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708788] 1 lock held by TaskSchedulerFo/9369:
[18432.708788]  #0:  (&mm->mmap_sem){++++}, at: [<00000000603ee2cd>]
SyS_madvise+0x859/0x920
[18432.708794] 1 lock held by TaskSchedulerFo/12373:
[18432.708795]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708802] 1 lock held by TaskSchedulerFo/13115:
[18432.708803]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708809] 1 lock held by TaskSchedulerFo/13125:
[18432.708810]  #0:  (&mm->mmap_sem){++++}, at: [<000000003933f0be>]
vm_mmap_pgoff+0xa5/0x120
[18432.708816] 1 lock held by TaskSchedulerBa/13514:
[18432.708817]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708977] 1 lock held by tracker-store/5038:
[18432.708978]  #0:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<00000000c3f6e04c>] xfs_ilock+0x195/0x200 [xfs]
[18432.709033] 2 locks held by kworker/3:1/10525:
[18432.709034]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709040]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709049] 2 locks held by kworker/3:2/13474:
[18432.709050]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709056]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709064] 2 locks held by cc1/14068:
[18432.709065]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18432.709070]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590

[18432.709078] =============================================


[18555.587276] INFO: task htop:2690 blocked for more than 120 seconds.
[18555.587281]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587283] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587285] htop            D12280  2690   2565 0x00000000
[18555.587290] Call Trace:
[18555.587298]  ? __schedule+0x2e3/0xb90
[18555.587303]  ? rwsem_down_read_failed+0x147/0x190
[18555.587307]  schedule+0x2f/0x90
[18555.587309]  rwsem_down_read_failed+0x118/0x190
[18555.587312]  ? __lock_acquire+0x2c3/0x1270
[18555.587320]  ? call_rwsem_down_read_failed+0x14/0x30
[18555.587323]  call_rwsem_down_read_failed+0x14/0x30
[18555.587328]  down_read+0x97/0xa0
[18555.587331]  proc_pid_cmdline_read+0xd2/0x4a0
[18555.587335]  ? debug_check_no_obj_freed+0x160/0x248
[18555.587343]  ? __vfs_read+0x33/0x170
[18555.587344]  __vfs_read+0x33/0x170
[18555.587351]  vfs_read+0x9e/0x150
[18555.587354]  SyS_read+0x55/0xc0
[18555.587359]  entry_SYSCALL_64_fastpath+0x1f/0x96
[18555.587372] RIP: 0033:0x7fc2d8f4ae01
[18555.587373] RSP: 002b:00007fffedb1f998 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[18555.587376] RAX: ffffffffffffffda RBX: 000056139647bc10 RCX:
00007fc2d8f4ae01
[18555.587377] RDX: 0000000000001000 RSI: 00007fffedb1fa60 RDI:
0000000000000007
[18555.587378] RBP: 000056139696f483 R08: 000056139696f483 R09:
0000000000000005
[18555.587380] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000007
[18555.587381] R13: 000056139696f3f0 R14: 00005613961bb8a0 R15:
00005613961bc5e0
[18555.587516] INFO: task Chrome_IOThread:27225 blocked for more than
120 seconds.
[18555.587519]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587521] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587522] Chrome_IOThread D11304 27225   3654 0x00000000
[18555.587526] Call Trace:
[18555.587531]  ? __schedule+0x2e3/0xb90
[18555.587537]  ? __lock_page+0xa9/0x180
[18555.587539]  schedule+0x2f/0x90
[18555.587542]  io_schedule+0x12/0x40
[18555.587544]  __lock_page+0xe9/0x180
[18555.587548]  ? page_cache_tree_insert+0x130/0x130
[18555.587553]  deferred_split_scan+0x2b6/0x300
[18555.587560]  shrink_slab.part.47+0x1f8/0x590
[18555.587566]  ? percpu_ref_put_many+0x84/0x100
[18555.587572]  shrink_node+0x2f4/0x300
[18555.587579]  do_try_to_free_pages+0xca/0x350
[18555.587584]  try_to_free_pages+0x140/0x350
[18555.587592]  __alloc_pages_slowpath+0x43c/0x1080
[18555.587605]  __alloc_pages_nodemask+0x3ac/0x430
[18555.587611]  alloc_pages_vma+0x7c/0x200
[18555.587617]  __handle_mm_fault+0x8a1/0x1230
[18555.587626]  handle_mm_fault+0x14c/0x310
[18555.587631]  __do_page_fault+0x28c/0x530
[18555.587637]  do_page_fault+0x32/0x270
[18555.587641]  page_fault+0x22/0x30
[18555.587643] RIP: 0033:0x7f9f336ac4ef
[18555.587644] RSP: 002b:00007f9f1533c968 EFLAGS: 00010206
[18555.587646] RAX: 00003d60824b4000 RBX: 00000000000885c8 RCX:
0000000000001040
[18555.587648] RDX: 0000000000001040 RSI: 00003d602692c400 RDI:
00003d60824b4000
[18555.587649] RBP: 00007f9f1533c9a0 R08: 0000000000000089 R09:
00003d602692d440
[18555.587650] R10: 00007f9f1533caf0 R11: 0000000000000000 R12:
00003d602c90f3c0
[18555.587651] R13: 0000000000000010 R14: 00000000000885b8 R15:
00003d60824b4000


[18555.587666] INFO: task CacheThread_Blo:27264 blocked for more than
120 seconds.
[18555.587669]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587672] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587674] CacheThread_Blo D12488 27264   3654 0x00000000
[18555.587680] Call Trace:
[18555.587687]  ? __schedule+0x2e3/0xb90
[18555.587694]  ? rwsem_down_read_failed+0x147/0x190
[18555.587699]  schedule+0x2f/0x90
[18555.587702]  rwsem_down_read_failed+0x118/0x190
[18555.587713]  ? call_rwsem_down_read_failed+0x14/0x30
[18555.587715]  call_rwsem_down_read_failed+0x14/0x30
[18555.587720]  down_read+0x97/0xa0
[18555.587723]  __do_page_fault+0x493/0x530
[18555.587727]  ? trace_hardirqs_on_caller+0xed/0x180
[18555.587732]  do_page_fault+0x32/0x270
[18555.587735]  page_fault+0x22/0x30
[18555.587737] RIP: 0033:0x55c9558374c0
[18555.587738] RSP: 002b:00007f9efed7b648 EFLAGS: 00010206
[18555.587740] RAX: 0000000000000128 RBX: 0000000000000200 RCX:
00007f9efed7b658
[18555.587741] RDX: 00000000000000b0 RSI: 00000000a1010000 RDI:
00003d60252f1088
[18555.587743] RBP: 00007f9efed7b680 R08: 00007f9f1d5eb520 R09:
00000000ffff0001
[18555.587744] R10: 0000000000000000 R11: 0000000000b10000 R12:
00003d6066f02c00
[18555.587745] R13: 0000000000000000 R14: 0000000000000128 R15:
00003d60252f1088
[18555.587754] INFO: task Chrome_HistoryT:27286 blocked for more than
120 seconds.
[18555.587756]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587757] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587759] Chrome_HistoryT D11432 27286   3654 0x00000000
[18555.587762] Call Trace:
[18555.587766]  ? __schedule+0x2e3/0xb90
[18555.587771]  ? rwsem_down_read_failed+0x147/0x190
[18555.587774]  schedule+0x2f/0x90
[18555.587776]  rwsem_down_read_failed+0x118/0x190
[18555.587784]  ? call_rwsem_down_read_failed+0x14/0x30
[18555.587786]  call_rwsem_down_read_failed+0x14/0x30
[18555.587790]  down_read+0x97/0xa0
[18555.587792]  __do_page_fault+0x493/0x530
[18555.587797]  ? SyS_futex+0x12d/0x180
[18555.587799]  ? trace_hardirqs_on_caller+0xed/0x180
[18555.587803]  do_page_fault+0x32/0x270
[18555.587806]  page_fault+0x22/0x30
[18555.587808] RIP: 0033:0x55c95555fa7a
[18555.587809] RSP: 002b:00007f9efdb5ac70 EFLAGS: 00010202
[18555.587811] RAX: 00007f9f1d5a7498 RBX: 000000000000000a RCX:
000000000000000b
[18555.587812] RDX: 000000000000000a RSI: 0000000000000000 RDI:
00003d60258bb200
[18555.587813] RBP: 00007f9efdb5aca0 R08: 0000000000000002 R09:
00003d602c693580
[18555.587814] R10: 000000000000000d R11: 0000000000000001 R12:
000000000000000a
[18555.587816] R13: 0000000000000001 R14: 00003d60258bb200 R15:
0000000000000001
[18555.588004] 
               Showing all locks held in the system:
[18555.588014] 1 lock held by khungtaskd/67:
[18555.588016]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
debug_show_all_locks+0x37/0x190
[18555.588124] 1 lock held by htop/2690:
[18555.588125]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
proc_pid_cmdline_read+0xd2/0x4a0
[18555.588162] 1 lock held by CPU 0/KVM/3893:
[18555.588163]  #0:  (&vcpu->mutex){+.+.}, at: [<00000000ff3fb7f4>]
vcpu_load+0x17/0x60 [kvm]
[18555.588278] 1 lock held by atop/15452:
[18555.588279]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
proc_pid_cmdline_read+0xd2/0x4a0
[18555.588306] 2 locks held by Chrome_IOThread/27225:
[18555.588307]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18555.588318]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590
[18555.588330] 1 lock held by CacheThread_Blo/27264:
[18555.588332]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588340] 1 lock held by Chrome_HistoryT/27286:
[18555.588341]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588348] 1 lock held by TaskSchedulerFo/9369:
[18555.588349]  #0:  (&mm->mmap_sem){++++}, at: [<00000000603ee2cd>]
SyS_madvise+0x859/0x920
[18555.588356] 1 lock held by TaskSchedulerFo/12373:
[18555.588357]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588363] 1 lock held by TaskSchedulerFo/13115:
[18555.588365]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588371] 1 lock held by TaskSchedulerFo/13125:
[18555.588372]  #0:  (&mm->mmap_sem){++++}, at: [<000000003933f0be>]
vm_mmap_pgoff+0xa5/0x120
[18555.588379] 1 lock held by TaskSchedulerBa/13514:
[18555.588380]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588574] 2 locks held by kworker/3:1/10525:
[18555.588575]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588582]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588592] 2 locks held by kworker/3:2/13474:
[18555.588593]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588599]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588606] 2 locks held by cc1/14068:
[18555.588608]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18555.588613]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590

[18555.588623] =============================================

--
Regards
Mikhail

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Darrick J. Wong]

On Fri, Dec 08, 2017 at 08:50:38AM +0500, mikhail wrote:
> Hi,
> 
> can anybody said what here happens?
> And which info needed for fixing it?
> Thanks.
> 
> [16712.376081] INFO: task tracker-store:27121 blocked for more than 120
> seconds.
> [16712.376088]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [16712.376092] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [16712.376095] tracker-store   D13400 27121   1843 0x00000000
> [16712.376102] Call Trace:
> [16712.376114]  ? __schedule+0x2e3/0xb90
> [16712.376123]  ? wait_for_completion+0x146/0x1e0
> [16712.376128]  schedule+0x2f/0x90
> [16712.376132]  schedule_timeout+0x236/0x540
> [16712.376143]  ? mark_held_locks+0x4e/0x80
> [16712.376147]  ? _raw_spin_unlock_irq+0x29/0x40
> [16712.376153]  ? wait_for_completion+0x146/0x1e0
> [16712.376158]  wait_for_completion+0x16e/0x1e0
> [16712.376162]  ? wake_up_q+0x70/0x70
> [16712.376204]  ? xfs_buf_read_map+0x134/0x2f0 [xfs]
> [16712.376234]  xfs_buf_submit_wait+0xaf/0x520 [xfs]

Stuck waiting for a directory block to read.  Slow disk?  Bad media?

--D

> [16712.376263]  xfs_buf_read_map+0x134/0x2f0 [xfs]
> [16712.376293]  ? xfs_trans_read_buf_map+0xc3/0x580 [xfs]
> [16712.376325]  xfs_trans_read_buf_map+0xc3/0x580 [xfs]
> [16712.376353]  xfs_da_read_buf+0xd3/0x120 [xfs]
> [16712.376387]  xfs_dir3_block_read+0x35/0x70 [xfs]
> [16712.376413]  xfs_dir2_block_lookup_int+0x4d/0x220 [xfs]
> [16712.376444]  xfs_dir2_block_replace+0x4e/0x1d0 [xfs]
> [16712.376467]  ? xfs_dir2_isblock+0x2f/0x90 [xfs]
> [16712.376492]  xfs_dir_replace+0x10a/0x180 [xfs]
> [16712.376526]  xfs_rename+0x586/0xbd0 [xfs]
> [16712.376573]  xfs_vn_rename+0xd5/0x140 [xfs]
> [16712.376586]  vfs_rename+0x494/0xa00
> [16712.376601]  SyS_rename+0x338/0x390
> [16712.376618]  entry_SYSCALL_64_fastpath+0x1f/0x96
> [16712.376622] RIP: 0033:0x7f02d4a2c167
> [16712.376624] RSP: 002b:00007ffd0998cb98 EFLAGS: 00000207 ORIG_RAX:
> 0000000000000052
> [16712.376629] RAX: ffffffffffffffda RBX: 0000000000000001 RCX:
> 00007f02d4a2c167
> [16712.376631] RDX: 0000000000000002 RSI: 0000560149d23fd0 RDI:
> 0000560149e737b0
> [16712.376633] RBP: 000000000000000f R08: 0000560149e73710 R09:
> 000000000000002c
> [16712.376635] R10: 0000000000058a8e R11: 0000000000000207 R12:
> 0000000000000000
> [16712.376638] R13: 0000560149e6c360 R14: 0000560149d23fd0 R15:
> 0000000000000000
> [16712.376828] 
>                Showing all locks held in the system:
> [16712.376876] 1 lock held by khungtaskd/67:
> [16712.376886]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
> debug_show_all_locks+0x37/0x190
> [16712.377113] 3 locks held by kworker/u16:2/18769:
> [16712.377115]  #0:  ((wq_completion)"writeback"){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [16712.377128]  #1:  ((work_completion)(&(&wb->dwork)->work)){+.+.},
> at: [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [16712.377138]  #2:  (&type->s_umount_key#63){++++}, at:
> [<00000000ecbba71d>] trylock_super+0x16/0x50
> [16712.377176] 8 locks held by tracker-store/27121:
> [16712.377178]  #0:  (sb_writers#17){.+.+}, at: [<0000000063218e58>]
> mnt_want_write+0x20/0x50
> [16712.377191]  #1:  (&type->i_mutex_dir_key#7/1){+.+.}, at:
> [<0000000026b21526>] lock_rename+0xcf/0xf0
> [16712.377208]  #2:  (&inode->i_rwsem){++++}, at: [<00000000b63ba570>]
> lock_two_nondirectories+0x6d/0x80
> [16712.377219]  #3:  (&inode->i_rwsem/4){+.+.}, at:
> [<00000000d44f800a>] vfs_rename+0x337/0xa00
> [16712.377232]  #4:  (sb_internal){.+.+}, at: [<00000000b5b0ff39>]
> xfs_trans_alloc+0xe2/0x120 [xfs]
> [16712.377269]  #5:  (&xfs_dir_ilock_class){++++}, at:
> [<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
> [16712.377306]  #6:  (&xfs_nondir_ilock_class/2){+.+.}, at:
> [<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
> [16712.377343]  #7:  (&xfs_nondir_ilock_class/3){+.+.}, at:
> [<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
> [16712.377380] 3 locks held by TaskSchedulerFo/27216:
> [16712.377382]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
> do_sys_ftruncate.constprop.17+0xda/0x110
> [16712.377396]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
> [<0000000086cbd317>] do_truncate+0x66/0xc0
> [16712.377408]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
> [<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
> [16712.377443] 3 locks held by TaskSchedulerFo/27217:
> [16712.377445]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
> do_sys_ftruncate.constprop.17+0xda/0x110
> [16712.377457]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
> [<0000000086cbd317>] do_truncate+0x66/0xc0
> [16712.377471]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
> [<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
> [16712.377504] 1 lock held by TaskSchedulerFo/27219:
> [16712.377506]  #0:  (sb_writers#17){.+.+}, at: [<0000000063218e58>]
> mnt_want_write+0x20/0x50
> [16712.377521] 3 locks held by TaskSchedulerFo/27287:
> [16712.377523]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
> do_sys_ftruncate.constprop.17+0xda/0x110
> [16712.377535]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
> [<0000000086cbd317>] do_truncate+0x66/0xc0
> [16712.377547]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
> [<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
> [16712.377581] 3 locks held by TaskSchedulerFo/27289:
> [16712.377583]  #0:  (&f->f_pos_lock){+.+.}, at: [<00000000cb121025>]
> __fdget_pos+0x48/0x60
> [16712.377594]  #1:  (&type->i_mutex_dir_key#7){++++}, at:
> [<00000000a872ed9a>] iterate_dir+0x56/0x180
> [16712.377607]  #2:  (&xfs_dir_ilock_class){++++}, at:
> [<000000002829e721>] xfs_ilock_data_map_shared+0x2c/0x30 [xfs]
> [16712.377641] 3 locks held by TaskSchedulerFo/27292:
> [16712.377642]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
> do_sys_ftruncate.constprop.17+0xda/0x110
> [16712.377655]  #1:  (&inode->i_rwsem){++++}, at: [<0000000086cbd317>]
> do_truncate+0x66/0xc0
> [16712.377667]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
> [<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
> 
> [16712.377873] =============================================
> 
> [18432.706561] INFO: task htop:2690 blocked for more than 120 seconds.
> [18432.706575]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18432.706581] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18432.706588] htop            D12280  2690   2565 0x00000000
> [18432.706602] Call Trace:
> [18432.706622]  ? __schedule+0x2e3/0xb90
> [18432.706637]  ? rwsem_down_read_failed+0x147/0x190
> [18432.706648]  schedule+0x2f/0x90
> [18432.706654]  rwsem_down_read_failed+0x118/0x190
> [18432.706662]  ? __lock_acquire+0x2c3/0x1270
> [18432.706688]  ? call_rwsem_down_read_failed+0x14/0x30
> [18432.706695]  call_rwsem_down_read_failed+0x14/0x30
> [18432.706710]  down_read+0x97/0xa0
> [18432.706719]  proc_pid_cmdline_read+0xd2/0x4a0
> [18432.706731]  ? debug_check_no_obj_freed+0x160/0x248
> [18432.706753]  ? __vfs_read+0x33/0x170
> [18432.706759]  __vfs_read+0x33/0x170
> [18432.706781]  vfs_read+0x9e/0x150
> [18432.706792]  SyS_read+0x55/0xc0
> [18432.706807]  entry_SYSCALL_64_fastpath+0x1f/0x96
> [18432.706814] RIP: 0033:0x7fc2d8f4ae01
> [18432.706819] RSP: 002b:00007fffedb1f998 EFLAGS: 00000246 ORIG_RAX:
> 0000000000000000
> [18432.706827] RAX: ffffffffffffffda RBX: 000056139647bc10 RCX:
> 00007fc2d8f4ae01
> [18432.706831] RDX: 0000000000001000 RSI: 00007fffedb1fa60 RDI:
> 0000000000000007
> [18432.706835] RBP: 000056139696f483 R08: 000056139696f483 R09:
> 0000000000000005
> [18432.706839] R10: 0000000000000000 R11: 0000000000000246 R12:
> 0000000000000007
> [18432.706844] R13: 000056139696f3f0 R14: 00005613961bb8a0 R15:
> 00005613961bc5e0
> [18432.707027] INFO: task Chrome_IOThread:27225 blocked for more than
> 120 seconds.
> [18432.707034]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18432.707039] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18432.707045] Chrome_IOThread D11304 27225   3654 0x00000000
> [18432.707057] Call Trace:
> [18432.707070]  ? __schedule+0x2e3/0xb90
> [18432.707086]  ? __lock_page+0xa9/0x180
> [18432.707095]  schedule+0x2f/0x90
> [18432.707102]  io_schedule+0x12/0x40
> [18432.707109]  __lock_page+0xe9/0x180
> [18432.707121]  ? page_cache_tree_insert+0x130/0x130
> [18432.707138]  deferred_split_scan+0x2b6/0x300
> [18432.707160]  shrink_slab.part.47+0x1f8/0x590
> [18432.707179]  ? percpu_ref_put_many+0x84/0x100
> [18432.707197]  shrink_node+0x2f4/0x300
> [18432.707219]  do_try_to_free_pages+0xca/0x350
> [18432.707236]  try_to_free_pages+0x140/0x350
> [18432.707259]  __alloc_pages_slowpath+0x43c/0x1080
> [18432.707298]  __alloc_pages_nodemask+0x3ac/0x430
> [18432.707316]  alloc_pages_vma+0x7c/0x200
> [18432.707331]  __handle_mm_fault+0x8a1/0x1230
> [18432.707359]  handle_mm_fault+0x14c/0x310
> [18432.707373]  __do_page_fault+0x28c/0x530
> [18432.707450]  do_page_fault+0x32/0x270
> [18432.707470]  page_fault+0x22/0x30
> [18432.707478] RIP: 0033:0x7f9f336ac4ef
> [18432.707482] RSP: 002b:00007f9f1533c968 EFLAGS: 00010206
> [18432.707491] RAX: 00003d60824b4000 RBX: 00000000000885c8 RCX:
> 0000000000001040
> [18432.707495] RDX: 0000000000001040 RSI: 00003d602692c400 RDI:
> 00003d60824b4000
> [18432.707499] RBP: 00007f9f1533c9a0 R08: 0000000000000089 R09:
> 00003d602692d440
> [18432.707503] R10: 00007f9f1533caf0 R11: 0000000000000000 R12:
> 00003d602c90f3c0
> [18432.707507] R13: 0000000000000010 R14: 00000000000885b8 R15:
> 00003d60824b4000
> [18432.707539] INFO: task TaskSchedulerFo:9369 blocked for more than
> 120 seconds.
> [18432.707546]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18432.707551] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18432.707557] TaskSchedulerFo D11224  9369   3654 0x00000000
> [18432.707568] Call Trace:
> [18432.707581]  ? __schedule+0x2e3/0xb90
> [18432.707596]  ? rwsem_down_read_failed+0x147/0x190
> [18432.707605]  schedule+0x2f/0x90
> [18432.707611]  rwsem_down_read_failed+0x118/0x190
> [18432.707618]  ? __lock_acquire+0x2c3/0x1270
> [18432.707643]  ? call_rwsem_down_read_failed+0x14/0x30
> [18432.707650]  call_rwsem_down_read_failed+0x14/0x30
> [18432.707665]  down_read+0x97/0xa0
> [18432.707673]  SyS_madvise+0x859/0x920
> [18432.707682]  ? SyS_rename+0xfc/0x390
> [18432.707695]  ? trace_hardirqs_on_caller+0xed/0x180
> [18432.707704]  ? trace_hardirqs_on_thunk+0x1a/0x1c
> [18432.707720]  ? entry_SYSCALL_64_fastpath+0x1f/0x96
> [18432.707726]  entry_SYSCALL_64_fastpath+0x1f/0x96
> [18432.707731] RIP: 0033:0x7f9f3363c4a7
> [18432.707735] RSP: 002b:00007f9ebe2805c8 EFLAGS: 00000206 ORIG_RAX:
> 000000000000001c
> [18432.707743] RAX: ffffffffffffffda RBX: 00007f9ebe2806d0 RCX:
> 00007f9f3363c4a7
> [18432.707747] RDX: 0000000000000004 RSI: 0000000000041000 RDI:
> 00003d6073c5d000
> [18432.707751] RBP: 00007f9ebe280600 R08: 0000000000000000 R09:
> 000000000000018d
> [18432.707755] R10: 0000000000000000 R11: 0000000000000206 R12:
> 0000000000000000
> [18432.707759] R13: 0000000000021796 R14: 00000000be280601 R15:
> 00007f9ebe2806d0
> [18432.707998] INFO: task kworker/3:1:10525 blocked for more than 120
> seconds.
> [18432.708004]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18432.708009] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18432.708015] kworker/3:1     D13784 10525      2 0x80000000
> [18432.708055] Workqueue: events async_pf_execute [kvm]
> [18432.708063] Call Trace:
> [18432.708075]  ? __schedule+0x2e3/0xb90
> [18432.708094]  schedule+0x2f/0x90
> [18432.708100]  io_schedule+0x12/0x40
> [18432.708108]  __lock_page_or_retry+0x2e4/0x350
> [18432.708121]  ? page_cache_tree_insert+0x130/0x130
> [18432.708137]  do_swap_page+0x721/0x9f0
> [18432.708149]  ? __lock_acquire+0x2c3/0x1270
> [18432.708163]  __handle_mm_fault+0xa5c/0x1230
> [18432.708209]  handle_mm_fault+0x14c/0x310
> [18432.708222]  __get_user_pages+0x1b0/0x6e0
> [18432.708244]  get_user_pages_remote+0x13a/0x200
> [18432.708281]  async_pf_execute+0x96/0x280 [kvm]
> [18432.708303]  process_one_work+0x25e/0x6c0
> [18432.708320]  worker_thread+0x3a/0x390
> [18432.708323]  ? process_one_work+0x6c0/0x6c0
> [18432.708325]  kthread+0x15d/0x180
> [18432.708338]  ? kthread_create_worker_on_cpu+0x70/0x70
> [18432.708341]  ret_from_fork+0x24/0x30
> [18432.708353] INFO: task kworker/3:2:13474 blocked for more than 120
> seconds.
> [18432.708355]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18432.708357] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18432.708358] kworker/3:2     D14176 13474      2 0x80000000
> [18432.708369] Workqueue: events async_pf_execute [kvm]
> [18432.708371] Call Trace:
> [18432.708384]  ? __schedule+0x2e3/0xb90
> [18432.708395]  schedule+0x2f/0x90
> [18432.708396]  io_schedule+0x12/0x40
> [18432.708399]  __lock_page_or_retry+0x2e4/0x350
> [18432.708403]  ? page_cache_tree_insert+0x130/0x130
> [18432.708407]  do_swap_page+0x721/0x9f0
> [18432.708411]  ? __lock_acquire+0x2c3/0x1270
> [18432.708415]  __handle_mm_fault+0xa5c/0x1230
> [18432.708425]  handle_mm_fault+0x14c/0x310
> [18432.708432]  __get_user_pages+0x1b0/0x6e0
> [18432.708443]  get_user_pages_remote+0x13a/0x200
> [18432.708457]  async_pf_execute+0x96/0x280 [kvm]
> [18432.708464]  process_one_work+0x25e/0x6c0
> [18432.708472]  worker_thread+0x3a/0x390
> [18432.708478]  ? process_one_work+0x6c0/0x6c0
> [18432.708481]  kthread+0x15d/0x180
> [18432.708485]  ? kthread_create_worker_on_cpu+0x70/0x70
> [18432.708491]  ret_from_fork+0x24/0x30
> [18432.708507] 
>                Showing all locks held in the system:
> [18432.708526] 1 lock held by khungtaskd/67:
> [18432.708527]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
> debug_show_all_locks+0x37/0x190
> [18432.708637] 1 lock held by htop/2690:
> [18432.708638]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
> proc_pid_cmdline_read+0xd2/0x4a0
> [18432.708657] 1 lock held by CPU 0/KVM/3893:
> [18432.708658]  #0:  (&vcpu->mutex){+.+.}, at: [<00000000ff3fb7f4>]
> vcpu_load+0x17/0x60 [kvm]
> [18432.708759] 2 locks held by Chrome_IOThread/27225:
> [18432.708760]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
> __do_page_fault+0x17a/0x530
> [18432.708766]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
> shrink_slab.part.47+0x5b/0x590
> [18432.708773] 1 lock held by CacheThread_Blo/27264:
> [18432.708774]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18432.708780] 1 lock held by Chrome_HistoryT/27286:
> [18432.708781]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18432.708788] 1 lock held by TaskSchedulerFo/9369:
> [18432.708788]  #0:  (&mm->mmap_sem){++++}, at: [<00000000603ee2cd>]
> SyS_madvise+0x859/0x920
> [18432.708794] 1 lock held by TaskSchedulerFo/12373:
> [18432.708795]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18432.708802] 1 lock held by TaskSchedulerFo/13115:
> [18432.708803]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18432.708809] 1 lock held by TaskSchedulerFo/13125:
> [18432.708810]  #0:  (&mm->mmap_sem){++++}, at: [<000000003933f0be>]
> vm_mmap_pgoff+0xa5/0x120
> [18432.708816] 1 lock held by TaskSchedulerBa/13514:
> [18432.708817]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18432.708977] 1 lock held by tracker-store/5038:
> [18432.708978]  #0:  (&sb->s_type->i_mutex_key#20){++++}, at:
> [<00000000c3f6e04c>] xfs_ilock+0x195/0x200 [xfs]
> [18432.709033] 2 locks held by kworker/3:1/10525:
> [18432.709034]  #0:  ((wq_completion)"events"){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18432.709040]  #1:  ((work_completion)(&work->work)){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18432.709049] 2 locks held by kworker/3:2/13474:
> [18432.709050]  #0:  ((wq_completion)"events"){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18432.709056]  #1:  ((work_completion)(&work->work)){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18432.709064] 2 locks held by cc1/14068:
> [18432.709065]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
> __do_page_fault+0x17a/0x530
> [18432.709070]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
> shrink_slab.part.47+0x5b/0x590
> 
> [18432.709078] =============================================
> 
> 
> [18555.587276] INFO: task htop:2690 blocked for more than 120 seconds.
> [18555.587281]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18555.587283] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18555.587285] htop            D12280  2690   2565 0x00000000
> [18555.587290] Call Trace:
> [18555.587298]  ? __schedule+0x2e3/0xb90
> [18555.587303]  ? rwsem_down_read_failed+0x147/0x190
> [18555.587307]  schedule+0x2f/0x90
> [18555.587309]  rwsem_down_read_failed+0x118/0x190
> [18555.587312]  ? __lock_acquire+0x2c3/0x1270
> [18555.587320]  ? call_rwsem_down_read_failed+0x14/0x30
> [18555.587323]  call_rwsem_down_read_failed+0x14/0x30
> [18555.587328]  down_read+0x97/0xa0
> [18555.587331]  proc_pid_cmdline_read+0xd2/0x4a0
> [18555.587335]  ? debug_check_no_obj_freed+0x160/0x248
> [18555.587343]  ? __vfs_read+0x33/0x170
> [18555.587344]  __vfs_read+0x33/0x170
> [18555.587351]  vfs_read+0x9e/0x150
> [18555.587354]  SyS_read+0x55/0xc0
> [18555.587359]  entry_SYSCALL_64_fastpath+0x1f/0x96
> [18555.587372] RIP: 0033:0x7fc2d8f4ae01
> [18555.587373] RSP: 002b:00007fffedb1f998 EFLAGS: 00000246 ORIG_RAX:
> 0000000000000000
> [18555.587376] RAX: ffffffffffffffda RBX: 000056139647bc10 RCX:
> 00007fc2d8f4ae01
> [18555.587377] RDX: 0000000000001000 RSI: 00007fffedb1fa60 RDI:
> 0000000000000007
> [18555.587378] RBP: 000056139696f483 R08: 000056139696f483 R09:
> 0000000000000005
> [18555.587380] R10: 0000000000000000 R11: 0000000000000246 R12:
> 0000000000000007
> [18555.587381] R13: 000056139696f3f0 R14: 00005613961bb8a0 R15:
> 00005613961bc5e0
> [18555.587516] INFO: task Chrome_IOThread:27225 blocked for more than
> 120 seconds.
> [18555.587519]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18555.587521] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18555.587522] Chrome_IOThread D11304 27225   3654 0x00000000
> [18555.587526] Call Trace:
> [18555.587531]  ? __schedule+0x2e3/0xb90
> [18555.587537]  ? __lock_page+0xa9/0x180
> [18555.587539]  schedule+0x2f/0x90
> [18555.587542]  io_schedule+0x12/0x40
> [18555.587544]  __lock_page+0xe9/0x180
> [18555.587548]  ? page_cache_tree_insert+0x130/0x130
> [18555.587553]  deferred_split_scan+0x2b6/0x300
> [18555.587560]  shrink_slab.part.47+0x1f8/0x590
> [18555.587566]  ? percpu_ref_put_many+0x84/0x100
> [18555.587572]  shrink_node+0x2f4/0x300
> [18555.587579]  do_try_to_free_pages+0xca/0x350
> [18555.587584]  try_to_free_pages+0x140/0x350
> [18555.587592]  __alloc_pages_slowpath+0x43c/0x1080
> [18555.587605]  __alloc_pages_nodemask+0x3ac/0x430
> [18555.587611]  alloc_pages_vma+0x7c/0x200
> [18555.587617]  __handle_mm_fault+0x8a1/0x1230
> [18555.587626]  handle_mm_fault+0x14c/0x310
> [18555.587631]  __do_page_fault+0x28c/0x530
> [18555.587637]  do_page_fault+0x32/0x270
> [18555.587641]  page_fault+0x22/0x30
> [18555.587643] RIP: 0033:0x7f9f336ac4ef
> [18555.587644] RSP: 002b:00007f9f1533c968 EFLAGS: 00010206
> [18555.587646] RAX: 00003d60824b4000 RBX: 00000000000885c8 RCX:
> 0000000000001040
> [18555.587648] RDX: 0000000000001040 RSI: 00003d602692c400 RDI:
> 00003d60824b4000
> [18555.587649] RBP: 00007f9f1533c9a0 R08: 0000000000000089 R09:
> 00003d602692d440
> [18555.587650] R10: 00007f9f1533caf0 R11: 0000000000000000 R12:
> 00003d602c90f3c0
> [18555.587651] R13: 0000000000000010 R14: 00000000000885b8 R15:
> 00003d60824b4000
> 
> 
> [18555.587666] INFO: task CacheThread_Blo:27264 blocked for more than
> 120 seconds.
> [18555.587669]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18555.587672] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18555.587674] CacheThread_Blo D12488 27264   3654 0x00000000
> [18555.587680] Call Trace:
> [18555.587687]  ? __schedule+0x2e3/0xb90
> [18555.587694]  ? rwsem_down_read_failed+0x147/0x190
> [18555.587699]  schedule+0x2f/0x90
> [18555.587702]  rwsem_down_read_failed+0x118/0x190
> [18555.587713]  ? call_rwsem_down_read_failed+0x14/0x30
> [18555.587715]  call_rwsem_down_read_failed+0x14/0x30
> [18555.587720]  down_read+0x97/0xa0
> [18555.587723]  __do_page_fault+0x493/0x530
> [18555.587727]  ? trace_hardirqs_on_caller+0xed/0x180
> [18555.587732]  do_page_fault+0x32/0x270
> [18555.587735]  page_fault+0x22/0x30
> [18555.587737] RIP: 0033:0x55c9558374c0
> [18555.587738] RSP: 002b:00007f9efed7b648 EFLAGS: 00010206
> [18555.587740] RAX: 0000000000000128 RBX: 0000000000000200 RCX:
> 00007f9efed7b658
> [18555.587741] RDX: 00000000000000b0 RSI: 00000000a1010000 RDI:
> 00003d60252f1088
> [18555.587743] RBP: 00007f9efed7b680 R08: 00007f9f1d5eb520 R09:
> 00000000ffff0001
> [18555.587744] R10: 0000000000000000 R11: 0000000000b10000 R12:
> 00003d6066f02c00
> [18555.587745] R13: 0000000000000000 R14: 0000000000000128 R15:
> 00003d60252f1088
> [18555.587754] INFO: task Chrome_HistoryT:27286 blocked for more than
> 120 seconds.
> [18555.587756]       Not tainted 4.15.0-rc2-amd-vega+ #10
> [18555.587757] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [18555.587759] Chrome_HistoryT D11432 27286   3654 0x00000000
> [18555.587762] Call Trace:
> [18555.587766]  ? __schedule+0x2e3/0xb90
> [18555.587771]  ? rwsem_down_read_failed+0x147/0x190
> [18555.587774]  schedule+0x2f/0x90
> [18555.587776]  rwsem_down_read_failed+0x118/0x190
> [18555.587784]  ? call_rwsem_down_read_failed+0x14/0x30
> [18555.587786]  call_rwsem_down_read_failed+0x14/0x30
> [18555.587790]  down_read+0x97/0xa0
> [18555.587792]  __do_page_fault+0x493/0x530
> [18555.587797]  ? SyS_futex+0x12d/0x180
> [18555.587799]  ? trace_hardirqs_on_caller+0xed/0x180
> [18555.587803]  do_page_fault+0x32/0x270
> [18555.587806]  page_fault+0x22/0x30
> [18555.587808] RIP: 0033:0x55c95555fa7a
> [18555.587809] RSP: 002b:00007f9efdb5ac70 EFLAGS: 00010202
> [18555.587811] RAX: 00007f9f1d5a7498 RBX: 000000000000000a RCX:
> 000000000000000b
> [18555.587812] RDX: 000000000000000a RSI: 0000000000000000 RDI:
> 00003d60258bb200
> [18555.587813] RBP: 00007f9efdb5aca0 R08: 0000000000000002 R09:
> 00003d602c693580
> [18555.587814] R10: 000000000000000d R11: 0000000000000001 R12:
> 000000000000000a
> [18555.587816] R13: 0000000000000001 R14: 00003d60258bb200 R15:
> 0000000000000001
> [18555.588004] 
>                Showing all locks held in the system:
> [18555.588014] 1 lock held by khungtaskd/67:
> [18555.588016]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
> debug_show_all_locks+0x37/0x190
> [18555.588124] 1 lock held by htop/2690:
> [18555.588125]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
> proc_pid_cmdline_read+0xd2/0x4a0
> [18555.588162] 1 lock held by CPU 0/KVM/3893:
> [18555.588163]  #0:  (&vcpu->mutex){+.+.}, at: [<00000000ff3fb7f4>]
> vcpu_load+0x17/0x60 [kvm]
> [18555.588278] 1 lock held by atop/15452:
> [18555.588279]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
> proc_pid_cmdline_read+0xd2/0x4a0
> [18555.588306] 2 locks held by Chrome_IOThread/27225:
> [18555.588307]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
> __do_page_fault+0x17a/0x530
> [18555.588318]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
> shrink_slab.part.47+0x5b/0x590
> [18555.588330] 1 lock held by CacheThread_Blo/27264:
> [18555.588332]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18555.588340] 1 lock held by Chrome_HistoryT/27286:
> [18555.588341]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18555.588348] 1 lock held by TaskSchedulerFo/9369:
> [18555.588349]  #0:  (&mm->mmap_sem){++++}, at: [<00000000603ee2cd>]
> SyS_madvise+0x859/0x920
> [18555.588356] 1 lock held by TaskSchedulerFo/12373:
> [18555.588357]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18555.588363] 1 lock held by TaskSchedulerFo/13115:
> [18555.588365]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18555.588371] 1 lock held by TaskSchedulerFo/13125:
> [18555.588372]  #0:  (&mm->mmap_sem){++++}, at: [<000000003933f0be>]
> vm_mmap_pgoff+0xa5/0x120
> [18555.588379] 1 lock held by TaskSchedulerBa/13514:
> [18555.588380]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
> __do_page_fault+0x493/0x530
> [18555.588574] 2 locks held by kworker/3:1/10525:
> [18555.588575]  #0:  ((wq_completion)"events"){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18555.588582]  #1:  ((work_completion)(&work->work)){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18555.588592] 2 locks held by kworker/3:2/13474:
> [18555.588593]  #0:  ((wq_completion)"events"){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18555.588599]  #1:  ((work_completion)(&work->work)){+.+.}, at:
> [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
> [18555.588606] 2 locks held by cc1/14068:
> [18555.588608]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
> __do_page_fault+0x17a/0x530
> [18555.588613]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
> shrink_slab.part.47+0x5b/0x590
> 
> [18555.588623] =============================================
> 
> --
> Regards
> Mikhail
> --
> To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

Darrick J. Wong wrote:
> On Fri, Dec 08, 2017 at 08:50:38AM +0500, mikhail wrote:
> > Hi,
> > 
> > can anybody said what here happens?
> > And which info needed for fixing it?
> > Thanks.
> > 
> > [16712.376081] INFO: task tracker-store:27121 blocked for more than 120
> > seconds.
> > [16712.376088]       Not tainted 4.15.0-rc2-amd-vega+ #10
> > [16712.376092] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables this message.
> > [16712.376095] tracker-store   D13400 27121   1843 0x00000000
> > [16712.376102] Call Trace:
> > [16712.376114]  ? __schedule+0x2e3/0xb90
> > [16712.376123]  ? wait_for_completion+0x146/0x1e0
> > [16712.376128]  schedule+0x2f/0x90
> > [16712.376132]  schedule_timeout+0x236/0x540
> > [16712.376143]  ? mark_held_locks+0x4e/0x80
> > [16712.376147]  ? _raw_spin_unlock_irq+0x29/0x40
> > [16712.376153]  ? wait_for_completion+0x146/0x1e0
> > [16712.376158]  wait_for_completion+0x16e/0x1e0
> > [16712.376162]  ? wake_up_q+0x70/0x70
> > [16712.376204]  ? xfs_buf_read_map+0x134/0x2f0 [xfs]
> > [16712.376234]  xfs_buf_submit_wait+0xaf/0x520 [xfs]
> 
> Stuck waiting for a directory block to read.  Slow disk?  Bad media?
> 

Most likely cause is that I/O was getting very slow due to memory pressure.
Running memory consuming processes (e.g. web browsers) and file writing
processes might generate stresses like this report.

I can't tell whether this report is a real deadlock/lockup or just a slowdown,
for currently we don't have means for checking whether memory allocation was
making progress or not.

The OOM killer is not invoked for allocation requests without __GFP_FS flag.
Therefore, GFP_NOIO / GFP_NOFS allocation requests have possibility of hanging
up the system. We can reproduce such hang up using artificial stress (e.g.
http://lkml.kernel.org/r/201703031948.CHJ81278.VOHSFFFOOLJQMt@I-love.SAKURA.ne.jp ),
but this problem will not be addressed unless it is proven to occur using real
workloads. It is a too much request for averaged users to prove that their systems
hung up due to this problem.

In order to avoid silent hang up, Linux 4.9 got warn_alloc() calls which
"synchronously" prints messages when a memory allocation request took more than
10 seconds. But since it was confirmed that concurrent warn_alloc() calls can
hang up the system, warn_alloc() was reverted in Linux 4.15-rc1
( https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/mm/page_alloc.c?id=400e22499dd92613 ).
Therefore, unfortunately your kernel does not allow you to check whether memory
allocation was making progress or not.

I have been proposing a watchdog which extends khungtaskd so that the system can
print useful information "asynchronously" without locking up the system (e.g.
http://lkml.kernel.org/r/1495331504-12480-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp
http://lkml.kernel.org/r/1510833448-19918-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp ).
But since OOM livelock is the least attractive domain, I'm stuck with zero advocate.
The watchdog did not get in time for obtaining information in your case, sorry.

For now, you can try setting /proc/sys/kernel/hung_task_warnings to -1, for the
default setting of /proc/sys/kernel/hung_task_warnings is 10 which means that
"INFO: task $commname:$pid blocked for more than 120 seconds." is printed for
only 10 times (like this report did) and makes it impossible for users to judge
whether the hung situation continued or not. There is SysRq-t and SysRq-m, but I
don't expect that current SysRq can give you enough information for analyzing
this problem.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Fri, 2017-12-08 at 19:18 +0900, Tetsuo Handa wrote:
> Darrick J. Wong wrote:
> > On Fri, Dec 08, 2017 at 08:50:38AM +0500, mikhail wrote:
> > > Hi,
> > > 
> > > can anybody said what here happens?
> > > And which info needed for fixing it?
> > > Thanks.
> > > 
> > > [16712.376081] INFO: task tracker-store:27121 blocked for more
> > > than 120
> > > seconds.
> > > [16712.376088]       Not tainted 4.15.0-rc2-amd-vega+ #10
> > > [16712.376092] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > > disables this message.
> > > [16712.376095] tracker-store   D13400 27121   1843 0x00000000
> > > [16712.376102] Call Trace:
> > > [16712.376114]  ? __schedule+0x2e3/0xb90
> > > [16712.376123]  ? wait_for_completion+0x146/0x1e0
> > > [16712.376128]  schedule+0x2f/0x90
> > > [16712.376132]  schedule_timeout+0x236/0x540
> > > [16712.376143]  ? mark_held_locks+0x4e/0x80
> > > [16712.376147]  ? _raw_spin_unlock_irq+0x29/0x40
> > > [16712.376153]  ? wait_for_completion+0x146/0x1e0
> > > [16712.376158]  wait_for_completion+0x16e/0x1e0
> > > [16712.376162]  ? wake_up_q+0x70/0x70
> > > [16712.376204]  ? xfs_buf_read_map+0x134/0x2f0 [xfs]
> > > [16712.376234]  xfs_buf_submit_wait+0xaf/0x520 [xfs]
> > 
> > Stuck waiting for a directory block to read.  Slow disk?  Bad
> > media?
> > 
> 
> Most likely cause is that I/O was getting very slow due to memory
> pressure.
> Running memory consuming processes (e.g. web browsers) and file
> writing
> processes might generate stresses like this report.
> 
> I can't tell whether this report is a real deadlock/lockup or just a
> slowdown,
> for currently we don't have means for checking whether memory
> allocation was
> making progress or not.

It not just slowdown because after 5 hours I was still unable launch even htop.After executing command was nothing happens. I was even surprised that
dmesg could work.

> The OOM killer is not invoked for allocation requests without
> __GFP_FS flag.
> Therefore, GFP_NOIO / GFP_NOFS allocation requests have possibility
> of hanging
> up the system. We can reproduce such hang up using artificial stress
> (e.g.
> http://lkml.kernel.org/r/201703031948.CHJ81278.VOHSFFFOOLJQMt@I-love.
> SAKURA.ne.jp ),
> but this problem will not be addressed unless it is proven to occur
> using real
> workloads. It is a too much request for averaged users to prove that
> their systems
> hung up due to this problem.
> 
> In order to avoid silent hang up, Linux 4.9 got warn_alloc() calls
> which
> "synchronously" prints messages when a memory allocation request took
> more than
> 10 seconds. But since it was confirmed that concurrent warn_alloc()
> calls can
> hang up the system, warn_alloc() was reverted in Linux 4.15-rc1
> ( https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/
> commit/mm/page_alloc.c?id=400e22499dd92613 ).
> Therefore, unfortunately your kernel does not allow you to check
> whether memory
> allocation was making progress or not.
> 
> I have been proposing a watchdog which extends khungtaskd so that the
> system can
> print useful information "asynchronously" without locking up the
> system (e.g.
> http://lkml.kernel.org/r/1495331504-12480-1-git-send-email-penguin-ke
> rnel@I-love.SAKURA.ne.jp
> http://lkml.kernel.org/r/1510833448-19918-1-git-send-email-penguin-ke
> rnel@I-love.SAKURA.ne.jp ).
> But since OOM livelock is the least attractive domain, I'm stuck with
> zero advocate.
> The watchdog did not get in time for obtaining information in your
> case, sorry.
> 
> For now, you can try setting /proc/sys/kernel/hung_task_warnings to
> -1, for the
> default setting of /proc/sys/kernel/hung_task_warnings is 10 which
> means that
> "INFO: task $commname:$pid blocked for more than 120 seconds." is
> printed for
> only 10 times (like this report did) and makes it impossible for
> users to judge
> whether the hung situation continued or not. There is SysRq-t and
> SysRq-m, but I
> don't expect that current SysRq can give you enough information for
> analyzing
> this problem.
> 

Thanks for the advice.
Decided to check what happens when I do SysRq-t.
SysRq-t produce a lot of the output even without running Google Chrome.
Such amout of data does not fit in the kernel output buffer and it's
impossible to read from the screen.

Demonstration: https://youtu.be/DUWB1WGBog0

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

mikhail wrote:
> On Fri, 2017-12-08 at 19:18 +0900, Tetsuo Handa wrote:
> > Most likely cause is that I/O was getting very slow due to memory
> > pressure.
> > Running memory consuming processes (e.g. web browsers) and file
> > writing
> > processes might generate stresses like this report.
> > 
> > I can't tell whether this report is a real deadlock/lockup or just a
> > slowdown,
> > for currently we don't have means for checking whether memory
> > allocation was
> > making progress or not.
> 
> It not just slowdown because after 5 hours I was still unable launch
> even htop. After executing command was nothing happens. I was even
> surprised that dmesg could work.

Then, it seems that it was a real deadlock/lockup.

> 
> Thanks for the advice.
> Decided to check what happens when I do SysRq-t.
> SysRq-t produce a lot of the output even without running Google Chrome.
> Such amout of data does not fit in the kernel output buffer and it's
> impossible to read from the screen.
> 
> Demonstration: https://youtu.be/DUWB1WGBog0

Under OOM lockup situation, kernel messages can unlikely be saved to syslog
files, for writing to files involves memory allocation. Can you set up
netconsole or serial console explained at
http://events.linuxfoundation.org/sites/events/files/slides/LCJ2014-en_0.pdf ?
If neither console is possible, it would become difficult to debug.

Michal, any idea?

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Sat, 2017-12-09 at 23:14 +0900, Tetsuo Handa wrote:
> Under OOM lockup situation, kernel messages can unlikely be saved to
> syslog
> files, for writing to files involves memory allocation. Can you set
> up
> netconsole or serial console explained at
> http://events.linuxfoundation.org/sites/events/files/slides/LCJ2014-e
> n_0.pdf ?
> If neither console is possible, it would become difficult to debug.

netconsole works only within local network? destination ip may be from
another network?

[11415.184163] netpoll: netconsole: local port 6665
[11415.184168] netpoll: netconsole: local IPv4 address 0.0.0.0
[11415.184169] netpoll: netconsole: interface 'enp2s0'
[11415.184171] netpoll: netconsole: remote port 6666
[11415.184173] netpoll: netconsole: remote IPv4 address 213.136.82.171
[11415.184174] netpoll: netconsole: remote ethernet address
ff:ff:ff:ff:ff:ff
[11415.184179] netpoll: netconsole: local IP 192.168.1.85
[11415.184738] console [netcon0] enabled
[11415.184741] netconsole: network logging started


But on remote host nothing happens when I do SysRq-t

Of course I compiled and launched ./udplogger on remote host under
tmux. And add udp port 6666 to firewalld rule.
# firewall-cmd --permanent --add-port=6666/udp && systemctl restart
firewalld

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

mikhail wrote:
> On Sat, 2017-12-09 at 23:14 +0900, Tetsuo Handa wrote:
> > Under OOM lockup situation, kernel messages can unlikely be saved to syslog
> > files, for writing to files involves memory allocation. Can you set up
> > netconsole or serial console explained at
> > http://events.linuxfoundation.org/sites/events/files/slides/LCJ2014-en_0.pdf ?
> > If neither console is possible, it would become difficult to debug.
> 
> netconsole works only within local network? destination ip may be from
> another network?

netconsole can work with another network.

(step 1) Verify that UDP packets are reachable. You can test with

         # echo test > /dev/udp/213.136.82.171/6666

         if you are using bash.

(step 2) Verify that you specified gateway's MAC address rather than
         target host's MAC address. "ff:ff:ff:ff:ff:ff" suggests that
         netconsole is unable to resolve correct MAC address.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Mon, 2017-12-11 at 09:14 +0900, Tetsuo Handa wrote:
> mikhail wrote:
> 
On Sat, 2017-12-09 at 23:14 +0900, Tetsuo Handa wrote:

Under OOM lockup situation, kernel messages can unlikely be saved to syslog
files, for writing to files involves memory allocation. Can you set up
netconsole or serial console explained at
http://events.linuxfoundation.org/sites/events/files/slides/LCJ2014-en_0.pdf ?
If neither console is possible, it would become difficult to debug.


netconsole works only within local network? destination ip may be from
another network?

> 
> netconsole can work with another network.
> 
> (step 1) Verify that UDP packets are reachable. You can test with
> 
>          # echo test > /dev/udp/213.136.82.171/6666
> 
>          if you are using bash.


After this on remote machine was created folder with name of router
external ip address.
Inside this folder was places one file with name of current day. This
file has size 0 of bytes and not contain "test" message inside.
That is how it should be?

> 
> (step 2) Verify that you specified gateway's MAC address rather than
>          target host's MAC address. "ff:ff:ff:ff:ff:ff" suggests that
>          netconsole is unable to resolve correct MAC address.
> 

I am not was specified MAC address when launch netconsole. The address
"ff:ff:ff:ff:ff:ff" was settled by default.
Anyway does it matter for remote machine placed behind router?
Ok, I also setted right MAC address for remote machine. But nothing is
changed.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

mikhail wrote:
> > > netconsole works only within local network? destination ip may be from
> > > another network?
> > 
> > netconsole can work with another network.
> > 
> > (step 1) Verify that UDP packets are reachable. You can test with
> > 
> >          # echo test > /dev/udp/213.136.82.171/6666
> > 
> >          if you are using bash.
> 
> After this on remote machine was created folder with name of router
> external ip address.
> Inside this folder was places one file with name of current day. This
> file has size 0 of bytes and not contain "test" message inside.
> That is how it should be?

The message should be written to the log file. If not written, UDP packets
are dropped somewhere. You need to solve this problem first.

> 
> > 
> > (step 2) Verify that you specified gateway's MAC address rather than
> >          target host's MAC address. "ff:ff:ff:ff:ff:ff" suggests that
> >          netconsole is unable to resolve correct MAC address.
> > 
> 
> I am not was specified MAC address when launch netconsole. The address
> "ff:ff:ff:ff:ff:ff" was settled by default.
> Anyway does it matter for remote machine placed behind router?
> Ok, I also setted right MAC address for remote machine. But nothing is
> changed.

If remote machine is in a different network segment, you need to specify
gateway's MAC address rather than remote machine's MAC address. For more
information about netconsole, please see
https://www.kernel.org/doc/Documentation/networking/netconsole.txt .

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Mon, 2017-12-11 at 12:48 +0900, Tetsuo Handa wrote:
> mikhail wrote:
> > > > netconsole works only within local network? destination ip may
> > > > be from
> > > > another network?
> > > 
> > > netconsole can work with another network.
> > > 
> > > (step 1) Verify that UDP packets are reachable. You can test with
> > > 
> > >          # echo test > /dev/udp/213.136.82.171/6666
> > > 
> > >          if you are using bash.
> > 
> > After this on remote machine was created folder with name of router
> > external ip address.
> > Inside this folder was places one file with name of current day.
> > This
> > file has size 0 of bytes and not contain "test" message inside.
> > That is how it should be?
> 
> The message should be written to the log file. If not written, UDP
> packets
> are dropped somewhere. You need to solve this problem first.

I found root cause this problem. Here culprit udplogger, because it not
flush buffers when terminated by ctrl-c.

Here my pull request with fix this problem:
https://github.com/kohsuke/udplogger/pull/1/

Also i fixed two segfault:

1) When send two messages in one second from different hosts or ports.
For reproduce just run
"echo test > /dev/udp/127.0.0.1/6666 && echo test >
/dev/udp/127.0.0.1/6666"
in console.

2) When exced limit of open files.
Just run "echo test > /dev/udp/127.0.0.1/6666" more than 1024 times.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

mikhail wrote:
> On Mon, 2017-12-11 at 12:48 +0900, Tetsuo Handa wrote:
> > mikhail wrote:
> > > > > netconsole works only within local network? destination ip may
> > > > > be from
> > > > > another network?
> > > > 
> > > > netconsole can work with another network.
> > > > 
> > > > (step 1) Verify that UDP packets are reachable. You can test with
> > > > 
> > > >          # echo test > /dev/udp/213.136.82.171/6666
> > > > 
> > > >          if you are using bash.
> > > 
> > > After this on remote machine was created folder with name of router
> > > external ip address.
> > > Inside this folder was places one file with name of current day.
> > > This
> > > file has size 0 of bytes and not contain "test" message inside.
> > > That is how it should be?
> > 
> > The message should be written to the log file. If not written, UDP
> > packets
> > are dropped somewhere. You need to solve this problem first.
> 
> I found root cause this problem. Here culprit udplogger, because it not
> flush buffers when terminated by ctrl-c.
> 
> Here my pull request with fix this problem:
> https://github.com/kohsuke/udplogger/pull/1/

Thank you. But excuse me?
Something unexpected must be happening in your environment.

udplogger will flush buffers upon '\n' or timeout (default is 10 seconds) or
too long line (default is 65536 bytes).

> 
> Also i fixed two segfault:
> 
> 1) When send two messages in one second from different hosts or ports.
> For reproduce just run
> "echo test > /dev/udp/127.0.0.1/6666 && echo test >
> /dev/udp/127.0.0.1/6666"
> in console.

I can't observe such problem.
udplogger is ready to concurrently receive from multiple sources.

2018-01-06 23:30:08 127.0.0.1:33637 test
2018-01-06 23:30:08 127.0.0.1:47459 test
2018-01-06 23:32:52 127.0.0.1:36343 test
2018-01-06 23:32:52 127.0.0.1:49087 test
2018-01-06 23:32:53 127.0.0.1:43124 test
2018-01-06 23:32:53 127.0.0.1:40711 test
2018-01-06 23:32:53 127.0.0.1:48455 test
2018-01-06 23:32:53 127.0.0.1:60887 test
2018-01-06 23:32:53 127.0.0.1:49617 test
2018-01-06 23:32:53 127.0.0.1:56967 test
2018-01-06 23:32:54 127.0.0.1:44289 test
2018-01-06 23:32:54 127.0.0.1:52134 test
2018-01-06 23:32:54 127.0.0.1:57924 test
2018-01-06 23:32:54 127.0.0.1:54044 test
2018-01-06 23:32:54 127.0.0.1:42350 test
2018-01-06 23:32:54 127.0.0.1:56750 test
2018-01-06 23:32:54 127.0.0.1:33790 test
2018-01-06 23:32:54 127.0.0.1:55627 test
2018-01-06 23:32:55 127.0.0.1:46477 test
2018-01-06 23:32:55 127.0.0.1:34978 test
2018-01-06 23:32:55 127.0.0.1:41563 test
2018-01-06 23:32:55 127.0.0.1:34146 test

> 
> 2) When exced limit of open files.
> Just run "echo test > /dev/udp/127.0.0.1/6666" more than 1024 times.
> 

I can't observe such problem.
udplogger switches to a new file upon acrossing 00:00:00 of the local time.
Simply repeating 1024 times can't reach max open files limit.

Are you using special environment? What is the shell? What is the compiler/version?

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Sat, 2018-01-06 at 23:52 +0900, Tetsuo Handa wrote:
> Thank you. But excuse me?
> Something unexpected must be happening in your environment.
> 
> udplogger will flush buffers upon '\n' or timeout (default is 10
> seconds) or
> too long line (default is 65536 bytes).

Very strange because neither '\n' not 10 seconds helps to flush
buffers.
$ echo -e "test\n" > /dev/udp/127.0.0.1/6666
May be I used obsolete source? Could you check this?

> 
> > 
> > Also i fixed two segfault:
> > 
> > 1) When send two messages in one second from different hosts or
> > ports.
> > For reproduce just run
> > "echo test > /dev/udp/127.0.0.1/6666 && echo test >
> > /dev/udp/127.0.0.1/6666"
> > in console.
> 
> I can't observe such problem.
> udplogger is ready to concurrently receive from multiple sources.


Too strange because this condition
https://github.com/kohsuke/udplogger/blob/master/udplogger.c#L82
do not allow open two file in one second.

> > 
> > 2) When exced limit of open files.
> > Just run "echo test > /dev/udp/127.0.0.1/6666" more than 1024
> > times.

How much your "ulimit -n" ?
My is 1024.
$ ulimit -n
1024

May be your ulimit much greater or you launch udplogger under root?

> 
> Are you using special environment? What is the shell? What is the
> compiler/version?
> 

$ gcc --version
gcc (GCC) 7.2.1 20170915 (Red Hat 7.2.1-2)
Copyright (C) 2017 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is
NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR
PURPOSE.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

mikhail wrote:
> > > Also i fixed two segfault:
> > > 
> > > 1) When send two messages in one second from different hosts or
> > > ports.
> > > For reproduce just run
> > > "echo test > /dev/udp/127.0.0.1/6666 && echo test >
> > > /dev/udp/127.0.0.1/6666"
> > > in console.
> > 
> > I can't observe such problem.
> > udplogger is ready to concurrently receive from multiple sources.
> 
> 
> Too strange because this condition
> https://github.com/kohsuke/udplogger/blob/master/udplogger.c#L82
> do not allow open two file in one second.

Oh, you got your copy of modified version of old version.

Please use original latest version at
https://osdn.net/projects/akari/scm/svn/tree/head/branches/udplogger/ .

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Sun, 2018-01-07 at 00:48 +0900, Tetsuo Handa wrote:
> mikhail wrote:
> > > > Also i fixed two segfault:
> > > > 
> > > > 1) When send two messages in one second from different hosts or
> > > > ports.
> > > > For reproduce just run
> > > > "echo test > /dev/udp/127.0.0.1/6666 && echo test >
> > > > /dev/udp/127.0.0.1/6666"
> > > > in console.
> > > 
> > > I can't observe such problem.
> > > udplogger is ready to concurrently receive from multiple sources.
> > 
> > 
> > Too strange because this condition
> > https://github.com/kohsuke/udplogger/blob/master/udplogger.c#L82
> > do not allow open two file in one second.
> 
> Oh, you got your copy of modified version of old version.
> 
> Please use original latest version at
> https://osdn.net/projects/akari/scm/svn/tree/head/branches/udplogger/
>  .


Thanks, I investigated the code of new version udplogger. I understood
why it is not subject to the problems described above. Because it uses
one file for all clients. The old version tried to create a separate
file for each client.

Why you not using git hosting?
Old version is quickly searchable by google.
Look here it's second place in search results:
https://imgur.com/a/IKHY8
And new version is impossible to find in searching engine, it's so sad.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[Tetsuo Handa]

mikhail wrote:
> Thanks, I investigated the code of new version udplogger. I understood
> why it is not subject to the problems described above. Because it uses
> one file for all clients. The old version tried to create a separate
> file for each client.
> 
> Why you not using git hosting?

Because I don't have my git trees. svn is sufficient.

> Old version is quickly searchable by google.

Using old version is fine.
What you are seeing is a bug which exists in kohsuke's version.

> Look here it's second place in search results:
> https://imgur.com/a/IKHY8
> And new version is impossible to find in searching engine, it's so sad.
> 

In my search result, my version is printed first.
URL of my version is explicitly shown in the LCJ2014-en_0.pdf file.
I can't afford investigating modified/variant versions which are called "udplogger".
I don't have control for preventing modified/variant versions from appearing. ;-)

Anyway, please report when you succeeded to reproduce slowdown problem.

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

Re: Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

On Thu, 2017-12-07 at 20:05 -0800, Darrick J. Wong wrote:
> > Hi, can anybody said what here happens? And which info needed for
> > fixing it? Thanks. [16712.376081] INFO: task tracker-store:27121
> > blocked for more than 120 seconds. [16712.376088] Not tainted
> > 4.15.0-rc2-amd-vega+ #10 [16712.376092] "echo 0 >
> > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [16712.376095] tracker-store D13400 27121 1843 0x00000000
> > [16712.376102] Call Trace: [16712.376114] ? __schedule+0x2e3/0xb90
> > [16712.376123] ? wait_for_completion+0x146/0x1e0 [16712.376128]
> > schedule+0x2f/0x90 [16712.376132] schedule_timeout+0x236/0x540
> > [16712.376143] ? mark_held_locks+0x4e/0x80 [16712.376147] ?
> > _raw_spin_unlock_irq+0x29/0x40 [16712.376153] ?
> > wait_for_completion+0x146/0x1e0 [16712.376158]
> > wait_for_completion+0x16e/0x1e0 [16712.376162] ?
> > wake_up_q+0x70/0x70 [16712.376204] ? xfs_buf_read_map+0x134/0x2f0
> > [xfs] [16712.376234] xfs_buf_submit_wait+0xaf/0x520 [xfs]
> 
> 

Stuck waiting for a directory block to read. 
> Slow disk? 
Usual Seagate SATA3 HDD with 7200rpms

> Bad media?
No. If there were problems with the hard drive, we would see errors in
the logs.

Any way you can sure in this if look at smartctl output for HDD.

https://paste.fedoraproject.org/paste/EsELRXoiKzlkR5PYhVmJeg

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

Google Chrome cause locks held in system (kernel 4.15 rc2)

[mikhail]

[-- Attachment #1: Type: text/plain, Size: 24318 bytes --]

Hi,

can anybody said what here happens?
And which info needed for fixing it?
Thanks.

[16712.376081] INFO: task tracker-store:27121 blocked for more than 120
seconds.
[16712.376088]       Not tainted 4.15.0-rc2-amd-vega+ #10
[16712.376092] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[16712.376095] tracker-store   D13400 27121   1843 0x00000000
[16712.376102] Call Trace:
[16712.376114]  ? __schedule+0x2e3/0xb90
[16712.376123]  ? wait_for_completion+0x146/0x1e0
[16712.376128]  schedule+0x2f/0x90
[16712.376132]  schedule_timeout+0x236/0x540
[16712.376143]  ? mark_held_locks+0x4e/0x80
[16712.376147]  ? _raw_spin_unlock_irq+0x29/0x40
[16712.376153]  ? wait_for_completion+0x146/0x1e0
[16712.376158]  wait_for_completion+0x16e/0x1e0
[16712.376162]  ? wake_up_q+0x70/0x70
[16712.376204]  ? xfs_buf_read_map+0x134/0x2f0 [xfs]
[16712.376234]  xfs_buf_submit_wait+0xaf/0x520 [xfs]
[16712.376263]  xfs_buf_read_map+0x134/0x2f0 [xfs]
[16712.376293]  ? xfs_trans_read_buf_map+0xc3/0x580 [xfs]
[16712.376325]  xfs_trans_read_buf_map+0xc3/0x580 [xfs]
[16712.376353]  xfs_da_read_buf+0xd3/0x120 [xfs]
[16712.376387]  xfs_dir3_block_read+0x35/0x70 [xfs]
[16712.376413]  xfs_dir2_block_lookup_int+0x4d/0x220 [xfs]
[16712.376444]  xfs_dir2_block_replace+0x4e/0x1d0 [xfs]
[16712.376467]  ? xfs_dir2_isblock+0x2f/0x90 [xfs]
[16712.376492]  xfs_dir_replace+0x10a/0x180 [xfs]
[16712.376526]  xfs_rename+0x586/0xbd0 [xfs]
[16712.376573]  xfs_vn_rename+0xd5/0x140 [xfs]
[16712.376586]  vfs_rename+0x494/0xa00
[16712.376601]  SyS_rename+0x338/0x390
[16712.376618]  entry_SYSCALL_64_fastpath+0x1f/0x96
[16712.376622] RIP: 0033:0x7f02d4a2c167
[16712.376624] RSP: 002b:00007ffd0998cb98 EFLAGS: 00000207 ORIG_RAX:
0000000000000052
[16712.376629] RAX: ffffffffffffffda RBX: 0000000000000001 RCX:
00007f02d4a2c167
[16712.376631] RDX: 0000000000000002 RSI: 0000560149d23fd0 RDI:
0000560149e737b0
[16712.376633] RBP: 000000000000000f R08: 0000560149e73710 R09:
000000000000002c
[16712.376635] R10: 0000000000058a8e R11: 0000000000000207 R12:
0000000000000000
[16712.376638] R13: 0000560149e6c360 R14: 0000560149d23fd0 R15:
0000000000000000
[16712.376828] 
               Showing all locks held in the system:
[16712.376876] 1 lock held by khungtaskd/67:
[16712.376886]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
debug_show_all_locks+0x37/0x190
[16712.377113] 3 locks held by kworker/u16:2/18769:
[16712.377115]  #0:  ((wq_completion)"writeback"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[16712.377128]  #1:  ((work_completion)(&(&wb->dwork)->work)){+.+.},
at: [<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[16712.377138]  #2:  (&type->s_umount_key#63){++++}, at:
[<00000000ecbba71d>] trylock_super+0x16/0x50
[16712.377176] 8 locks held by tracker-store/27121:
[16712.377178]  #0:  (sb_writers#17){.+.+}, at: [<0000000063218e58>]
mnt_want_write+0x20/0x50
[16712.377191]  #1:  (&type->i_mutex_dir_key#7/1){+.+.}, at:
[<0000000026b21526>] lock_rename+0xcf/0xf0
[16712.377208]  #2:  (&inode->i_rwsem){++++}, at: [<00000000b63ba570>]
lock_two_nondirectories+0x6d/0x80
[16712.377219]  #3:  (&inode->i_rwsem/4){+.+.}, at:
[<00000000d44f800a>] vfs_rename+0x337/0xa00
[16712.377232]  #4:  (sb_internal){.+.+}, at: [<00000000b5b0ff39>]
xfs_trans_alloc+0xe2/0x120 [xfs]
[16712.377269]  #5:  (&xfs_dir_ilock_class){++++}, at:
[<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
[16712.377306]  #6:  (&xfs_nondir_ilock_class/2){+.+.}, at:
[<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
[16712.377343]  #7:  (&xfs_nondir_ilock_class/3){+.+.}, at:
[<000000007c7eac55>] xfs_rename+0x45e/0xbd0 [xfs]
[16712.377380] 3 locks held by TaskSchedulerFo/27216:
[16712.377382]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377396]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<0000000086cbd317>] do_truncate+0x66/0xc0
[16712.377408]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
[16712.377443] 3 locks held by TaskSchedulerFo/27217:
[16712.377445]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377457]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<0000000086cbd317>] do_truncate+0x66/0xc0
[16712.377471]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
[16712.377504] 1 lock held by TaskSchedulerFo/27219:
[16712.377506]  #0:  (sb_writers#17){.+.+}, at: [<0000000063218e58>]
mnt_want_write+0x20/0x50
[16712.377521] 3 locks held by TaskSchedulerFo/27287:
[16712.377523]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377535]  #1:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<0000000086cbd317>] do_truncate+0x66/0xc0
[16712.377547]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]
[16712.377581] 3 locks held by TaskSchedulerFo/27289:
[16712.377583]  #0:  (&f->f_pos_lock){+.+.}, at: [<00000000cb121025>]
__fdget_pos+0x48/0x60
[16712.377594]  #1:  (&type->i_mutex_dir_key#7){++++}, at:
[<00000000a872ed9a>] iterate_dir+0x56/0x180
[16712.377607]  #2:  (&xfs_dir_ilock_class){++++}, at:
[<000000002829e721>] xfs_ilock_data_map_shared+0x2c/0x30 [xfs]
[16712.377641] 3 locks held by TaskSchedulerFo/27292:
[16712.377642]  #0:  (sb_writers#17){.+.+}, at: [<0000000054534ce6>]
do_sys_ftruncate.constprop.17+0xda/0x110
[16712.377655]  #1:  (&inode->i_rwsem){++++}, at: [<0000000086cbd317>]
do_truncate+0x66/0xc0
[16712.377667]  #2:  (&(&ip->i_mmaplock)->mr_lock){++++}, at:
[<00000000adf132fd>] xfs_ilock+0x14b/0x200 [xfs]

[16712.377873] =============================================

[18432.706561] INFO: task htop:2690 blocked for more than 120 seconds.
[18432.706575]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.706581] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.706588] htop            D12280  2690   2565 0x00000000
[18432.706602] Call Trace:
[18432.706622]  ? __schedule+0x2e3/0xb90
[18432.706637]  ? rwsem_down_read_failed+0x147/0x190
[18432.706648]  schedule+0x2f/0x90
[18432.706654]  rwsem_down_read_failed+0x118/0x190
[18432.706662]  ? __lock_acquire+0x2c3/0x1270
[18432.706688]  ? call_rwsem_down_read_failed+0x14/0x30
[18432.706695]  call_rwsem_down_read_failed+0x14/0x30
[18432.706710]  down_read+0x97/0xa0
[18432.706719]  proc_pid_cmdline_read+0xd2/0x4a0
[18432.706731]  ? debug_check_no_obj_freed+0x160/0x248
[18432.706753]  ? __vfs_read+0x33/0x170
[18432.706759]  __vfs_read+0x33/0x170
[18432.706781]  vfs_read+0x9e/0x150
[18432.706792]  SyS_read+0x55/0xc0
[18432.706807]  entry_SYSCALL_64_fastpath+0x1f/0x96
[18432.706814] RIP: 0033:0x7fc2d8f4ae01
[18432.706819] RSP: 002b:00007fffedb1f998 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[18432.706827] RAX: ffffffffffffffda RBX: 000056139647bc10 RCX:
00007fc2d8f4ae01
[18432.706831] RDX: 0000000000001000 RSI: 00007fffedb1fa60 RDI:
0000000000000007
[18432.706835] RBP: 000056139696f483 R08: 000056139696f483 R09:
0000000000000005
[18432.706839] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000007
[18432.706844] R13: 000056139696f3f0 R14: 00005613961bb8a0 R15:
00005613961bc5e0
[18432.707027] INFO: task Chrome_IOThread:27225 blocked for more than
120 seconds.
[18432.707034]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.707039] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.707045] Chrome_IOThread D11304 27225   3654 0x00000000
[18432.707057] Call Trace:
[18432.707070]  ? __schedule+0x2e3/0xb90
[18432.707086]  ? __lock_page+0xa9/0x180
[18432.707095]  schedule+0x2f/0x90
[18432.707102]  io_schedule+0x12/0x40
[18432.707109]  __lock_page+0xe9/0x180
[18432.707121]  ? page_cache_tree_insert+0x130/0x130
[18432.707138]  deferred_split_scan+0x2b6/0x300
[18432.707160]  shrink_slab.part.47+0x1f8/0x590
[18432.707179]  ? percpu_ref_put_many+0x84/0x100
[18432.707197]  shrink_node+0x2f4/0x300
[18432.707219]  do_try_to_free_pages+0xca/0x350
[18432.707236]  try_to_free_pages+0x140/0x350
[18432.707259]  __alloc_pages_slowpath+0x43c/0x1080
[18432.707298]  __alloc_pages_nodemask+0x3ac/0x430
[18432.707316]  alloc_pages_vma+0x7c/0x200
[18432.707331]  __handle_mm_fault+0x8a1/0x1230
[18432.707359]  handle_mm_fault+0x14c/0x310
[18432.707373]  __do_page_fault+0x28c/0x530
[18432.707450]  do_page_fault+0x32/0x270
[18432.707470]  page_fault+0x22/0x30
[18432.707478] RIP: 0033:0x7f9f336ac4ef
[18432.707482] RSP: 002b:00007f9f1533c968 EFLAGS: 00010206
[18432.707491] RAX: 00003d60824b4000 RBX: 00000000000885c8 RCX:
0000000000001040
[18432.707495] RDX: 0000000000001040 RSI: 00003d602692c400 RDI:
00003d60824b4000
[18432.707499] RBP: 00007f9f1533c9a0 R08: 0000000000000089 R09:
00003d602692d440
[18432.707503] R10: 00007f9f1533caf0 R11: 0000000000000000 R12:
00003d602c90f3c0
[18432.707507] R13: 0000000000000010 R14: 00000000000885b8 R15:
00003d60824b4000
[18432.707539] INFO: task TaskSchedulerFo:9369 blocked for more than
120 seconds.
[18432.707546]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.707551] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.707557] TaskSchedulerFo D11224  9369   3654 0x00000000
[18432.707568] Call Trace:
[18432.707581]  ? __schedule+0x2e3/0xb90
[18432.707596]  ? rwsem_down_read_failed+0x147/0x190
[18432.707605]  schedule+0x2f/0x90
[18432.707611]  rwsem_down_read_failed+0x118/0x190
[18432.707618]  ? __lock_acquire+0x2c3/0x1270
[18432.707643]  ? call_rwsem_down_read_failed+0x14/0x30
[18432.707650]  call_rwsem_down_read_failed+0x14/0x30
[18432.707665]  down_read+0x97/0xa0
[18432.707673]  SyS_madvise+0x859/0x920
[18432.707682]  ? SyS_rename+0xfc/0x390
[18432.707695]  ? trace_hardirqs_on_caller+0xed/0x180
[18432.707704]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[18432.707720]  ? entry_SYSCALL_64_fastpath+0x1f/0x96
[18432.707726]  entry_SYSCALL_64_fastpath+0x1f/0x96
[18432.707731] RIP: 0033:0x7f9f3363c4a7
[18432.707735] RSP: 002b:00007f9ebe2805c8 EFLAGS: 00000206 ORIG_RAX:
000000000000001c
[18432.707743] RAX: ffffffffffffffda RBX: 00007f9ebe2806d0 RCX:
00007f9f3363c4a7
[18432.707747] RDX: 0000000000000004 RSI: 0000000000041000 RDI:
00003d6073c5d000
[18432.707751] RBP: 00007f9ebe280600 R08: 0000000000000000 R09:
000000000000018d
[18432.707755] R10: 0000000000000000 R11: 0000000000000206 R12:
0000000000000000
[18432.707759] R13: 0000000000021796 R14: 00000000be280601 R15:
00007f9ebe2806d0
[18432.707998] INFO: task kworker/3:1:10525 blocked for more than 120
seconds.
[18432.708004]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.708009] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.708015] kworker/3:1     D13784 10525      2 0x80000000
[18432.708055] Workqueue: events async_pf_execute [kvm]
[18432.708063] Call Trace:
[18432.708075]  ? __schedule+0x2e3/0xb90
[18432.708094]  schedule+0x2f/0x90
[18432.708100]  io_schedule+0x12/0x40
[18432.708108]  __lock_page_or_retry+0x2e4/0x350
[18432.708121]  ? page_cache_tree_insert+0x130/0x130
[18432.708137]  do_swap_page+0x721/0x9f0
[18432.708149]  ? __lock_acquire+0x2c3/0x1270
[18432.708163]  __handle_mm_fault+0xa5c/0x1230
[18432.708209]  handle_mm_fault+0x14c/0x310
[18432.708222]  __get_user_pages+0x1b0/0x6e0
[18432.708244]  get_user_pages_remote+0x13a/0x200
[18432.708281]  async_pf_execute+0x96/0x280 [kvm]
[18432.708303]  process_one_work+0x25e/0x6c0
[18432.708320]  worker_thread+0x3a/0x390
[18432.708323]  ? process_one_work+0x6c0/0x6c0
[18432.708325]  kthread+0x15d/0x180
[18432.708338]  ? kthread_create_worker_on_cpu+0x70/0x70
[18432.708341]  ret_from_fork+0x24/0x30
[18432.708353] INFO: task kworker/3:2:13474 blocked for more than 120
seconds.
[18432.708355]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18432.708357] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18432.708358] kworker/3:2     D14176 13474      2 0x80000000
[18432.708369] Workqueue: events async_pf_execute [kvm]
[18432.708371] Call Trace:
[18432.708384]  ? __schedule+0x2e3/0xb90
[18432.708395]  schedule+0x2f/0x90
[18432.708396]  io_schedule+0x12/0x40
[18432.708399]  __lock_page_or_retry+0x2e4/0x350
[18432.708403]  ? page_cache_tree_insert+0x130/0x130
[18432.708407]  do_swap_page+0x721/0x9f0
[18432.708411]  ? __lock_acquire+0x2c3/0x1270
[18432.708415]  __handle_mm_fault+0xa5c/0x1230
[18432.708425]  handle_mm_fault+0x14c/0x310
[18432.708432]  __get_user_pages+0x1b0/0x6e0
[18432.708443]  get_user_pages_remote+0x13a/0x200
[18432.708457]  async_pf_execute+0x96/0x280 [kvm]
[18432.708464]  process_one_work+0x25e/0x6c0
[18432.708472]  worker_thread+0x3a/0x390
[18432.708478]  ? process_one_work+0x6c0/0x6c0
[18432.708481]  kthread+0x15d/0x180
[18432.708485]  ? kthread_create_worker_on_cpu+0x70/0x70
[18432.708491]  ret_from_fork+0x24/0x30
[18432.708507] 
               Showing all locks held in the system:
[18432.708526] 1 lock held by khungtaskd/67:
[18432.708527]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
debug_show_all_locks+0x37/0x190
[18432.708637] 1 lock held by htop/2690:
[18432.708638]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
proc_pid_cmdline_read+0xd2/0x4a0
[18432.708657] 1 lock held by CPU 0/KVM/3893:
[18432.708658]  #0:  (&vcpu->mutex){+.+.}, at: [<00000000ff3fb7f4>]
vcpu_load+0x17/0x60 [kvm]
[18432.708759] 2 locks held by Chrome_IOThread/27225:
[18432.708760]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18432.708766]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590
[18432.708773] 1 lock held by CacheThread_Blo/27264:
[18432.708774]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708780] 1 lock held by Chrome_HistoryT/27286:
[18432.708781]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708788] 1 lock held by TaskSchedulerFo/9369:
[18432.708788]  #0:  (&mm->mmap_sem){++++}, at: [<00000000603ee2cd>]
SyS_madvise+0x859/0x920
[18432.708794] 1 lock held by TaskSchedulerFo/12373:
[18432.708795]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708802] 1 lock held by TaskSchedulerFo/13115:
[18432.708803]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708809] 1 lock held by TaskSchedulerFo/13125:
[18432.708810]  #0:  (&mm->mmap_sem){++++}, at: [<000000003933f0be>]
vm_mmap_pgoff+0xa5/0x120
[18432.708816] 1 lock held by TaskSchedulerBa/13514:
[18432.708817]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18432.708977] 1 lock held by tracker-store/5038:
[18432.708978]  #0:  (&sb->s_type->i_mutex_key#20){++++}, at:
[<00000000c3f6e04c>] xfs_ilock+0x195/0x200 [xfs]
[18432.709033] 2 locks held by kworker/3:1/10525:
[18432.709034]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709040]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709049] 2 locks held by kworker/3:2/13474:
[18432.709050]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709056]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18432.709064] 2 locks held by cc1/14068:
[18432.709065]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18432.709070]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590

[18432.709078] =============================================


[18555.587276] INFO: task htop:2690 blocked for more than 120 seconds.
[18555.587281]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587283] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587285] htop            D12280  2690   2565 0x00000000
[18555.587290] Call Trace:
[18555.587298]  ? __schedule+0x2e3/0xb90
[18555.587303]  ? rwsem_down_read_failed+0x147/0x190
[18555.587307]  schedule+0x2f/0x90
[18555.587309]  rwsem_down_read_failed+0x118/0x190
[18555.587312]  ? __lock_acquire+0x2c3/0x1270
[18555.587320]  ? call_rwsem_down_read_failed+0x14/0x30
[18555.587323]  call_rwsem_down_read_failed+0x14/0x30
[18555.587328]  down_read+0x97/0xa0
[18555.587331]  proc_pid_cmdline_read+0xd2/0x4a0
[18555.587335]  ? debug_check_no_obj_freed+0x160/0x248
[18555.587343]  ? __vfs_read+0x33/0x170
[18555.587344]  __vfs_read+0x33/0x170
[18555.587351]  vfs_read+0x9e/0x150
[18555.587354]  SyS_read+0x55/0xc0
[18555.587359]  entry_SYSCALL_64_fastpath+0x1f/0x96
[18555.587372] RIP: 0033:0x7fc2d8f4ae01
[18555.587373] RSP: 002b:00007fffedb1f998 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[18555.587376] RAX: ffffffffffffffda RBX: 000056139647bc10 RCX:
00007fc2d8f4ae01
[18555.587377] RDX: 0000000000001000 RSI: 00007fffedb1fa60 RDI:
0000000000000007
[18555.587378] RBP: 000056139696f483 R08: 000056139696f483 R09:
0000000000000005
[18555.587380] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000007
[18555.587381] R13: 000056139696f3f0 R14: 00005613961bb8a0 R15:
00005613961bc5e0
[18555.587516] INFO: task Chrome_IOThread:27225 blocked for more than
120 seconds.
[18555.587519]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587521] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587522] Chrome_IOThread D11304 27225   3654 0x00000000
[18555.587526] Call Trace:
[18555.587531]  ? __schedule+0x2e3/0xb90
[18555.587537]  ? __lock_page+0xa9/0x180
[18555.587539]  schedule+0x2f/0x90
[18555.587542]  io_schedule+0x12/0x40
[18555.587544]  __lock_page+0xe9/0x180
[18555.587548]  ? page_cache_tree_insert+0x130/0x130
[18555.587553]  deferred_split_scan+0x2b6/0x300
[18555.587560]  shrink_slab.part.47+0x1f8/0x590
[18555.587566]  ? percpu_ref_put_many+0x84/0x100
[18555.587572]  shrink_node+0x2f4/0x300
[18555.587579]  do_try_to_free_pages+0xca/0x350
[18555.587584]  try_to_free_pages+0x140/0x350
[18555.587592]  __alloc_pages_slowpath+0x43c/0x1080
[18555.587605]  __alloc_pages_nodemask+0x3ac/0x430
[18555.587611]  alloc_pages_vma+0x7c/0x200
[18555.587617]  __handle_mm_fault+0x8a1/0x1230
[18555.587626]  handle_mm_fault+0x14c/0x310
[18555.587631]  __do_page_fault+0x28c/0x530
[18555.587637]  do_page_fault+0x32/0x270
[18555.587641]  page_fault+0x22/0x30
[18555.587643] RIP: 0033:0x7f9f336ac4ef
[18555.587644] RSP: 002b:00007f9f1533c968 EFLAGS: 00010206
[18555.587646] RAX: 00003d60824b4000 RBX: 00000000000885c8 RCX:
0000000000001040
[18555.587648] RDX: 0000000000001040 RSI: 00003d602692c400 RDI:
00003d60824b4000
[18555.587649] RBP: 00007f9f1533c9a0 R08: 0000000000000089 R09:
00003d602692d440
[18555.587650] R10: 00007f9f1533caf0 R11: 0000000000000000 R12:
00003d602c90f3c0
[18555.587651] R13: 0000000000000010 R14: 00000000000885b8 R15:
00003d60824b4000


[18555.587666] INFO: task CacheThread_Blo:27264 blocked for more than
120 seconds.
[18555.587669]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587672] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587674] CacheThread_Blo D12488 27264   3654 0x00000000
[18555.587680] Call Trace:
[18555.587687]  ? __schedule+0x2e3/0xb90
[18555.587694]  ? rwsem_down_read_failed+0x147/0x190
[18555.587699]  schedule+0x2f/0x90
[18555.587702]  rwsem_down_read_failed+0x118/0x190
[18555.587713]  ? call_rwsem_down_read_failed+0x14/0x30
[18555.587715]  call_rwsem_down_read_failed+0x14/0x30
[18555.587720]  down_read+0x97/0xa0
[18555.587723]  __do_page_fault+0x493/0x530
[18555.587727]  ? trace_hardirqs_on_caller+0xed/0x180
[18555.587732]  do_page_fault+0x32/0x270
[18555.587735]  page_fault+0x22/0x30
[18555.587737] RIP: 0033:0x55c9558374c0
[18555.587738] RSP: 002b:00007f9efed7b648 EFLAGS: 00010206
[18555.587740] RAX: 0000000000000128 RBX: 0000000000000200 RCX:
00007f9efed7b658
[18555.587741] RDX: 00000000000000b0 RSI: 00000000a1010000 RDI:
00003d60252f1088
[18555.587743] RBP: 00007f9efed7b680 R08: 00007f9f1d5eb520 R09:
00000000ffff0001
[18555.587744] R10: 0000000000000000 R11: 0000000000b10000 R12:
00003d6066f02c00
[18555.587745] R13: 0000000000000000 R14: 0000000000000128 R15:
00003d60252f1088
[18555.587754] INFO: task Chrome_HistoryT:27286 blocked for more than
120 seconds.
[18555.587756]       Not tainted 4.15.0-rc2-amd-vega+ #10
[18555.587757] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[18555.587759] Chrome_HistoryT D11432 27286   3654 0x00000000
[18555.587762] Call Trace:
[18555.587766]  ? __schedule+0x2e3/0xb90
[18555.587771]  ? rwsem_down_read_failed+0x147/0x190
[18555.587774]  schedule+0x2f/0x90
[18555.587776]  rwsem_down_read_failed+0x118/0x190
[18555.587784]  ? call_rwsem_down_read_failed+0x14/0x30
[18555.587786]  call_rwsem_down_read_failed+0x14/0x30
[18555.587790]  down_read+0x97/0xa0
[18555.587792]  __do_page_fault+0x493/0x530
[18555.587797]  ? SyS_futex+0x12d/0x180
[18555.587799]  ? trace_hardirqs_on_caller+0xed/0x180
[18555.587803]  do_page_fault+0x32/0x270
[18555.587806]  page_fault+0x22/0x30
[18555.587808] RIP: 0033:0x55c95555fa7a
[18555.587809] RSP: 002b:00007f9efdb5ac70 EFLAGS: 00010202
[18555.587811] RAX: 00007f9f1d5a7498 RBX: 000000000000000a RCX:
000000000000000b
[18555.587812] RDX: 000000000000000a RSI: 0000000000000000 RDI:
00003d60258bb200
[18555.587813] RBP: 00007f9efdb5aca0 R08: 0000000000000002 R09:
00003d602c693580
[18555.587814] R10: 000000000000000d R11: 0000000000000001 R12:
000000000000000a
[18555.587816] R13: 0000000000000001 R14: 00003d60258bb200 R15:
0000000000000001
[18555.588004] 
               Showing all locks held in the system:
[18555.588014] 1 lock held by khungtaskd/67:
[18555.588016]  #0:  (tasklist_lock){.+.+}, at: [<00000000a615f1dc>]
debug_show_all_locks+0x37/0x190
[18555.588124] 1 lock held by htop/2690:
[18555.588125]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
proc_pid_cmdline_read+0xd2/0x4a0
[18555.588162] 1 lock held by CPU 0/KVM/3893:
[18555.588163]  #0:  (&vcpu->mutex){+.+.}, at: [<00000000ff3fb7f4>]
vcpu_load+0x17/0x60 [kvm]
[18555.588278] 1 lock held by atop/15452:
[18555.588279]  #0:  (&mm->mmap_sem){++++}, at: [<000000003ae69604>]
proc_pid_cmdline_read+0xd2/0x4a0
[18555.588306] 2 locks held by Chrome_IOThread/27225:
[18555.588307]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18555.588318]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590
[18555.588330] 1 lock held by CacheThread_Blo/27264:
[18555.588332]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588340] 1 lock held by Chrome_HistoryT/27286:
[18555.588341]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588348] 1 lock held by TaskSchedulerFo/9369:
[18555.588349]  #0:  (&mm->mmap_sem){++++}, at: [<00000000603ee2cd>]
SyS_madvise+0x859/0x920
[18555.588356] 1 lock held by TaskSchedulerFo/12373:
[18555.588357]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588363] 1 lock held by TaskSchedulerFo/13115:
[18555.588365]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588371] 1 lock held by TaskSchedulerFo/13125:
[18555.588372]  #0:  (&mm->mmap_sem){++++}, at: [<000000003933f0be>]
vm_mmap_pgoff+0xa5/0x120
[18555.588379] 1 lock held by TaskSchedulerBa/13514:
[18555.588380]  #0:  (&mm->mmap_sem){++++}, at: [<00000000aa62fc68>]
__do_page_fault+0x493/0x530
[18555.588574] 2 locks held by kworker/3:1/10525:
[18555.588575]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588582]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588592] 2 locks held by kworker/3:2/13474:
[18555.588593]  #0:  ((wq_completion)"events"){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588599]  #1:  ((work_completion)(&work->work)){+.+.}, at:
[<000000000f8b6ef4>] process_one_work+0x1d4/0x6c0
[18555.588606] 2 locks held by cc1/14068:
[18555.588608]  #0:  (&mm->mmap_sem){++++}, at: [<0000000012cb6189>]
__do_page_fault+0x17a/0x530
[18555.588613]  #1:  (shrinker_rwsem){++++}, at: [<0000000033d29b77>]
shrink_slab.part.47+0x5b/0x590

[18555.588623] =============================================

--
Regards
Mikhail

[-- Attachment #2: Type: text/html, Size: 33268 bytes --]