* 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 ` 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
0 siblings, 0 replies; 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
* [PATCH] fs: Add to super_blocks list after SB_BORN is set.
@ 2018-07-13 10:09 ` Tetsuo Handa
0 siblings, 0 replies; 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 ` Tetsuo Handa
(?)
@ 2018-07-13 12:00 ` Al Viro
-1 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
end 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 10:09 ` 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
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.