Bug 13976 - WARNING: possible circular locking dependency detected 5.2.0-rc1
Summary: WARNING: possible circular locking dependency detected 5.2.0-rc1
Status: RESOLVED FIXED
Alias: None
Product: CifsVFS
Classification: Unclassified
Component: kernel fs (show other bugs)
Version: 3.x
Hardware: x64 Linux
: P5 normal
Target Milestone: ---
Assignee: Steve French
QA Contact:
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-05-29 20:01 UTC by Paulo E. Castro
Modified: 2020-04-01 21:22 UTC (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Paulo E. Castro 2019-05-29 20:01:54 UTC
I hibernate both the server and the client without doing any cleaning ( unmounting ) and when I bring them back, the client sometimes throws the error below.

I won't be able to use the client until I restart the machine.

Though this is happening on the latest rc1, I've witnessed this behaviour on the v5.1 series and previous ones as well.

Regards, 



    PECastro

How to reproduce: Hibernate both client and server and bring them back.
Kernel version: 5.2.0-rc1
OS: Fedora28
cifs package: cifs-utils-6.8-1.fc28.x86_64

<dmesg>

[80492.738361] ======================================================
[80492.738364] WARNING: possible circular locking dependency detected
[80492.738367] 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1 Not tainted
[80492.738370] ------------------------------------------------------
[80492.738373] cifsd/32288 is trying to acquire lock:
[80492.738376] 000000007d281247 (&type->s_umount_key#63){++++}, at: iterate_supers_type+0x5e/0xd0
[80492.738386]
               but task is already holding lock:
[80492.738388] 00000000ed20100a (&(&GlobalMid_Lock)->rlock){+.+.}, at: cifs_reconnect+0x4d/0x750 [cifs]
[80492.738417]
               which lock already depends on the new lock.

[80492.738420]
               the existing dependency chain (in reverse order) is:
[80492.738424]
               -> #1 (&(&GlobalMid_Lock)->rlock){+.+.}:
[80492.738433]        lock_acquire+0x90/0x180
[80492.738439]        _raw_spin_lock+0x2c/0x40
[80492.738451]        _get_xid+0x12/0x50 [cifs]
[80492.738461]        cifs_writepages+0x61/0xd00 [cifs]
[80492.738464]        do_writepages+0x41/0xd0
[80492.738468]        __writeback_single_inode+0x54/0x650
[80492.738472]        writeback_sb_inodes+0x1fc/0x550
[80492.738475]        __writeback_inodes_wb+0x5d/0xb0
[80492.738480]        wb_writeback+0x340/0x4b0
[80492.738483]        wb_workfn+0x43b/0x5c0
[80492.738488]        process_one_work+0x2a5/0x660
[80492.738491]        worker_thread+0x2d/0x3d0
[80492.738494]        kthread+0x113/0x130
[80492.738497]        ret_from_fork+0x3a/0x50
[80492.738500]
               -> #0 (&type->s_umount_key#63){++++}:
[80492.738504]        __lock_acquire+0xa18/0xe10
[80492.738507]        lock_acquire+0x90/0x180
[80492.738510]        down_read+0x28/0xc0
[80492.738516]        iterate_supers_type+0x5e/0xd0
[80492.738524]        cifs_reconnect+0x80/0x750 [cifs]
[80492.738533]        cifs_readv_from_socket+0x137/0x1d0 [cifs]
[80492.738541]        cifs_read_from_socket+0x4a/0x70 [cifs]
[80492.738549]        cifs_demultiplex_thread+0xed/0x820 [cifs]
[80492.738553]        kthread+0x113/0x130
[80492.738555]        ret_from_fork+0x3a/0x50
[80492.738558]
               other info that might help us debug this:

[80492.738560]  Possible unsafe locking scenario:

[80492.738562]        CPU0                    CPU1
[80492.738564]        ----                    ----
[80492.738566]   lock(&(&GlobalMid_Lock)->rlock);
[80492.738568] lock(&type->s_umount_key#63);
[80492.738571] lock(&(&GlobalMid_Lock)->rlock);
[80492.738574]   lock(&type->s_umount_key#63);
[80492.738576]
                *** DEADLOCK ***

[80492.738579] 1 lock held by cifsd/32288:
[80492.738581]  #0: 00000000ed20100a (&(&GlobalMid_Lock)->rlock){+.+.}, at: cifs_reconnect+0x4d/0x750 [cifs]
[80492.738591]
               stack backtrace:
[80492.738595] CPU: 6 PID: 32288 Comm: cifsd Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80492.738598] Hardware name: LENOVO 20378/Lenovo Y50-70, BIOS 9ECN31WW(V1.14) 08/18/2014
[80492.738601] Call Trace:
[80492.738607]  dump_stack+0x67/0x90
[80492.738612]  print_circular_bug.cold.60+0x15c/0x195
[80492.738616]  check_prevs_add+0x766/0xea0
[80492.738622]  ? find_held_lock+0x2d/0x90
[80492.738626]  __lock_acquire+0xa18/0xe10
[80492.738630]  lock_acquire+0x90/0x180
[80492.738634]  ? iterate_supers_type+0x5e/0xd0
[80492.738644]  ? allocate_buffers+0xa0/0xa0 [cifs]
[80492.738649]  down_read+0x28/0xc0
[80492.738653]  ? iterate_supers_type+0x5e/0xd0
[80492.738656]  iterate_supers_type+0x5e/0xd0
[80492.738665]  cifs_reconnect+0x80/0x750 [cifs]
[80492.738674]  cifs_readv_from_socket+0x137/0x1d0 [cifs]
[80492.738683]  cifs_read_from_socket+0x4a/0x70 [cifs]
[80492.738694]  ? cifs_small_buf_get+0x16/0x20 [cifs]
[80492.738703]  cifs_demultiplex_thread+0xed/0x820 [cifs]
[80492.738706]  ? __kthread_parkme+0x4c/0x70
[80492.738715]  ? cifs_handle_standard+0x180/0x180 [cifs]
[80492.738725]  ? cifs_handle_standard+0x180/0x180 [cifs]
[80492.738728]  kthread+0x113/0x130
[80492.738731]  ? kthread_create_on_node+0x60/0x60
[80492.738734]  ret_from_fork+0x3a/0x50
[80609.471622] INFO: task file.so:27701 blocked for more than 122 seconds.
[80609.471632]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80609.471635] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80609.471638] file.so         D13512 27701   3233 0x00000000
[80609.471645] Call Trace:
[80609.471654]  ? __schedule+0x310/0x770
[80609.471661]  schedule+0x30/0xb0
[80609.471665]  schedule_preempt_disabled+0x11/0x20
[80609.471669]  __mutex_lock+0x448/0x8b0
[80609.471674]  ? find_held_lock+0x2d/0x90
[80609.471699]  ? open_shroot+0x76/0x450 [cifs]
[80609.471727]  ? open_shroot+0x76/0x450 [cifs]
[80609.471744]  open_shroot+0x76/0x450 [cifs]
[80609.471756]  ? find_held_lock+0x2d/0x90
[80609.471767]  ? rcu_read_lock_sched_held+0x74/0x80
[80609.471775]  ? __alloc_pages_nodemask+0x36c/0x3c0
[80609.471791]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80609.471808]  smb2_query_path_info+0x18a/0x320 [cifs]
[80609.471826]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80609.471833]  ? rcu_read_lock_sched_held+0x74/0x80
[80609.471851]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80609.471867]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80609.471874]  ? __kmalloc+0x283/0x2b0
[80609.471884]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80609.471897]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80609.471909]  cifs_getattr+0x63/0x1d0 [cifs]
[80609.471915]  vfs_statx+0x89/0xe0
[80609.471921]  __do_sys_newlstat+0x39/0x70
[80609.471929]  do_syscall_64+0x50/0x1b0
[80609.471935]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80609.472014] RIP: 0033:0x7f72e3f454f5
[80609.472021] Code: Bad RIP value.
[80609.472025] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80609.472029] RAX: ffffffffffffffda RBX: 000055a6c7372050 RCX: 00007f72e3f454f5
[80609.472032] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c7371050
[80609.472035] RBP: 00007ffda0d33220 R08: 000055a6c7371040 R09: 0000000000000001
[80609.472038] R10: 000055a6c737101d R11: 0000000000000246 R12: 000055a6c7371050
[80609.472042] R13: 000055a6c7371025 R14: 000055a6c7371024 R15: 000055a6c737105d
[80609.472050] INFO: task file.so:27763 blocked for more than 122 seconds.
[80609.472054]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80609.472056] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80609.472060] file.so         D13944 27763   3233 0x00000000
[80609.472065] Call Trace:
[80609.472071]  ? __schedule+0x310/0x770
[80609.472077]  schedule+0x30/0xb0
[80609.472081]  schedule_preempt_disabled+0x11/0x20
[80609.472084]  __mutex_lock+0x448/0x8b0
[80609.472089]  ? find_held_lock+0x2d/0x90
[80609.472100]  ? open_shroot+0x76/0x450 [cifs]
[80609.472114]  ? open_shroot+0x76/0x450 [cifs]
[80609.472125]  open_shroot+0x76/0x450 [cifs]
[80609.472132]  ? find_held_lock+0x2d/0x90
[80609.472139]  ? rcu_read_lock_sched_held+0x74/0x80
[80609.472143]  ? __alloc_pages_nodemask+0x36c/0x3c0
[80609.472158]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80609.472169]  smb2_query_path_info+0x18a/0x320 [cifs]
[80609.472180]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80609.472185]  ? rcu_read_lock_sched_held+0x74/0x80
[80609.472196]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80609.472207]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80609.472212]  ? __kmalloc+0x283/0x2b0
[80609.472223]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80609.472235]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80609.472246]  cifs_getattr+0x63/0x1d0 [cifs]
[80609.472252]  vfs_statx+0x89/0xe0
[80609.472257]  __do_sys_newlstat+0x39/0x70
[80609.472265]  do_syscall_64+0x50/0x1b0
[80609.472270]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80609.472273] RIP: 0033:0x7f72e3f454f5
[80609.472278] Code: Bad RIP value.
[80609.472281] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80609.472285] RAX: ffffffffffffffda RBX: 000055a6c7372050 RCX: 00007f72e3f454f5
[80609.472288] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c7371050
[80609.472291] RBP: 00007ffda0d33220 R08: 000055a6c7371040 R09: 0000000000000001
[80609.472294] R10: 000055a6c737101d R11: 0000000000000246 R12: 000055a6c7371050
[80609.472297] R13: 000055a6c7371025 R14: 000055a6c7371024 R15: 000055a6c737105d
[80609.472305] INFO: task file.so:27809 blocked for more than 122 seconds.
[80609.472399]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80609.472402] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80609.472405] file.so         D14200 27809   3233 0x00000000
[80609.472411] Call Trace:
[80609.472416]  ? __schedule+0x310/0x770
[80609.472421]  schedule+0x30/0xb0
[80609.472425]  schedule_preempt_disabled+0x11/0x20
[80609.472429]  __mutex_lock+0x448/0x8b0
[80609.472433]  ? find_held_lock+0x2d/0x90
[80609.472445]  ? open_shroot+0x76/0x450 [cifs]
[80609.472458]  ? open_shroot+0x76/0x450 [cifs]
[80609.472479]  open_shroot+0x76/0x450 [cifs]
[80609.472485]  ? find_held_lock+0x2d/0x90
[80609.472490]  ? rcu_read_lock_sched_held+0x74/0x80
[80609.472493]  ? __alloc_pages_nodemask+0x36c/0x3c0
[80609.472504]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80609.472513]  smb2_query_path_info+0x18a/0x320 [cifs]
[80609.472521]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80609.472525]  ? rcu_read_lock_sched_held+0x74/0x80
[80609.472533]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80609.472542]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80609.472545]  ? __kmalloc+0x283/0x2b0
[80609.472553]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80609.472566]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80609.472575]  cifs_getattr+0x63/0x1d0 [cifs]
[80609.472580]  vfs_statx+0x89/0xe0
[80609.472585]  __do_sys_newlstat+0x39/0x70
[80609.472591]  do_syscall_64+0x50/0x1b0
[80609.472595]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80609.472598] RIP: 0033:0x7f72e3f454f5
[80609.472603] Code: Bad RIP value.
[80609.472605] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80609.472608] RAX: ffffffffffffffda RBX: 000055a6c7372050 RCX: 00007f72e3f454f5
[80609.472611] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c7371050
[80609.472614] RBP: 00007ffda0d33220 R08: 000055a6c7371040 R09: 0000000000000001
[80609.472617] R10: 000055a6c737101d R11: 0000000000000246 R12: 000055a6c7371050
[80609.472620] R13: 000055a6c7371025 R14: 000055a6c7371024 R15: 000055a6c737105d
[80609.472627] INFO: lockdep is turned off.
[80732.350522] INFO: task file.so:9608 blocked for more than 122 seconds.
[80732.350539]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.350543] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.350546] file.so         D11704  9608   3233 0x00004000
[80732.350552] Call Trace:
[80732.350562]  ? __schedule+0x310/0x770
[80732.350568]  ? __mutex_lock+0xcb/0x8b0
[80732.350574]  schedule+0x30/0xb0
[80732.350578]  schedule_preempt_disabled+0x11/0x20
[80732.350581]  __mutex_lock+0x448/0x8b0
[80732.350587]  ? find_nls+0x16/0x80
[80732.350606]  ? smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.350623]  ? smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.350634]  smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.350641]  ? wait_woken+0x80/0x80
[80732.350653]  smb2_plain_req_init+0x4b/0x290 [cifs]
[80732.350659]  ? _raw_spin_unlock+0x24/0x40
[80732.350669]  SMB2_open_init+0x6c/0x700 [cifs]
[80732.350683]  open_shroot+0x174/0x450 [cifs]
[80732.350702]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80732.350712]  smb2_query_path_info+0x18a/0x320 [cifs]
[80732.350722]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80732.350727]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.350737]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80732.350746]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80732.350751]  ? __kmalloc+0x283/0x2b0
[80732.350762]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80732.350772]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80732.350782]  cifs_getattr+0x63/0x1d0 [cifs]
[80732.350787]  vfs_statx+0x89/0xe0
[80732.350792]  __do_sys_newlstat+0x39/0x70
[80732.350799]  do_syscall_64+0x50/0x1b0
[80732.350803]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80732.350807] RIP: 0033:0x7f72e3f454f5
[80732.350813] Code: Bad RIP value.
[80732.350817] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80732.350820] RAX: ffffffffffffffda RBX: 000055a6c73850e0 RCX: 00007f72e3f454f5
[80732.350823] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c73840e0
[80732.350825] RBP: 00007ffda0d33220 R08: 0000000000000003 R09: 0000000000000000
[80732.350828] R10: 000055a6c73840ad R11: 0000000000000246 R12: 000055a6c73840e0
[80732.350831] R13: 000055a6c73840b5 R14: 000055a6c73840b4 R15: 000055a6c73840ed
[80732.350842] INFO: task kworker/6:2:1159 blocked for more than 122 seconds.
[80732.350845]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.350848] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.350850] kworker/6:2     D11096  1159      2 0x80004000
[80732.350864] Workqueue: cifsiod smb2_reconnect_server [cifs]
[80732.350866] Call Trace:
[80732.350871]  ? __schedule+0x310/0x770
[80732.350876]  schedule+0x30/0xb0
[80732.350879]  schedule_preempt_disabled+0x11/0x20
[80732.350882]  __mutex_lock+0x448/0x8b0
[80732.350890]  ? cifs_mark_open_files_invalid+0x56/0x80 [cifs]
[80732.350900]  ? cifs_mark_open_files_invalid+0x56/0x80 [cifs]
[80732.350906]  cifs_mark_open_files_invalid+0x56/0x80 [cifs]
[80732.350916]  smb2_reconnect.part.23+0x20f/0x5a0 [cifs]
[80732.350922]  ? _raw_spin_lock+0x2c/0x40
[80732.350932]  smb2_reconnect_server+0x142/0x200 [cifs]
[80732.350939]  process_one_work+0x2a5/0x660
[80732.350944]  ? process_one_work+0x660/0x660
[80732.350948]  worker_thread+0x2d/0x3d0
[80732.350952]  ? process_one_work+0x660/0x660
[80732.350955]  kthread+0x113/0x130
[80732.350958]  ? kthread_create_on_node+0x60/0x60
[80732.350962]  ret_from_fork+0x3a/0x50
[80732.350973] INFO: task sadc:27559 blocked for more than 122 seconds.
[80732.350976]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.350978] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.350981] sadc            D11184 27559      1 0x00000000
[80732.350985] Call Trace:
[80732.350990]  ? __schedule+0x310/0x770
[80732.350993]  ? __mutex_lock+0xcb/0x8b0
[80732.350997]  schedule+0x30/0xb0
[80732.351000]  schedule_preempt_disabled+0x11/0x20
[80732.351003]  __mutex_lock+0x448/0x8b0
[80732.351007]  ? find_nls+0x16/0x80
[80732.351027]  ? smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.351038]  ? smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.351046]  smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.351061]  smb2_plain_req_init+0x4b/0x290 [cifs]
[80732.351073]  SMB2_open_init+0x6c/0x700 [cifs]
[80732.351083]  ? cifs_small_buf_release.part.10+0x11/0x20 [cifs]
[80732.351087]  ? kmem_cache_free+0x130/0x2c0
[80732.351097]  smb2_query_info_compound+0x180/0x3a0 [cifs]
[80732.351104]  ? lookup_fast+0xc8/0x430
[80732.351110]  ? lockref_get_not_dead+0xc/0x30
[80732.351113]  ? lookup_fast+0xc8/0x430
[80732.351128]  ? smb2_queryfs+0x70/0xf0 [cifs]
[80732.351138]  smb2_queryfs+0x70/0xf0 [cifs]
[80732.351147]  cifs_statfs+0xb4/0x370 [cifs]
[80732.351152]  statfs_by_dentry+0x52/0x70
[80732.351155]  vfs_statfs+0x16/0xc0
[80732.351159]  user_statfs+0x54/0xa0
[80732.351163]  __do_sys_statfs+0x20/0x50
[80732.351168]  do_syscall_64+0x50/0x1b0
[80732.351172]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80732.351175] RIP: 0033:0x7febb87c6657
[80732.351179] Code: Bad RIP value.
[80732.351181] RSP: 002b:00007fff19fb1208 EFLAGS: 00000246 ORIG_RAX: 0000000000000089
[80732.351185] RAX: ffffffffffffffda RBX: 00007fff19fb13b0 RCX: 00007febb87c6657
[80732.351188] RDX: 0000000000000008 RSI: 00007fff19fb1210 RDI: 00007fff19fb13b0
[80732.351190] RBP: 00007fff19fb1210 R08: 0000000000000000 R09: 00007fff19fb13b5
[80732.351192] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fff19fb12c0
[80732.351194] R13: 00007fff19fb13b0 R14: 0000000000000009 R15: 0000000000000000
[80732.351200] INFO: task file.so:27578 blocked for more than 122 seconds.
[80732.351203]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.351205] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.351207] file.so         D12488 27578   3233 0x00004000
[80732.351212] Call Trace:
[80732.351216]  ? __schedule+0x310/0x770
[80732.351218]  ? __mutex_lock+0x4a0/0x8b0
[80732.351222]  schedule+0x30/0xb0
[80732.351225]  schedule_preempt_disabled+0x11/0x20
[80732.351228]  __mutex_lock+0x448/0x8b0
[80732.351232]  ? find_nls+0x16/0x80
[80732.351241]  ? smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.351252]  ? smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.351270]  smb2_reconnect.part.23+0x1c9/0x5a0 [cifs]
[80732.351285]  ? wait_woken+0x80/0x80
[80732.351294]  smb2_plain_req_init+0x4b/0x290 [cifs]
[80732.351305]  ? cifs_small_buf_release.part.10+0x11/0x20 [cifs]
[80732.351316]  SMB2_open_init+0x6c/0x700 [cifs]
[80732.351328]  smb2_query_info_compound+0x180/0x3a0 [cifs]
[80732.351362]  ? lookup_fast+0xc8/0x430
[80732.351381]  ? lockref_get_not_dead+0xc/0x30
[80732.351386]  ? lookup_fast+0xc8/0x430
[80732.351416]  ? smb2_queryfs+0x70/0xf0 [cifs]
[80732.351436]  smb2_queryfs+0x70/0xf0 [cifs]
[80732.351458]  cifs_statfs+0xb4/0x370 [cifs]
[80732.351463]  statfs_by_dentry+0x52/0x70
[80732.351468]  vfs_statfs+0x16/0xc0
[80732.351472]  user_statfs+0x54/0xa0
[80732.351479]  __do_sys_statfs+0x20/0x50
[80732.351487]  do_syscall_64+0x50/0x1b0
[80732.351492]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80732.351496] RIP: 0033:0x7f72e3f45657
[80732.351500] Code: Bad RIP value.
[80732.351504] RSP: 002b:00007ffda0d33318 EFLAGS: 00000246 ORIG_RAX: 0000000000000089
[80732.351507] RAX: ffffffffffffffda RBX: 000055a6c736fed8 RCX: 00007f72e3f45657
[80732.351510] RDX: 0000000000000000 RSI: 00007ffda0d33320 RDI: 000055a6c736fed8
[80732.351513] RBP: 00007ffda0d33320 R08: 00007f72e4213c40 R09: 0000000000000026
[80732.351517] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffda0d333e0
[80732.351520] R13: 00007ffda0d333d8 R14: 000055a6c7348c68 R15: 000055a6c7367c80
[80732.351529] INFO: task file.so:27701 blocked for more than 245 seconds.
[80732.351543]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.351546] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.351549] file.so         D13512 27701   3233 0x00000000
[80732.351556] Call Trace:
[80732.351562]  ? __schedule+0x310/0x770
[80732.351568]  schedule+0x30/0xb0
[80732.351582]  schedule_preempt_disabled+0x11/0x20
[80732.351589]  __mutex_lock+0x448/0x8b0
[80732.351594]  ? find_held_lock+0x2d/0x90
[80732.351608]  ? open_shroot+0x76/0x450 [cifs]
[80732.351631]  ? open_shroot+0x76/0x450 [cifs]
[80732.351653]  open_shroot+0x76/0x450 [cifs]
[80732.351662]  ? find_held_lock+0x2d/0x90
[80732.351670]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.351676]  ? __alloc_pages_nodemask+0x36c/0x3c0
[80732.351693]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80732.351715]  smb2_query_path_info+0x18a/0x320 [cifs]
[80732.351739]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80732.351744]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.351757]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80732.351780]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80732.351796]  ? __kmalloc+0x283/0x2b0
[80732.351809]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80732.351824]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80732.351848]  cifs_getattr+0x63/0x1d0 [cifs]
[80732.351855]  vfs_statx+0x89/0xe0
[80732.351878]  __do_sys_newlstat+0x39/0x70
[80732.351897]  do_syscall_64+0x50/0x1b0
[80732.351903]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80732.351907] RIP: 0033:0x7f72e3f454f5
[80732.351913] Code: Bad RIP value.
[80732.351916] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80732.351920] RAX: ffffffffffffffda RBX: 000055a6c7372050 RCX: 00007f72e3f454f5
[80732.351924] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c7371050
[80732.351928] RBP: 00007ffda0d33220 R08: 000055a6c7371040 R09: 0000000000000001
[80732.351933] R10: 000055a6c737101d R11: 0000000000000246 R12: 000055a6c7371050
[80732.351937] R13: 000055a6c7371025 R14: 000055a6c7371024 R15: 000055a6c737105d
[80732.351947] INFO: task file.so:27763 blocked for more than 245 seconds.
[80732.351951]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.351955] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.351959] file.so         D13944 27763   3233 0x00000000
[80732.351975] Call Trace:
[80732.351991]  ? __schedule+0x310/0x770
[80732.352003]  schedule+0x30/0xb0
[80732.352008]  schedule_preempt_disabled+0x11/0x20
[80732.352012]  __mutex_lock+0x448/0x8b0
[80732.352017]  ? find_held_lock+0x2d/0x90
[80732.352031]  ? open_shroot+0x76/0x450 [cifs]
[80732.352067]  ? open_shroot+0x76/0x450 [cifs]
[80732.352081]  open_shroot+0x76/0x450 [cifs]
[80732.352090]  ? find_held_lock+0x2d/0x90
[80732.352098]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.352104]  ? __alloc_pages_nodemask+0x36c/0x3c0
[80732.352121]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80732.352135]  smb2_query_path_info+0x18a/0x320 [cifs]
[80732.352159]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80732.352175]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.352187]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80732.352201]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80732.352208]  ? __kmalloc+0x283/0x2b0
[80732.352221]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80732.352236]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80732.352250]  cifs_getattr+0x63/0x1d0 [cifs]
[80732.352258]  vfs_statx+0x89/0xe0
[80732.352264]  __do_sys_newlstat+0x39/0x70
[80732.352274]  do_syscall_64+0x50/0x1b0
[80732.352280]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80732.352284] RIP: 0033:0x7f72e3f454f5
[80732.352290] Code: Bad RIP value.
[80732.352294] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80732.352298] RAX: ffffffffffffffda RBX: 000055a6c7372050 RCX: 00007f72e3f454f5
[80732.352369] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c7371050
[80732.352373] RBP: 00007ffda0d33220 R08: 000055a6c7371040 R09: 0000000000000001
[80732.352377] R10: 000055a6c737101d R11: 0000000000000246 R12: 000055a6c7371050
[80732.352380] R13: 000055a6c7371025 R14: 000055a6c7371024 R15: 000055a6c737105d
[80732.352391] INFO: task file.so:27809 blocked for more than 245 seconds.
[80732.352395]       Not tainted 5.2.0-rc1.1.PEC40-00198-g4c4364477e1d #1
[80732.352398] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[80732.352401] file.so         D14200 27809   3233 0x00000000
[80732.352411] Call Trace:
[80732.352417]  ? __schedule+0x310/0x770
[80732.352424]  schedule+0x30/0xb0
[80732.352429]  schedule_preempt_disabled+0x11/0x20
[80732.352433]  __mutex_lock+0x448/0x8b0
[80732.352438]  ? find_held_lock+0x2d/0x90
[80732.352451]  ? open_shroot+0x76/0x450 [cifs]
[80732.352468]  ? open_shroot+0x76/0x450 [cifs]
[80732.352481]  open_shroot+0x76/0x450 [cifs]
[80732.352490]  ? find_held_lock+0x2d/0x90
[80732.352499]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.352504]  ? __alloc_pages_nodemask+0x36c/0x3c0
[80732.352522]  ? smb2_query_path_info+0x18a/0x320 [cifs]
[80732.352536]  smb2_query_path_info+0x18a/0x320 [cifs]
[80732.352560]  ? cifs_get_inode_info+0x1bf/0x6b0 [cifs]
[80732.352566]  ? rcu_read_lock_sched_held+0x74/0x80
[80732.352579]  cifs_get_inode_info+0x1fa/0x6b0 [cifs]
[80732.352602]  ? build_path_from_dentry_optional_prefix+0x262/0x5c0 [cifs]
[80732.352609]  ? __kmalloc+0x283/0x2b0
[80732.352631]  ? build_path_from_dentry_optional_prefix+0x27f/0x5c0 [cifs]
[80732.352646]  cifs_revalidate_dentry_attr+0xd1/0x3c0 [cifs]
[80732.352660]  cifs_getattr+0x63/0x1d0 [cifs]
[80732.352666]  vfs_statx+0x89/0xe0
[80732.352673]  __do_sys_newlstat+0x39/0x70
[80732.352682]  do_syscall_64+0x50/0x1b0
[80732.352689]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[80732.352693] RIP: 0033:0x7f72e3f454f5
[80732.352698] Code: Bad RIP value.
[80732.352702] RSP: 002b:00007ffda0d33108 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[80732.352706] RAX: ffffffffffffffda RBX: 000055a6c7372050 RCX: 00007f72e3f454f5
[80732.352711] RDX: 00007ffda0d33150 RSI: 00007ffda0d33150 RDI: 000055a6c7371050
[80732.352715] RBP: 00007ffda0d33220 R08: 000055a6c7371040 R09: 0000000000000001
[80732.352719] R10: 000055a6c737101d R11: 0000000000000246 R12: 000055a6c7371050
[80732.352722] R13: 000055a6c7371025 R14: 000055a6c7371024 R15: 000055a6c737105d
[80732.352732] INFO: lockdep is turned off.
</dmesg>
Comment 1 Oleksandr Natalenko 2019-08-04 12:06:48 UTC
This is still the case for me with Samba v4.10.6 on server and v5.2.6 kernel on the client.

