* INFO: task hung in iterate_supers
@ 2018-07-10 10:30 syzbot
2018-07-10 10:34 ` Tetsuo Handa
2022-08-11 6:01 ` INFO: task hung in iterate_supers Tetsuo Handa
0 siblings, 2 replies; 8+ messages in thread
From: syzbot @ 2018-07-10 10:30 UTC (permalink / raw)
To: linux-fsdevel, linux-kernel, syzkaller-bugs, viro
Hello,
syzbot found the following crash on:
HEAD commit: d00d6d9a339d Add linux-next specific files for 20180709
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=111179b2400000
kernel config: https://syzkaller.appspot.com/x/.config?x=94fe2b586beccacd
dashboard link: https://syzkaller.appspot.com/bug?extid=2349f5067b1772c1d8a5
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
syzkaller repro:https://syzkaller.appspot.com/x/repro.syz?x=174329b2400000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11229044400000
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+2349f5067b1772c1d8a5@syzkaller.appspotmail.com
INFO: task syz-executor687:4459 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D23544 4459 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad5912da8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dac44 RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dac40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4479 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D25408 4479 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0x10c/0x1e0 fs/sync.c:115
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad58f1da8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dac5c RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dac58 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4492 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D22992 4492 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad58d0da8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dac74 RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dac70 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4497 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D25408 4497 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad58afda8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dac8c RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dac88 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4503 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D24512 4503 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad588eda8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006daca4 RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006daca0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4521 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D23648 4521 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad586dda8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dacbc RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dacb8 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4524 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D23640 4524 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad584cda8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dacd4 RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dacd0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4534 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D23864 4534 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad582bda8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dacec RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dace8 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4548 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D25408 4548 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad580ada8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dad04 RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dad00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: task syz-executor687:4556 blocked for more than 140 seconds.
Not tainted 4.18.0-rc3-next-20180709+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor687 D24480 4556 4456 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2853 [inline]
__schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
schedule+0xfb/0x450 kernel/sched/core.c:3545
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:269 [inline]
rwsem_down_read_failed+0x362/0x600 kernel/locking/rwsem-xadd.c:286
call_rwsem_down_read_failed+0x18/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0xc3/0x1d0 kernel/locking/rwsem.c:26
iterate_supers+0xe2/0x290 fs/super.c:728
ksys_sync+0xec/0x1e0 fs/sync.c:113
__ia32_sys_sync+0xe/0x20 fs/sync.c:124
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4498c9
Code: e8 1c e8 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 ab d2 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0ad57e9da8 EFLAGS: 00000293 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00000000006dad1c RCX: 00000000004498c9
RDX: 00000000004498c9 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00000000006dad18 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0030656c69662f2e
R13: 3d6e6f6973726576 R14: 64663d736e617274 R15: 0000000000000001
INFO: lockdep is turned off.
NMI backtrace for cpu 0
CPU: 0 PID: 899 Comm: khungtaskd Not tainted 4.18.0-rc3-next-20180709+ #2
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.5+0x19/0xce lib/nmi_backtrace.c:103
nmi_trigger_cpumask_backtrace+0x151/0x192 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:143 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
watchdog+0xb39/0x10b0 kernel/hung_task.c:265
kthread+0x345/0x410 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt+0x6/0x10
arch/x86/include/asm/irqflags.h:54
---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.
syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with
syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches
^ permalink raw reply [flat|nested] 8+ messages in thread* Re: INFO: task hung in iterate_supers 2018-07-10 10:30 INFO: task hung in iterate_supers syzbot @ 2018-07-10 10:34 ` Tetsuo Handa 2018-07-11 10:19 ` Tetsuo Handa 2022-08-11 6:01 ` INFO: task hung in iterate_supers Tetsuo Handa 1 sibling, 1 reply; 8+ messages in thread From: Tetsuo Handa @ 2018-07-10 10:34 UTC (permalink / raw) To: viro; +Cc: syzbot, linux-fsdevel, linux-kernel, syzkaller-bugs Since syzbot found a C reproducer, I reproduced locally with below change applied. ---------------------------------------- diff --git a/kernel/hung_task.c b/kernel/hung_task.c index 32b4794..aca1cca 100644 --- a/kernel/hung_task.c +++ b/kernel/hung_task.c @@ -115,13 +115,6 @@ static void check_hung_task(struct task_struct *t, unsigned long timeout) sysctl_hung_task_warnings--; pr_err("INFO: task %s:%d blocked for more than %ld seconds.\n", t->comm, t->pid, timeout); - pr_err(" %s %s %.*s\n", - print_tainted(), init_utsname()->release, - (int)strcspn(init_utsname()->version, " "), - init_utsname()->version); - pr_err("\"echo 0 > /proc/sys/kernel/hung_task_timeout_secs\"" - " disables this message.\n"); - sched_show_task(t); hung_task_show_lock = true; } @@ -190,8 +183,20 @@ static void check_hung_uninterruptible_tasks(unsigned long timeout) } unlock: rcu_read_unlock(); - if (hung_task_show_lock) - debug_show_all_locks(); + if (hung_task_show_lock) { + extern void lockdep_print_held_locks(struct task_struct *p); + + rcu_read_lock(); + for_each_process_thread(g, t) { + if (!t->lockdep_depth) + continue; + sched_show_task(t); + lockdep_print_held_locks(t); + touch_nmi_watchdog(); + touch_all_softlockup_watchdogs(); + } + rcu_read_unlock(); + } if (hung_task_call_panic) { trigger_all_cpu_backtrace(); panic("hung_task: blocked tasks"); diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c index 5fa4d31..e3de52d 100644 --- a/kernel/locking/lockdep.c +++ b/kernel/locking/lockdep.c @@ -561,7 +561,7 @@ static void print_lock(struct held_lock *hlock) printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip); } -static void lockdep_print_held_locks(struct task_struct *p) +void lockdep_print_held_locks(struct task_struct *p) { int i, depth = READ_ONCE(p->lockdep_depth); @@ -575,7 +575,7 @@ static void lockdep_print_held_locks(struct task_struct *p) * and it's not the current task. */ if (p->state == TASK_RUNNING && p != current) - return; + printk("RUNNING TASK\n"); for (i = 0; i < depth; i++) { printk(" #%d: ", i); print_lock(p->held_locks + i); ---------------------------------------- It turned out that, although the reason of stalling v9fs_mount() is currently unknown, the reason of many processes stuck at iterate_supers() is that they are unable to take s->s_umount object due to down_write_nested() below. /* * sget() can have s_umount recursion. * * When it cannot find a suitable sb, it allocates a new * one (this one), and tries again to find a suitable old * one. * * In case that succeeds, it will acquire the s_umount * lock of the old one. Since these are clearly distrinct * locks, and this object isn't exposed yet, there's no * risk of deadlocks. * * Annotate this by putting this lock in a different * subclass. */ down_write_nested(&s->s_umount, SINGLE_DEPTH_NESTING); (The hashed address 00000000d803423d is printed among processes below.) [ 224.224404] INFO: task a.out:5454 blocked for more than 10 seconds. [ 224.230981] INFO: task a.out:5476 blocked for more than 10 seconds. [ 224.237530] INFO: task a.out:5491 blocked for more than 10 seconds. [ 224.242368] INFO: task a.out:5514 blocked for more than 10 seconds. [ 224.246407] INFO: task a.out:5529 blocked for more than 10 seconds. [ 224.250429] INFO: task a.out:5681 blocked for more than 10 seconds. [ 224.254420] INFO: task a.out:5697 blocked for more than 10 seconds. [ 224.258822] INFO: task a.out:5711 blocked for more than 10 seconds. [ 224.262873] INFO: task a.out:5723 blocked for more than 10 seconds. [ 224.266883] INFO: task a.out:5740 blocked for more than 10 seconds. [ 224.270740] INFO: task a.out:5757 blocked for more than 10 seconds. [ 224.272797] INFO: task a.out:5769 blocked for more than 10 seconds. [ 224.274895] INFO: task a.out:5789 blocked for more than 10 seconds. [ 224.276914] INFO: task a.out:5799 blocked for more than 10 seconds. [ 224.278909] INFO: task a.out:5823 blocked for more than 10 seconds. [ 224.280760] INFO: task a.out:5833 blocked for more than 10 seconds. [ 224.282612] INFO: task a.out:5456 blocked for more than 10 seconds. [ 224.284464] INFO: task a.out:5474 blocked for more than 10 seconds. [ 224.286389] INFO: task a.out:5492 blocked for more than 10 seconds. [ 224.288445] INFO: task a.out:5526 blocked for more than 10 seconds. [ 224.290524] INFO: task a.out:5570 blocked for more than 10 seconds. [ 224.292544] INFO: task a.out:5679 blocked for more than 10 seconds. [ 224.294551] INFO: task a.out:5693 blocked for more than 10 seconds. [ 224.296468] INFO: task a.out:5707 blocked for more than 10 seconds. [ 224.298317] INFO: task a.out:5720 blocked for more than 10 seconds. [ 224.300167] INFO: task a.out:5745 blocked for more than 10 seconds. [ 224.302098] INFO: task a.out:5759 blocked for more than 10 seconds. [ 224.304110] INFO: task a.out:5770 blocked for more than 10 seconds. [ 224.306111] INFO: task a.out:5786 blocked for more than 10 seconds. [ 224.308129] INFO: task a.out:5798 blocked for more than 10 seconds. [ 224.310068] INFO: task a.out:5813 blocked for more than 10 seconds. [ 224.312073] INFO: task a.out:5825 blocked for more than 10 seconds. [ 224.313958] INFO: task a.out:5458 blocked for more than 10 seconds. [ 224.315811] INFO: task a.out:5477 blocked for more than 10 seconds. [ 224.317721] INFO: task a.out:5485 blocked for more than 10 seconds. [ 224.319709] INFO: task a.out:5521 blocked for more than 10 seconds. [ 224.321709] INFO: task a.out:5530 blocked for more than 10 seconds. [ 224.323633] INFO: task a.out:5575 blocked for more than 10 seconds. [ 224.325630] INFO: task a.out:5686 blocked for more than 10 seconds. [ 224.327633] INFO: task a.out:5698 blocked for more than 10 seconds. [ 224.329602] INFO: task a.out:5719 blocked for more than 10 seconds. [ 224.331501] INFO: task a.out:5734 blocked for more than 10 seconds. [ 224.333448] INFO: task a.out:5748 blocked for more than 10 seconds. [ 224.335411] INFO: task a.out:5763 blocked for more than 10 seconds. [ 224.337343] INFO: task a.out:5775 blocked for more than 10 seconds. [ 224.339231] INFO: task a.out:5788 blocked for more than 10 seconds. [ 224.341156] INFO: task a.out:5800 blocked for more than 10 seconds. [ 224.343165] INFO: task a.out:5821 blocked for more than 10 seconds. [ 224.345157] INFO: task a.out:5461 blocked for more than 10 seconds. [ 224.347063] INFO: task a.out:5475 blocked for more than 10 seconds. [ 224.348970] INFO: task a.out:5486 blocked for more than 10 seconds. [ 224.351030] INFO: task a.out:5567 blocked for more than 10 seconds. [ 224.353060] INFO: task a.out:5577 blocked for more than 10 seconds. [ 224.354909] INFO: task a.out:5672 blocked for more than 10 seconds. [ 224.356761] INFO: task a.out:5690 blocked for more than 10 seconds. [ 224.358740] INFO: task a.out:5712 blocked for more than 10 seconds. [ 224.360722] INFO: task a.out:5722 blocked for more than 10 seconds. [ 224.362725] INFO: task a.out:5742 blocked for more than 10 seconds. [ 224.364623] INFO: task a.out:5754 blocked for more than 10 seconds. [ 224.366649] INFO: task a.out:5768 blocked for more than 10 seconds. [ 224.368651] INFO: task a.out:5782 blocked for more than 10 seconds. [ 224.370523] INFO: task a.out:5796 blocked for more than 10 seconds. [ 224.372377] INFO: task a.out:5811 blocked for more than 10 seconds. [ 224.374224] INFO: task a.out:5824 blocked for more than 10 seconds. [ 224.376253] INFO: task a.out:5481 blocked for more than 10 seconds. [ 224.378262] INFO: task a.out:5494 blocked for more than 10 seconds. [ 224.380189] INFO: task a.out:5528 blocked for more than 10 seconds. [ 224.382210] INFO: task a.out:5576 blocked for more than 10 seconds. [ 224.384217] INFO: task a.out:5662 blocked for more than 10 seconds. [ 224.386101] INFO: task a.out:5675 blocked for more than 10 seconds. [ 224.387969] INFO: task a.out:5692 blocked for more than 10 seconds. [ 224.389825] INFO: task a.out:5708 blocked for more than 10 seconds. [ 224.391758] INFO: task a.out:5721 blocked for more than 10 seconds. [ 224.393657] INFO: task a.out:5736 blocked for more than 10 seconds. [ 224.395577] INFO: task a.out:5750 blocked for more than 10 seconds. [ 224.397571] INFO: task a.out:5767 blocked for more than 10 seconds. [ 224.399579] INFO: task a.out:5783 blocked for more than 10 seconds. [ 224.401539] INFO: task a.out:5795 blocked for more than 10 seconds. [ 224.403410] INFO: task a.out:5810 blocked for more than 10 seconds. [ 224.405301] INFO: task a.out:5465 blocked for more than 10 seconds. [ 224.407194] INFO: task a.out:5483 blocked for more than 10 seconds. [ 224.409169] INFO: task a.out:5493 blocked for more than 10 seconds. [ 224.411220] INFO: task a.out:5512 blocked for more than 10 seconds. [ 224.413257] INFO: task a.out:5571 blocked for more than 10 seconds. [ 224.415156] INFO: task a.out:5678 blocked for more than 10 seconds. [ 224.417071] INFO: task a.out:5689 blocked for more than 10 seconds. [ 224.418921] INFO: task a.out:5710 blocked for more than 10 seconds. [ 224.420791] INFO: task a.out:5728 blocked for more than 10 seconds. [ 224.422642] INFO: task a.out:5741 blocked for more than 10 seconds. [ 224.424491] INFO: task a.out:5753 blocked for more than 10 seconds. [ 224.426527] INFO: task a.out:5766 blocked for more than 10 seconds. [ 224.428583] INFO: task a.out:5777 blocked for more than 10 seconds. [ 224.430508] INFO: task a.out:5792 blocked for more than 10 seconds. [ 224.432408] INFO: task a.out:5804 blocked for more than 10 seconds. [ 224.434273] INFO: task a.out:5820 blocked for more than 10 seconds. [ 224.436125] INFO: task a.out:5467 blocked for more than 10 seconds. [ 224.437998] INFO: task a.out:5482 blocked for more than 10 seconds. [ 224.439868] INFO: task a.out:5506 blocked for more than 10 seconds. [ 224.441763] INFO: task a.out:5513 blocked for more than 10 seconds. [ 224.443824] INFO: task a.out:5520 blocked for more than 10 seconds. [ 224.445849] INFO: task a.out:5673 blocked for more than 10 seconds. [ 224.447810] INFO: task a.out:5691 blocked for more than 10 seconds. [ 224.449697] INFO: task a.out:5709 blocked for more than 10 seconds. [ 224.451550] INFO: task a.out:5724 blocked for more than 10 seconds. [ 224.453425] INFO: task a.out:5739 blocked for more than 10 seconds. [ 224.455320] INFO: task a.out:5756 blocked for more than 10 seconds. [ 224.457223] INFO: task a.out:5772 blocked for more than 10 seconds. [ 224.459271] INFO: task a.out:5787 blocked for more than 10 seconds. [ 224.461337] INFO: task a.out:5797 blocked for more than 10 seconds. [ 224.463336] INFO: task a.out:5818 blocked for more than 10 seconds. [ 224.465229] INFO: task a.out:5831 blocked for more than 10 seconds. [ 224.467137] INFO: task a.out:5469 blocked for more than 10 seconds. [ 224.468994] INFO: task a.out:5473 blocked for more than 10 seconds. [ 224.470930] INFO: task a.out:5484 blocked for more than 10 seconds. [ 224.472824] INFO: task a.out:5525 blocked for more than 10 seconds. [ 224.475015] INFO: task a.out:5661 blocked for more than 10 seconds. [ 224.477571] INFO: task a.out:5671 blocked for more than 10 seconds. [ 224.479594] INFO: task a.out:5685 blocked for more than 10 seconds. [ 224.481574] INFO: task a.out:5699 blocked for more than 10 seconds. [ 224.483441] INFO: task a.out:5704 blocked for more than 10 seconds. [ 224.485314] INFO: task a.out:5731 blocked for more than 10 seconds. [ 224.487163] INFO: task a.out:5749 blocked for more than 10 seconds. [ 224.489028] INFO: task a.out:5765 blocked for more than 10 seconds. [ 224.490958] INFO: task a.out:5776 blocked for more than 10 seconds. [ 224.493029] INFO: task a.out:5790 blocked for more than 10 seconds. [ 224.495054] INFO: task a.out:5801 blocked for more than 10 seconds. [ 224.497054] INFO: task a.out:5822 blocked for more than 10 seconds. [ 224.498927] khungtaskd R running task 29656 953 2 0x80000000 [ 224.501027] Call Trace: [ 224.501796] sched_show_task+0x33a/0x420 [ 224.503205] watchdog+0x7c7/0xba0 [ 224.504277] kthread+0x2e5/0x3e0 [ 224.505373] ? reset_hung_task_detector+0x30/0x30 [ 224.506836] ? kthread_delayed_work_timer_fn+0x250/0x250 [ 224.508467] ret_from_fork+0x3a/0x50 [ 224.509645] 1 lock held by khungtaskd/953: [ 224.510933] #0: 00000000a7346670 (rcu_read_lock){....}, at: watchdog+0x673/0xba0 [ 224.513358] a.out D27464 5454 1 0x00000004 [ 224.515294] Call Trace: [ 224.516192] __schedule+0xb55/0x1dd0 [ 224.517399] ? pci_mmcfg_check_reserved+0x120/0x120 [ 224.518997] ? mark_held_locks+0xc8/0x120 [ 224.520392] ? _raw_spin_unlock_irq+0x27/0x70 [ 224.522016] schedule+0x8f/0x1b0 [ 224.523319] rwsem_down_read_failed+0x24c/0x3a0 [ 224.524907] ? rwsem_down_write_failed+0xce0/0xce0 [ 224.526626] ? block_ioctl+0xd7/0x130 [ 224.527932] ? __ia32_sys_tee+0x200/0x200 [ 224.529362] call_rwsem_down_read_failed+0x18/0x30 [ 224.530966] ? call_rwsem_down_read_failed+0x18/0x30 [ 224.532587] down_read+0x4e/0xb0 [ 224.533669] ? iterate_supers+0x113/0x210 [ 224.534939] iterate_supers+0x113/0x210 [ 224.536181] ksys_sync+0xa5/0x170 [ 224.537307] ? sync_filesystem+0x200/0x200 [ 224.538701] ? kasan_check_write+0x14/0x20 [ 224.540061] ? fput+0x18/0x130 [ 224.541107] ? entry_SYSCALL_64_after_hwframe+0x59/0xbe [ 224.542818] ? do_syscall_64+0x21/0x4e0 [ 224.544182] __ia32_sys_sync+0x9/0x10 [ 224.545437] do_syscall_64+0xd6/0x4e0 [ 224.546675] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 224.548256] RIP: 0033:0x7f774b2694d9 [ 224.549409] Code: Bad RIP value. [ 224.550481] RSP: 002b:00007f774b966f18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2 [ 224.552780] RAX: ffffffffffffffda RBX: 0000000000602124 RCX: 00007f774b2694d9 [ 224.554964] RDX: 00007f774b2694d9 RSI: 0000000000000000 RDI: 0000000000000000 [ 224.557068] RBP: 0000000000602120 R08: 00007f774b966f70 R09: 00007f774b966f70 [ 224.559216] R10: 00007f774b966f70 R11: 0000000000000246 R12: 0000000000000000 [ 224.561546] R13: 0000000000008c00 R14: 0000000000000000 R15: 00000000756e0874 [ 224.563801] 1 lock held by a.out/5454: [ 224.564980] #0: 00000000d803423d (&type->s_umount_key#54){.+.+}, at: iterate_supers+0x113/0x210 [ 224.567645] a.out D27464 5476 1 0x00000004 [ 224.569476] Call Trace: [ 224.570350] __schedule+0xb55/0x1dd0 [ 224.571556] ? pci_mmcfg_check_reserved+0x120/0x120 [ 224.573065] ? mark_held_locks+0xc8/0x120 [ 224.574334] ? _raw_spin_unlock_irq+0x27/0x70 [ 224.575721] schedule+0x8f/0x1b0 [ 224.576859] rwsem_down_read_failed+0x24c/0x3a0 [ 224.578280] ? rwsem_down_write_failed+0xce0/0xce0 [ 224.579772] ? lock_downgrade+0x840/0x840 [ 224.581060] ? __ia32_sys_tee+0x200/0x200 [ 224.582311] call_rwsem_down_read_failed+0x18/0x30 [ 224.583831] ? call_rwsem_down_read_failed+0x18/0x30 [ 224.585431] down_read+0x4e/0xb0 [ 224.586487] ? iterate_supers+0x113/0x210 [ 224.587757] iterate_supers+0x113/0x210 [ 224.588984] ksys_sync+0xa5/0x170 [ 224.590073] ? sync_filesystem+0x200/0x200 [ 224.591350] ? entry_SYSCALL_64_after_hwframe+0x59/0xbe [ 224.593043] ? do_syscall_64+0x21/0x4e0 [ 224.594309] __ia32_sys_sync+0x9/0x10 [ 224.595540] do_syscall_64+0xd6/0x4e0 [ 224.596773] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 224.598353] RIP: 0033:0x7f774b2694d9 [ 224.599544] Code: Bad RIP value. [ 224.600702] RSP: 002b:00007f774b945f18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2 [ 224.603112] RAX: ffffffffffffffda RBX: 000000000060213c RCX: 00007f774b2694d9 [ 224.605199] RDX: 00007f774b2694d9 RSI: ffffffffffffff98 RDI: 0000000000000001 [ 224.607302] RBP: 0000000000602138 R08: 0000000000000000 R09: 0000000000000000 [ 224.609402] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 224.611694] R13: 0000000000008c00 R14: 0000000000000000 R15: 00000000756e0874 [ 224.613927] 1 lock held by a.out/5476: [ 224.615168] #0: 00000000d803423d (&type->s_umount_key#54){.+.+}, at: iterate_supers+0x113/0x210 [ 224.618055] a.out D27464 5491 1 0x00000004 [ 224.619811] Call Trace: [ 224.620649] __schedule+0xb55/0x1dd0 [ 224.621788] ? pci_mmcfg_check_reserved+0x120/0x120 [ 224.623301] ? mark_held_locks+0xc8/0x120 [ 224.624570] ? _raw_spin_unlock_irq+0x27/0x70 [ 224.625939] schedule+0x8f/0x1b0 [ 224.627059] rwsem_down_read_failed+0x24c/0x3a0 [ 224.628508] ? rwsem_down_write_failed+0xce0/0xce0 [ 224.630102] ? block_ioctl+0xd7/0x130 [ 224.631385] ? __ia32_sys_tee+0x200/0x200 [ 224.632659] call_rwsem_down_read_failed+0x18/0x30 [ 224.634158] ? call_rwsem_down_read_failed+0x18/0x30 [ 224.635732] down_read+0x4e/0xb0 [ 224.636782] ? iterate_supers+0x113/0x210 [ 224.638064] iterate_supers+0x113/0x210 [ 224.639287] ksys_sync+0xa5/0x170 [ 224.640370] ? sync_filesystem+0x200/0x200 [ 224.641665] ? kasan_check_write+0x14/0x20 [ 224.642994] ? fput+0x18/0x130 [ 224.644073] ? entry_SYSCALL_64_after_hwframe+0x59/0xbe [ 224.645787] ? do_syscall_64+0x21/0x4e0 [ 224.647115] __ia32_sys_sync+0x9/0x10 [ 224.648350] do_syscall_64+0xd6/0x4e0 [ 224.649592] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 224.651178] RIP: 0033:0x7f774b2694d9 [ 224.652356] Code: Bad RIP value. [ 224.653414] RSP: 002b:00007f774b924f18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2 [ 224.655692] RAX: ffffffffffffffda RBX: 0000000000602154 RCX: 00007f774b2694d9 [ 224.657831] RDX: 00007f774b2694d9 RSI: 0000000000000000 RDI: 0000000000000000 [ 224.660026] RBP: 0000000000602150 R08: 0000000000000000 R09: 0000000000000000 [ 224.662220] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 224.664520] R13: 0000000000008c00 R14: 0000000000000000 R15: 00000000756e0874 [ 224.666681] 1 lock held by a.out/5491: [ 224.667890] #0: 00000000d803423d (&type->s_umount_key#54){.+.+}, at: iterate_supers+0x113/0x210 (...snipped...) [ 227.999265] a.out D27464 5463 1 0x00000004 [ 228.001055] Call Trace: [ 228.001867] __schedule+0xb55/0x1dd0 [ 228.003079] ? trace_hardirqs_on+0xd/0x10 [ 228.004417] ? pci_mmcfg_check_reserved+0x120/0x120 [ 228.006059] ? wait_woken+0x2b0/0x2b0 [ 228.007311] schedule+0x8f/0x1b0 [ 228.008433] p9_client_rpc+0x39a/0x1040 [ 228.009721] ? __free_pages_ok+0xfdc/0x1aa0 [ 228.011141] ? trace_event_raw_event_9p_client_res+0x310/0x310 [ 228.013036] ? p9_parse_header+0x12b/0x4f0 [ 228.014435] ? remove_wait_queue+0x1b0/0x1b0 [ 228.015849] ? mark_held_locks+0xc8/0x120 [ 228.017191] ? p9_fd_cancel+0x50/0x1f0 [ 228.018472] p9_client_flush+0xfa/0x1f0 [ 228.019781] ? p9_client_rpc+0x1040/0x1040 [ 228.021204] ? _raw_spin_unlock+0x22/0x30 [ 228.022543] ? p9_fd_cancel+0x50/0x1f0 [ 228.023799] p9_client_rpc+0x9d8/0x1040 [ 228.025095] ? trace_event_raw_event_9p_client_res+0x310/0x310 [ 228.026997] ? p9_idpool_put+0x31/0x40 [ 228.028255] ? mark_held_locks+0xc8/0x120 [ 228.029598] ? mark_held_locks+0xc8/0x120 [ 228.030977] ? remove_wait_queue+0x1b0/0x1b0 [ 228.032414] ? trace_hardirqs_on_caller+0x442/0x5c0 [ 228.034044] ? trace_hardirqs_on+0xd/0x10 [ 228.035434] ? p9_client_stat+0x1e4/0x4a0 [ 228.036790] ? kasan_check_read+0x11/0x20 [ 228.038127] p9_client_clunk+0x80/0x180 [ 228.039431] v9fs_mount+0x515/0x7d0 [ 228.040615] mount_fs+0x81/0x2b0 [ 228.041733] vfs_kern_mount+0x66/0x3c0 [ 228.043241] do_mount+0x366/0x2910 [ 228.044403] ? copy_mount_string+0x20/0x20 [ 228.045780] ? kmem_cache_alloc_trace+0x33c/0x750 [ 228.047370] ? copy_mount_options+0x55/0x2f0 [ 228.048814] ksys_mount+0x7e/0xd0 [ 228.049997] __x64_sys_mount+0xb9/0x150 [ 228.051328] ? trace_hardirqs_on_caller+0x442/0x5c0 [ 228.052925] do_syscall_64+0xd6/0x4e0 [ 228.054171] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 228.055834] RIP: 0033:0x7f774b2694d9 [ 228.057043] Code: Bad RIP value. [ 228.058164] RSP: 002b:00007f774b966f18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5 [ 228.060583] RAX: ffffffffffffffda RBX: 0000000000602124 RCX: 00007f774b2694d9 [ 228.062873] RDX: 0000000020000340 RSI: 00000000200000c0 RDI: 0000000000000000 [ 228.065187] RBP: 0000000000602120 R08: 00000000200003c0 R09: 00007f774b966f70 [ 228.067481] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 228.069793] R13: 0000000000008c00 R14: 0000000000000000 R15: 00000000756e0874 [ 228.072166] 1 lock held by a.out/5463: [ 228.073427] #0: 00000000d803423d (&type->s_umount_key#53/1){+.+.}, at: sget_userns+0x21d/0xb50 (...snipped...) [ 280.160650] a.out D27464 5463 1 0x00000004 [ 280.162434] Call Trace: [ 280.163327] __schedule+0xb55/0x1dd0 [ 280.164569] ? trace_hardirqs_on+0xd/0x10 [ 280.165915] ? pci_mmcfg_check_reserved+0x120/0x120 [ 280.167526] ? wait_woken+0x2b0/0x2b0 [ 280.168818] schedule+0x8f/0x1b0 [ 280.169893] p9_client_rpc+0x39a/0x1040 [ 280.171455] ? __free_pages_ok+0xfdc/0x1aa0 [ 280.172865] ? trace_event_raw_event_9p_client_res+0x310/0x310 [ 280.174679] ? p9_parse_header+0x12b/0x4f0 [ 280.176010] ? remove_wait_queue+0x1b0/0x1b0 [ 280.177452] ? mark_held_locks+0xc8/0x120 [ 280.178830] ? p9_fd_cancel+0x50/0x1f0 [ 280.180109] p9_client_flush+0xfa/0x1f0 [ 280.181436] ? p9_client_rpc+0x1040/0x1040 [ 280.182758] ? _raw_spin_unlock+0x22/0x30 [ 280.184050] ? p9_fd_cancel+0x50/0x1f0 [ 280.185337] p9_client_rpc+0x9d8/0x1040 [ 280.186614] ? trace_event_raw_event_9p_client_res+0x310/0x310 [ 280.188527] ? p9_idpool_put+0x31/0x40 [ 280.189799] ? mark_held_locks+0xc8/0x120 [ 280.191170] ? mark_held_locks+0xc8/0x120 [ 280.192603] ? remove_wait_queue+0x1b0/0x1b0 [ 280.194048] ? trace_hardirqs_on_caller+0x442/0x5c0 [ 280.195666] ? trace_hardirqs_on+0xd/0x10 [ 280.197010] ? p9_client_stat+0x1e4/0x4a0 [ 280.198296] ? kasan_check_read+0x11/0x20 [ 280.199574] p9_client_clunk+0x80/0x180 [ 280.200848] v9fs_mount+0x515/0x7d0 [ 280.202058] mount_fs+0x81/0x2b0 [ 280.203180] vfs_kern_mount+0x66/0x3c0 [ 280.204456] do_mount+0x366/0x2910 [ 280.205664] ? copy_mount_string+0x20/0x20 [ 280.207064] ? kmem_cache_alloc_trace+0x33c/0x750 [ 280.208618] ? copy_mount_options+0x55/0x2f0 [ 280.210027] ksys_mount+0x7e/0xd0 [ 280.211114] __x64_sys_mount+0xb9/0x150 [ 280.212389] ? trace_hardirqs_on_caller+0x442/0x5c0 [ 280.213932] do_syscall_64+0xd6/0x4e0 [ 280.215187] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 280.216849] RIP: 0033:0x7f774b2694d9 [ 280.218063] Code: Bad RIP value. [ 280.219196] RSP: 002b:00007f774b966f18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5 [ 280.221658] RAX: ffffffffffffffda RBX: 0000000000602124 RCX: 00007f774b2694d9 [ 280.223981] RDX: 0000000020000340 RSI: 00000000200000c0 RDI: 0000000000000000 [ 280.226240] RBP: 0000000000602120 R08: 00000000200003c0 R09: 00007f774b966f70 [ 280.228403] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 280.230615] R13: 0000000000008c00 R14: 0000000000000000 R15: 00000000756e0874 [ 280.232804] 1 lock held by a.out/5463: [ 280.234032] #0: 00000000d803423d (&type->s_umount_key#53/1){+.+.}, at: sget_userns+0x21d/0xb50 [ 280.236875] a.out D27464 5481 1 0x00000004 [ 280.238721] Call Trace: [ 280.239610] __schedule+0xb55/0x1dd0 [ 280.240798] ? pci_mmcfg_check_reserved+0x120/0x120 [ 280.242368] ? mark_held_locks+0xc8/0x120 [ 280.243712] ? _raw_spin_unlock_irq+0x27/0x70 [ 280.245182] schedule+0x8f/0x1b0 [ 280.246319] rwsem_down_read_failed+0x24c/0x3a0 [ 280.247852] ? rwsem_down_write_failed+0xce0/0xce0 [ 280.249415] ? lock_downgrade+0x840/0x840 [ 280.250785] ? __ia32_sys_tee+0x200/0x200 [ 280.252169] call_rwsem_down_read_failed+0x18/0x30 [ 280.253773] ? call_rwsem_down_read_failed+0x18/0x30 [ 280.255455] down_read+0x4e/0xb0 [ 280.256585] ? iterate_supers+0x113/0x210 [ 280.257931] iterate_supers+0x113/0x210 [ 280.259220] ksys_sync+0xa5/0x170 [ 280.260386] ? sync_filesystem+0x200/0x200 [ 280.261782] ? entry_SYSCALL_64_after_hwframe+0x59/0xbe [ 280.263495] ? do_syscall_64+0x21/0x4e0 [ 280.264874] __ia32_sys_sync+0x9/0x10 [ 280.266117] do_syscall_64+0xd6/0x4e0 [ 280.267364] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 280.269027] RIP: 0033:0x7f774b2694d9 [ 280.270249] Code: Bad RIP value. [ 280.271390] RSP: 002b:00007f774b945f18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2 [ 280.273819] RAX: ffffffffffffffda RBX: 000000000060213c RCX: 00007f774b2694d9 [ 280.275980] RDX: 00007f774b2694d9 RSI: ffffffffffffff98 RDI: 0000000000000001 [ 280.278234] RBP: 0000000000602138 R08: 0000000000000000 R09: 0000000000000000 [ 280.280421] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 280.282597] R13: 0000000000008c00 R14: 0000000000000000 R15: 00000000756e0874 [ 280.284843] 1 lock held by a.out/5481: [ 280.286118] #0: 00000000d803423d (&type->s_umount_key#54){.+.+}, at: iterate_supers+0x113/0x210 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: INFO: task hung in iterate_supers 2018-07-10 10:34 ` Tetsuo Handa @ 2018-07-11 10:19 ` Tetsuo Handa 2018-07-13 10:09 ` [PATCH] fs: Add to super_blocks list after SB_BORN is set Tetsuo Handa 0 siblings, 1 reply; 8+ messages in thread From: Tetsuo Handa @ 2018-07-11 10:19 UTC (permalink / raw) To: viro; +Cc: syzbot, linux-fsdevel, linux-kernel, syzkaller-bugs On 2018/07/10 19:34, Tetsuo Handa wrote: > It turned out that, although the reason of stalling v9fs_mount() is currently > unknown, the reason of many processes stuck at iterate_supers() is that > they are unable to take s->s_umount object due to down_write_nested() below. > > /* > * sget() can have s_umount recursion. > * > * When it cannot find a suitable sb, it allocates a new > * one (this one), and tries again to find a suitable old > * one. > * > * In case that succeeds, it will acquire the s_umount > * lock of the old one. Since these are clearly distrinct > * locks, and this object isn't exposed yet, there's no > * risk of deadlocks. > * > * Annotate this by putting this lock in a different > * subclass. > */ > down_write_nested(&s->s_umount, SINGLE_DEPTH_NESTING); > Guessing from commit dabe0dc194d5d56d ("vfs: fix the rest of sget() races"), this is an overlooked sget() race. iterate_supers() is calling down_read(&sb_s_umount) on all superblocks found by traversing super_blocks list. But sget_userns() adds "newly created superblock to super_blocks list with ->s_umount held by alloc_super() for write" before "mount_fs() sets SB_BORN flag after returning from type->mount()". Therefore, if type->mount() (e.g. v9fs_mount()) took long after sget() for some reason, processes will be blocked on a superblock on SB_BORN not yet set. Doing the test (which is done after ->s_umount is held) before holding ->s_umount (patch shown below) works for me. Although there seems to be many bugs in v9fs code, I think that making sure that other threads won't try to wait for superblock with SB_BORN not yet set is better. --- fs/super.c | 31 ++++++++++++++++++++++--------- 1 file changed, 22 insertions(+), 9 deletions(-) diff --git a/fs/super.c b/fs/super.c index 50728d9..03c3b3f 100644 --- a/fs/super.c +++ b/fs/super.c @@ -37,6 +37,11 @@ #include <linux/user_namespace.h> #include "internal.h" +static inline bool sb_is_alive(struct super_block *sb) +{ + return sb->s_root && (sb->s_flags & SB_BORN); +} + static int thaw_super_locked(struct super_block *sb); static LIST_HEAD(super_blocks); @@ -407,8 +412,7 @@ static int grab_super(struct super_block *s) __releases(sb_lock) bool trylock_super(struct super_block *sb) { if (down_read_trylock(&sb->s_umount)) { - if (!hlist_unhashed(&sb->s_instances) && - sb->s_root && (sb->s_flags & SB_BORN)) + if (!hlist_unhashed(&sb->s_instances) && sb_is_alive(sb)) return true; up_read(&sb->s_umount); } @@ -590,6 +594,8 @@ static void __iterate_supers(void (*f)(struct super_block *)) spin_lock(&sb_lock); list_for_each_entry(sb, &super_blocks, s_list) { + if (!sb_is_alive(sb)) + continue; if (hlist_unhashed(&sb->s_instances)) continue; sb->s_count++; @@ -620,13 +626,15 @@ void iterate_supers(void (*f)(struct super_block *, void *), void *arg) spin_lock(&sb_lock); list_for_each_entry(sb, &super_blocks, s_list) { + if (!sb_is_alive(sb)) + continue; if (hlist_unhashed(&sb->s_instances)) continue; sb->s_count++; spin_unlock(&sb_lock); down_read(&sb->s_umount); - if (sb->s_root && (sb->s_flags & SB_BORN)) + if (sb_is_alive(sb)) f(sb, arg); up_read(&sb->s_umount); @@ -656,11 +664,13 @@ void iterate_supers_type(struct file_system_type *type, spin_lock(&sb_lock); hlist_for_each_entry(sb, &type->fs_supers, s_instances) { + if (!sb_is_alive(sb)) + continue; sb->s_count++; spin_unlock(&sb_lock); down_read(&sb->s_umount); - if (sb->s_root && (sb->s_flags & SB_BORN)) + if (sb_is_alive(sb)) f(sb, arg); up_read(&sb->s_umount); @@ -689,6 +699,8 @@ static struct super_block *__get_super(struct block_device *bdev, bool excl) if (hlist_unhashed(&sb->s_instances)) continue; if (sb->s_bdev == bdev) { + if (!sb_is_alive(sb)) + continue; sb->s_count++; spin_unlock(&sb_lock); if (!excl) @@ -696,7 +708,7 @@ static struct super_block *__get_super(struct block_device *bdev, bool excl) else down_write(&sb->s_umount); /* still alive? */ - if (sb->s_root && (sb->s_flags & SB_BORN)) + if (sb_is_alive(sb)) return sb; if (!excl) up_read(&sb->s_umount); @@ -813,11 +825,13 @@ struct super_block *user_get_super(dev_t dev) if (hlist_unhashed(&sb->s_instances)) continue; if (sb->s_dev == dev) { + if (!sb_is_alive(sb)) + continue; sb->s_count++; spin_unlock(&sb_lock); down_read(&sb->s_umount); /* still alive? */ - if (sb->s_root && (sb->s_flags & SB_BORN)) + if (sb_is_alive(sb)) return sb; up_read(&sb->s_umount); /* nope, got unmounted */ @@ -916,8 +930,7 @@ int do_remount_sb(struct super_block *sb, int sb_flags, void *data, int force) static void do_emergency_remount_callback(struct super_block *sb) { down_write(&sb->s_umount); - if (sb->s_root && sb->s_bdev && (sb->s_flags & SB_BORN) && - !sb_rdonly(sb)) { + if (sb_is_alive(sb) && sb->s_bdev && !sb_rdonly(sb)) { /* * What lock protects sb->s_flags?? */ @@ -947,7 +960,7 @@ void emergency_remount(void) static void do_thaw_all_callback(struct super_block *sb) { down_write(&sb->s_umount); - if (sb->s_root && sb->s_flags & SB_BORN) { + if (sb_is_alive(sb)) { emergency_thaw_bdev(sb); thaw_super_locked(sb); } else { -- 1.8.3.1 ---------------------------------------- // autogenerated by syzkaller (http://github.com/google/syzkaller) #define _GNU_SOURCE #include <fcntl.h> #include <linux/futex.h> #include <pthread.h> #include <stdio.h> #include <string.h> #include <sys/stat.h> #include <sys/syscall.h> #include <unistd.h> #include <sys/mount.h> #include <signal.h> struct thread_t { int created, running, call; pthread_t th; }; static struct thread_t threads[16]; static void execute_call(int call); static int running; static void* thr(void* arg) { struct thread_t* th = (struct thread_t*)arg; for (;;) { while (!__atomic_load_n(&th->running, __ATOMIC_ACQUIRE)) syscall(SYS_futex, &th->running, FUTEX_WAIT, 0, 0); execute_call(th->call); __atomic_fetch_sub(&running, 1, __ATOMIC_RELAXED); __atomic_store_n(&th->running, 0, __ATOMIC_RELEASE); syscall(SYS_futex, &th->running, FUTEX_WAKE); } return 0; } static void execute(int num_calls) { int call, thread; running = 0; for (call = 0; call < num_calls; call++) { for (thread = 0; thread < sizeof(threads) / sizeof(threads[0]); thread++) { struct thread_t* th = &threads[thread]; if (!th->created) { th->created = 1; pthread_attr_t attr; pthread_attr_init(&attr); pthread_attr_setstacksize(&attr, 128 << 10); pthread_create(&th->th, &attr, thr, th); } if (!__atomic_load_n(&th->running, __ATOMIC_ACQUIRE)) { th->call = call; __atomic_fetch_add(&running, 1, __ATOMIC_RELAXED); __atomic_store_n(&th->running, 1, __ATOMIC_RELEASE); syscall(SYS_futex, &th->running, FUTEX_WAKE); struct timespec ts; ts.tv_sec = 0; ts.tv_nsec = 20 * 1000 * 1000; syscall(SYS_futex, &th->running, FUTEX_WAIT, 1, &ts); if (__atomic_load_n(&running, __ATOMIC_RELAXED)) usleep((call == num_calls - 1) ? 10000 : 1000); break; } } } } static void execute_call(int call) { static int fd[2] = { EOF, EOF }; static char buffer[128] = { }; switch (call) { case 4: sync(); break; case 6: if (pipe(fd) == EOF) kill(0, SIGKILL); break; case 7: mkdir("./file0", 0); break; case 8: snprintf(buffer, sizeof(buffer) - 1, "trans=fd,rfdno=0x%x,wfdno=0x%x,version=9p2000.u,", fd[0], fd[1]); mount(NULL, "./file0", "9p", 0, buffer); break; case 9: write(fd[1], "\x79\x04\x00\x00\x7d\x01\x00\x05\x00\x58\x00\x00\x00\x00\x00\x00" "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00" "\x00\x00\x00\x00\x00\x00\x00\x00\x23\x00\x00\x00\x00\x39\x00\x00" "\x00\x00\x00\x10\x00\x76\x65\x72\x73\x69\x6f\x6e\x3d\x39\x70\x32" "\x30\x30\x30\x2e\x75\x0d\x00\x77\x6c\x61\x6e\x31\x76\x62\x6f\x78" "\x6e\x65\x74\x30\x03\x00\x39\x70\x00\x05\x00\x72\x66\x64\x6e\x6f" "\x0c\x00\x76\x9a\xae\x6d\x5f\xff\xf0\x68\xa6\xbe\x6b\x2c\xc3\xfd" "\x62\x6f\x78\x6e\x65\x74\x31\x28\x7d\x25\x24\x00\x00\x00\x00\x00" "\x00\x00\x00\x00\x00\x00\x00", 135); break; } } int main(int argc, char *argv[]) { int procid; for (procid = 0; procid < 8; procid++) if (fork() == 0) while (1) execute(10); sleep(1000000); return 0; } ---------------------------------------- By the way, iterate_supers_type() was introduced in v3.1 for fs/ubifs/debug.c /* * TODO: this is racy - the file-system might have already been * unmounted and we'd oops in this case. The plan is to fix it with * help of 'iterate_supers_type()' which we should have in v3.0: when * a debugfs opened, we rember FS's UUID in file->private_data. Then * whenever we access the FS via a debugfs file, we iterate all UBIFS * superblocks and fine the one with the same UUID, and take the * locking right. * * The other way to go suggested by Al Viro is to create a separate * 'ubifs-debug' file-system instead. */ but is still not called. Do we want to remove iterate_supers_type() ? ^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH] fs: Add to super_blocks list after SB_BORN is set. 2018-07-11 10:19 ` Tetsuo Handa @ 2018-07-13 10:09 ` Tetsuo Handa 2018-07-13 12:00 ` Al Viro 0 siblings, 1 reply; 8+ messages in thread From: Tetsuo Handa @ 2018-07-13 10:09 UTC (permalink / raw) To: viro; +Cc: syzbot, linux-fsdevel, linux-kernel, syzkaller-bugs More simple version. Is this assumption correct? >From 52f10183f2b921cd946dd4c83d9b1d99bc48914e Mon Sep 17 00:00:00 2001 From: Tetsuo Handa <penguin-kernel@I-love.SKAURA.ne.jp> Date: Fri, 13 Jul 2018 12:15:54 +0900 Subject: [PATCH] fs: Add to super_blocks list after SB_BORN is set. syzbot is reporting hung tasks at iterate_supers() [1]. This is because iterate_supers() is calling down_read(&sb->s_umount) on all superblocks found by traversing super_blocks list while sget_userns() adds "newly created superblock to super_blocks list with ->s_umount held by alloc_super() for write" before "mount_fs() sets SB_BORN flag after returning from type->mount()". If type->mount() took long time after returning from sget() for some reason, e.g. sync() request will be blocked on !SB_BORN superblocks. Also, since security_sb_kern_mount() which is called after SB_BORN is set might involve GFP_KERNEL memory allocation, we can't guarantee that up_write(&sb->s_umount) is called as soon as SB_BORN was set. Therefore, this patch makes sure that newly created superblock is added to super_blocks list immediately before calling up_write(&sb->s_umount). [1] https://syzkaller.appspot.com/bug?id=3c0c173ff55822aacb81ce7ae27a6676fba29a5c Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SKAURA.ne.jp> --- fs/super.c | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/fs/super.c b/fs/super.c index 50728d9..8b2c8cc 100644 --- a/fs/super.c +++ b/fs/super.c @@ -236,6 +236,7 @@ static struct super_block *alloc_super(struct file_system_type *type, int flags, s->s_flags = flags; if (s->s_user_ns != &init_user_ns) s->s_iflags |= SB_I_NODEV; + INIT_LIST_HEAD(&s->s_list); INIT_HLIST_NODE(&s->s_instances); INIT_HLIST_BL_HEAD(&s->s_roots); mutex_init(&s->s_sync_lock); @@ -527,8 +528,6 @@ struct super_block *sget_userns(struct file_system_type *type, } s->s_type = type; strlcpy(s->s_id, type->name, sizeof(s->s_id)); - list_add_tail(&s->s_list, &super_blocks); - hlist_add_head(&s->s_instances, &type->fs_supers); spin_unlock(&sb_lock); get_filesystem(type); register_shrinker_prepared(&s->s_shrink); @@ -1305,6 +1304,12 @@ mount_fs(struct file_system_type *type, int flags, const char *name, void *data) WARN((sb->s_maxbytes < 0), "%s set sb->s_maxbytes to " "negative value (%lld)\n", type->name, sb->s_maxbytes); + if (list_empty(&sb->s_list)) { + spin_lock(&sb_lock); + list_add_tail(&sb->s_list, &super_blocks); + hlist_add_head(&sb->s_instances, &type->fs_supers); + spin_unlock(&sb_lock); + } up_write(&sb->s_umount); free_secdata(secdata); return root; -- 2.7.4 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH] fs: Add to super_blocks list after SB_BORN is set. 2018-07-13 10:09 ` [PATCH] fs: Add to super_blocks list after SB_BORN is set Tetsuo Handa @ 2018-07-13 12:00 ` Al Viro 0 siblings, 0 replies; 8+ messages in thread From: Al Viro @ 2018-07-13 12:00 UTC (permalink / raw) To: Tetsuo Handa; +Cc: syzbot, linux-fsdevel, linux-kernel, syzkaller-bugs On Fri, Jul 13, 2018 at 07:09:03PM +0900, Tetsuo Handa wrote: > More simple version. Is this assumption correct? Racy, for obvious reasons (sget/sget) ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: INFO: task hung in iterate_supers 2018-07-10 10:30 INFO: task hung in iterate_supers syzbot 2018-07-10 10:34 ` Tetsuo Handa @ 2022-08-11 6:01 ` Tetsuo Handa 2022-08-11 6:53 ` Dominique Martinet 1 sibling, 1 reply; 8+ messages in thread From: Tetsuo Handa @ 2022-08-11 6:01 UTC (permalink / raw) To: Eric Van Hensbergen, Latchesar Ionkov, Dominique Martinet, Christian Schoenebeck Cc: linux-fsdevel, syzbot, syzkaller-bugs, v9fs-developer Hello. https://syzkaller.appspot.com/text?tag=CrashReport&x=154869fd080000 suggests that p9_client_rpc() is trapped at infinite retry loop ---------- again: /* Wait for the response */ err = wait_event_killable(req->wq, req->status >= REQ_STATUS_RCVD); /* Make sure our req is coherent with regard to updates in other * threads - echoes to wmb() in the callback */ smp_rmb(); if (err == -ERESTARTSYS && c->status == Connected && type == P9_TFLUSH) { sigpending = 1; clear_thread_flag(TIF_SIGPENDING); goto again; } ---------- which I guess that net/9p/trans_fd.c is failing to call p9_client_cb() in order to update req->status and wake up req->wq. But why does p9 think that Flush operation worth retrying forever? The peer side should be able to detect close of file descriptor on local side due to process termination via SIGKILL, and the peer side should be able to perform appropriate recovery operation even if local side cannot receive response for Flush operation. Thus, why not to give up upon SIGKILL? On 2018/07/10 19:30, syzbot wrote: > Hello, > > syzbot found the following crash on: > > HEAD commit: d00d6d9a339d Add linux-next specific files for 20180709 > git tree: linux-next > console output: https://syzkaller.appspot.com/x/log.txt?x=111179b2400000 > kernel config: https://syzkaller.appspot.com/x/.config?x=94fe2b586beccacd > dashboard link: https://syzkaller.appspot.com/bug?extid=2349f5067b1772c1d8a5 > compiler: gcc (GCC) 8.0.1 20180413 (experimental) > syzkaller repro:https://syzkaller.appspot.com/x/repro.syz?x=174329b2400000 > C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11229044400000 > > IMPORTANT: if you fix the bug, please add the following tag to the commit: > Reported-by: syzbot+2349f5067b1772c1d8a5@syzkaller.appspotmail.com > ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: INFO: task hung in iterate_supers 2022-08-11 6:01 ` INFO: task hung in iterate_supers Tetsuo Handa @ 2022-08-11 6:53 ` Dominique Martinet 0 siblings, 0 replies; 8+ messages in thread From: Dominique Martinet @ 2022-08-11 6:53 UTC (permalink / raw) To: Tetsuo Handa Cc: Eric Van Hensbergen, Latchesar Ionkov, Christian Schoenebeck, linux-fsdevel, syzbot, syzkaller-bugs, v9fs-developer Hi, Tetsuo Handa wrote on Thu, Aug 11, 2022 at 03:01:23PM +0900: > https://syzkaller.appspot.com/text?tag=CrashReport&x=154869fd080000 > suggests that p9_client_rpc() is trapped at infinite retry loop Would be far from the first one, Dmitry brought this up years ago... > But why does p9 think that Flush operation worth retrying forever? I can't answer much more than "it's how it was done"; I started implementing asynchronous flush back when this was first discussed but my implementation introduced a regression somewhere and I never had time to debug it; the main "problem" is that we (currently) have no way of freeing up resources associated with that request if we leave the thread. The first step was adding refcounting to requests and this is somewhat holding up, so all's left now would be to properly clean things up if we leave this call. You can find inspiration in my old patches[1] if you'd like to give it a try: [1] https://lore.kernel.org/all/20181217110111.GB17466@nautica/T/ Note that there is one point that wasn't discussed back then, but according to the 9p man page for flush[2], the request should be considered successful if the original request's reply comes before the flush reply. This might be important e.g. with caching enabled and mkdir, create or unlink with caching enabled as the 9p client has no notion of cache coherency... So even if the caller itself will be busy dealing with a signal at least the cache should be kept coherent, somehow. I don't see any way of doing that with the current 9pfs/9pnet layering, 9pnet cannot call back in the vfs. [2] https://9fans.github.io/plan9port/man/man9/flush.html > The peer side should be able to detect close of file descriptor on local > side due to process termination via SIGKILL, and the peer side should be > able to perform appropriate recovery operation even if local side cannot > receive response for Flush operation. The peer side (= server in my vocabulary) has no idea about processes or file descriptors, it's the 9p client's job to do any such cleanup. The vfs takes care of calling the proper close functions that'll end up in clunk for fids properly, there was a report of fid leak recently but these are rare enough... The problem isn't open fids though, but really resources associated with the request itself; it shouldn't be too hard to do (ignoring any cache coherency issue), but... > Thus, why not to give up upon SIGKILL? ... "Nobody has done it yet". Last year I'd probably have answered that I'm open to funding, but franlky don't have the time anyway; I'll be happy to review and lightly test anything sent my way in my meager free time though. (And yes, I agree ignoring sigkill is bad user experience) -- Dominique ^ permalink raw reply [flat|nested] 8+ messages in thread
* INFO: task hung in iterate_supers
@ 2021-09-13 2:33 Hao Sun
0 siblings, 0 replies; 8+ messages in thread
From: Hao Sun @ 2021-09-13 2:33 UTC (permalink / raw)
To: linux-fsdevel, viro; +Cc: linux-kernel
Hello,
When using Healer to fuzz the latest Linux kernel, the following crash
was triggered.
HEAD commit: 4b93c544e90e-thunderbolt: test: split up test cases
git tree: upstream
console output:
https://drive.google.com/file/d/1gi1OlktAs3lQS5uGyqcOmFdGg-hb5ek8/view?usp=sharing
kernel config: https://drive.google.com/file/d/1c0u2EeRDhRO-ZCxr9MP2VvAtJd6kfg-p/view?usp=sharing
Similar repot: https://groups.google.com/g/syzkaller-bugs/c/N3_ECgVYE0c/m/ubwipYJ6AgAJ
Sorry, I don't have a reproducer for this crash, hope the symbolized
report can help.
If you fix this issue, please add the following tag to the commit:
Reported-by: Hao Sun <sunhao.th@gmail.com>
INFO: task syz-executor:13124 blocked for more than 143 seconds.
Not tainted 5.14.0+ #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor state:D stack:29232 pid:13124 ppid: 12323 flags:0x00404004
Call Trace:
context_switch kernel/sched/core.c:4940 [inline]
__schedule+0xcd9/0x2530 kernel/sched/core.c:6287
schedule+0xd3/0x270 kernel/sched/core.c:6366
rwsem_down_read_slowpath+0x4ee/0x9d0 kernel/locking/rwsem.c:993
__down_read_common kernel/locking/rwsem.c:1214 [inline]
__down_read kernel/locking/rwsem.c:1223 [inline]
down_read+0xe4/0x440 kernel/locking/rwsem.c:1464
iterate_supers+0xdb/0x290 fs/super.c:693
ksys_sync+0x86/0x150 fs/sync.c:114
__do_sys_sync+0xa/0x10 fs/sync.c:125
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x2000000a
RSP: 002b:00007f38a62cbbb8 EFLAGS: 00000a83 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 0000000000000009 RCX: 000000002000000a
RDX: 0000000000004c01 RSI: 0000000000000003 RDI: 000000000000001c
RBP: 00000000000000ab R08: 0000000000000005 R09: 0000000000000006
R10: 0000000000000007 R11: 0000000000000a83 R12: 000000000000000b
R13: 000000000000000c R14: 000000000000000d R15: 00007f38a62cbdc0
INFO: task syz-executor:13127 blocked for more than 143 seconds.
Not tainted 5.14.0+ #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor state:D stack:27752 pid:13127 ppid: 12323 flags:0x00404004
Call Trace:
context_switch kernel/sched/core.c:4940 [inline]
__schedule+0xcd9/0x2530 kernel/sched/core.c:6287
schedule+0xd3/0x270 kernel/sched/core.c:6366
rwsem_down_read_slowpath+0x4ee/0x9d0 kernel/locking/rwsem.c:993
__down_read_common kernel/locking/rwsem.c:1214 [inline]
__down_read kernel/locking/rwsem.c:1223 [inline]
down_read+0xe4/0x440 kernel/locking/rwsem.c:1464
iterate_supers+0xdb/0x290 fs/super.c:693
ksys_sync+0x86/0x150 fs/sync.c:114
__do_sys_sync+0xa/0x10 fs/sync.c:125
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x2000000a
RSP: 002b:00007f38a62aabb8 EFLAGS: 00000a83 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 0000000000000009 RCX: 000000002000000a
RDX: 0000000000004c01 RSI: 0000000000000003 RDI: 000000000000001c
RBP: 00000000000000ab R08: 0000000000000005 R09: 0000000000000006
R10: 0000000000000007 R11: 0000000000000a83 R12: 000000000000000b
R13: 000000000000000c R14: 000000000000000d R15: 00007f38a62aadc0
Showing all locks held in the system:
1 lock held by khungtaskd/1360:
#0: ffffffff8b97dde0 (rcu_read_lock){....}-{1:2}, at:
debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6446
1 lock held by in:imklog/8202:
#0: ffff88801f4d7a70 (&f->f_pos_lock){+.+.}-{3:3}, at:
__fdget_pos+0xe9/0x100 fs/file.c:990
1 lock held by syz-executor/11128:
#0: ffff88810f7600e0 (&type->s_umount_key#69/1){+.+.}-{3:3}, at:
alloc_super+0x1dd/0xab0 fs/super.c:229
1 lock held by syz-executor/11714:
#0: ffff8880163760e0 (&type->s_umount_key#69/1){+.+.}-{3:3}, at:
alloc_super+0x1dd/0xab0 fs/super.c:229
1 lock held by syz-executor/12302:
#0: ffff888026ad60e0 (&type->s_umount_key#69/1){+.+.}-{3:3}, at:
alloc_super+0x1dd/0xab0 fs/super.c:229
1 lock held by syz-executor/13124:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/13127:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/15012:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/15016:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/15627:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/15630:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/16215:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
1 lock held by syz-executor/16219:
#0: ffff88810f7600e0 (&type->s_umount_key#73){.+.+}-{3:3}, at:
iterate_supers+0xdb/0x290 fs/super.c:693
=============================================
NMI backtrace for cpu 3
CPU: 3 PID: 1360 Comm: khungtaskd Not tainted 5.14.0+ #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
Call Trace:
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:105
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:105
nmi_trigger_cpumask_backtrace+0x1e1/0x220 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
watchdog+0xcc8/0x1010 kernel/hung_task.c:295
kthread+0x3e5/0x4d0 kernel/kthread.c:319
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
Sending NMI from CPU 3 to CPUs 0-2:
NMI backtrace for cpu 1
CPU: 1 PID: 4939 Comm: systemd-journal Not tainted 5.14.0+ #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
RIP: 0010:__sanitizer_cov_trace_pc+0x1a/0x40 kernel/kcov.c:197
Code: 00 c3 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 65 48 8b 0c 25
40 f0 01 00 bf 02 00 00 00 48 89 ce 4c 8b 04 24 e8 76 ff ff ff <84> c0
74 20 48 8b 91 20 15 00 00 8b 89 1c 15 00 00 48 8b 02 48 83
RSP: 0018:ffffc9000112fd08 EFLAGS: 00000293
RAX: 0000000000000000 RBX: 0000000000000059 RCX: ffff888012bb5580
RDX: 0000000000000000 RSI: ffff888012bb5580 RDI: 0000000000000002
RBP: ffff8880125b8151 R08: ffffffff81c7243d R09: 0000000000000000
R10: 0000000000000007 R11: ffffed10024b7000 R12: ffff8880125b80f8
R13: 0000000000000001 R14: ffffea0000496e00 R15: ffffea0000496e00
FS: 00007f5f361678c0(0000) GS:ffff888135c00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5f3364d000 CR3: 00000000233d6000 CR4: 0000000000350ee0
Call Trace:
PageSlab include/linux/page-flags.h:345 [inline]
check_heap_object mm/usercopy.c:238 [inline]
__check_object_size mm/usercopy.c:286 [inline]
__check_object_size+0x26d/0x450 mm/usercopy.c:256
check_object_size include/linux/thread_info.h:185 [inline]
check_copy_size include/linux/thread_info.h:218 [inline]
copy_to_user include/linux/uaccess.h:199 [inline]
devkmsg_read+0x530/0x750 kernel/printk/printk.c:761
vfs_read+0x1b5/0x600 fs/read_write.c:483
ksys_read+0x12d/0x250 fs/read_write.c:623
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f5f356f7210
Code: 73 01 c3 48 8b 0d 98 7d 20 00 f7 d8 64 89 01 48 83 c8 ff c3 66
0f 1f 44 00 00 83 3d b9 c1 20 00 00 75 10 b8 00 00 00 00 0f 05 <48> 3d
01 f0 ff ff 73 31 c3 48 83 ec 08 e8 4e fc ff ff 48 89 04 24
RSP: 002b:00007ffc1620fa58 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 00007ffc162124d0 RCX: 00007f5f356f7210
RDX: 0000000000002000 RSI: 00007ffc162102d0 RDI: 0000000000000009
RBP: 0000000000000000 R08: 0000000000000008 R09: 00007ffc162e60f0
R10: 0000000000012664 R11: 0000000000000246 R12: 00007ffc162102d0
R13: 00007ffc16212428 R14: 0000555f702f1958 R15: 0005cb9b366b0203
NMI backtrace for cpu 2 skipped: idling at native_safe_halt
arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 2 skipped: idling at arch_safe_halt
arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 2 skipped: idling at default_idle+0xb/0x10
arch/x86/kernel/process.c:716
NMI backtrace for cpu 0 skipped: idling at native_safe_halt
arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 0 skipped: idling at arch_safe_halt
arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 0 skipped: idling at default_idle+0xb/0x10
arch/x86/kernel/process.c:716
----------------
Code disassembly (best guess):
0: 00 c3 add %al,%bl
2: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
9: 00 00 00 00
d: 0f 1f 00 nopl (%rax)
10: 65 48 8b 0c 25 40 f0 mov %gs:0x1f040,%rcx
17: 01 00
19: bf 02 00 00 00 mov $0x2,%edi
1e: 48 89 ce mov %rcx,%rsi
21: 4c 8b 04 24 mov (%rsp),%r8
25: e8 76 ff ff ff callq 0xffffffa0
* 2a: 84 c0 test %al,%al <-- trapping instruction
2c: 74 20 je 0x4e
2e: 48 8b 91 20 15 00 00 mov 0x1520(%rcx),%rdx
35: 8b 89 1c 15 00 00 mov 0x151c(%rcx),%ecx
3b: 48 8b 02 mov (%rdx),%rax
3e: 48 rex.W
3f: 83 .byte 0x83
^ permalink raw reply [flat|nested] 8+ messages in threadend of thread, other threads:[~2022-08-11 6:53 UTC | newest] Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2018-07-10 10:30 INFO: task hung in iterate_supers syzbot 2018-07-10 10:34 ` Tetsuo Handa 2018-07-11 10:19 ` Tetsuo Handa 2018-07-13 10:09 ` [PATCH] fs: Add to super_blocks list after SB_BORN is set Tetsuo Handa 2018-07-13 12:00 ` Al Viro 2022-08-11 6:01 ` INFO: task hung in iterate_supers Tetsuo Handa 2022-08-11 6:53 ` Dominique Martinet 2021-09-13 2:33 Hao Sun
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).