* INFO: task hung in iterate_supers
@ 2018-07-10 10:30 syzbot
2018-07-10 10:34 ` Tetsuo Handa
0 siblings, 1 reply; 6+ 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] 6+ 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
0 siblings, 1 reply; 6+ 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] 6+ 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; 6+ 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] 6+ 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; 6+ 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] 6+ 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; 6+ 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] 6+ messages in thread
* INFO: task hung in iterate_supers
@ 2021-09-13 2:33 Hao Sun
0 siblings, 0 replies; 6+ 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] 6+ messages in thread
end of thread, other threads:[~2021-09-13 2:35 UTC | newest]
Thread overview: 6+ 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
2021-09-13 2:33 INFO: task hung in iterate_supers 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).