Once I restart server with mountpoints being mounted on the client and not unmounted prior to restart, the mountpoints stall, and the client tasks stuck with the following stack trace:

===
srp 04 13:47:52 spock kernel: dolphin         D    0  1039    873 0x00000080
srp 04 13:47:52 spock kernel: Call Trace:
srp 04 13:47:52 spock kernel:  schedule+0x8c/0x250
srp 04 13:47:52 spock kernel:  schedule_preempt_disabled+0x6c/0x140
srp 04 13:47:52 spock kernel:  __mutex_lock.isra.0+0x28d/0x540
srp 04 13:47:52 spock kernel:  open_shroot+0xf5/0x640 [cifs]
srp 04 13:47:52 spock kernel:  smb2_query_path_info+0x19d/0x330 [cifs]
srp 04 13:47:52 spock kernel:  cifs_get_inode_info+0x3c8/0xa70 [cifs]
srp 04 13:47:52 spock kernel:  cifs_revalidate_dentry_attr+0x12d/0x3f0 [cifs]
srp 04 13:47:52 spock kernel:  cifs_getattr+0x5b/0x190 [cifs]
srp 04 13:47:52 spock kernel:  __se_sys_newlstat+0x8e/0x100
srp 04 13:47:52 spock kernel:  do_syscall_64+0x5f/0x1d0
srp 04 13:47:52 spock kernel:  entry_SYSCALL_64_after_hwframe+0x44/0xa9
===
Comment 2 Steve French 2020-04-01 21:22:22 UTC
Fixed in 5.4 kernel (and later) and was backported to stable for 5.3.4, 5.2.18 etc) See patch https://patchwork.kernel.org/patch/11143873/