INFO: task hung in binder_deferred_func
22 views
Skip to first unread message
syzbot
May 22, 2019, 1:24:07 PM5/22/19
to syzkaller-a...@googlegroups.com
Hello,
syzbot found the following crash on:
HEAD commit: df08e347 Merge 4.9.178 into android-4.9
git tree: android-4.9
console output: https://syzkaller.appspot.com/x/log.txt?x=153a88a2a00000
kernel config: https://syzkaller.appspot.com/x/.config?x=6c7d2d319368ebd4
dashboard link: https://syzkaller.appspot.com/bug?extid=88a5a2b6c238e22f7b74
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1124fb9ca00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=152bae54a00000
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+88a5a2...@syzkaller.appspotmail.com
binder: 29731:29731 ioctl 4018620d 200000c0 returned -16
binder: BINDER_SET_CONTEXT_MGR already set
binder: 29732:29732 ioctl 4018620d 200000c0 returned -16
binder: BINDER_SET_CONTEXT_MGR already set
binder: 29735:29735 ioctl 4018620d 200000c0 returned -16
INFO: task kworker/0:1:23 blocked for more than 140 seconds.
Not tainted 4.9.178+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:1 D26328 23 2 0x80000000
Workqueue: events binder_deferred_func
0000000000000087 ffff8801da73af80 0000000000000000 ffff8801db621000
ffff8801da6817c0 ffff8801db621018 ffff8801d9c3fa08 ffffffff82808fee
ffff8801da73b830 1ffff1003b387f2a 0000000000000046 ffff8801db6218f0
Call Trace:
[<00000000c5e88402>] schedule+0x92/0x1c0 kernel/sched/core.c:3546
[<00000000406d30b2>] schedule_preempt_disabled+0x13/0x20
kernel/sched/core.c:3579
[<0000000007dc7600>] __mutex_lock_common kernel/locking/mutex.c:582
[inline]
[<0000000007dc7600>] mutex_lock_nested+0x38d/0x920
kernel/locking/mutex.c:621
[<00000000dd02992f>] binder_deferred_release drivers/android/binder.c:5361
[inline]
[<00000000dd02992f>] binder_deferred_func+0x3a1/0xde0
drivers/android/binder.c:5469
[<000000007aa541f5>] process_one_work+0x88b/0x1600 kernel/workqueue.c:2114
[<00000000c49fd61e>] worker_thread+0x5df/0x11d0 kernel/workqueue.c:2251
[<00000000f90e0bb6>] kthread+0x278/0x310 kernel/kthread.c:211
[<00000000ad6b4e8c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:375
Showing all locks held in the system:
3 locks held by kworker/0:1/23:
#0: ("events"){.+.+.+}, at: [<000000002a5add28>]
process_one_work+0x790/0x1600 kernel/workqueue.c:2107
#1: (binder_deferred_work){+.+...}, at: [<000000002074fc00>]
process_one_work+0x7ce/0x1600 kernel/workqueue.c:2111
#2: (&binder_device->context.context_mgr_node_lock){+.+.+.}, at:
[<00000000dd02992f>] binder_deferred_release drivers/android/binder.c:5361
[inline]
#2: (&binder_device->context.context_mgr_node_lock){+.+.+.}, at:
[<00000000dd02992f>] binder_deferred_func+0x3a1/0xde0
drivers/android/binder.c:5469
2 locks held by khungtaskd/24:
#0: (rcu_read_lock){......}, at: [<000000002631a828>]
check_hung_uninterruptible_tasks kernel/hung_task.c:169 [inline]
#0: (rcu_read_lock){......}, at: [<000000002631a828>]
watchdog+0x14b/0xaf0 kernel/hung_task.c:263
#1: (tasklist_lock){.+.+..}, at: [<00000000c37b8025>]
debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4336
1 lock held by rsyslogd/1911:
#0: (&f->f_pos_lock){+.+.+.}, at: [<00000000b09f0aad>]
__fdget_pos+0xa8/0xd0 fs/file.c:782
2 locks held by getty/2038:
#0: (&tty->ldisc_sem){++++++}, at: [<000000003216906c>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+...}, at: [<000000000a2eba59>]
n_tty_read+0x1fe/0x1820 drivers/tty/n_tty.c:2156
1 lock held by init/15758:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15759:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15760:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15761:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15762:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15763:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
=============================================
NMI backtrace for cpu 1
CPU: 1 PID: 24 Comm: khungtaskd Not tainted 4.9.178+ #2
ffff8801d98d7cc8 ffffffff81b57351 0000000000000001 0000000000000000
0000000000000001 ffffffff81099901 dffffc0000000000 ffff8801d98d7d00
ffffffff81b625ec 0000000000000001 0000000000000000 0000000000000001
Call Trace:
[<00000000e1d29fd1>] __dump_stack lib/dump_stack.c:15 [inline]
[<00000000e1d29fd1>] dump_stack+0xc1/0x120 lib/dump_stack.c:51
[<000000007ce1f75f>] nmi_cpu_backtrace.cold+0x47/0x87
lib/nmi_backtrace.c:99
[<000000006dddd131>] nmi_trigger_cpumask_backtrace+0x124/0x155
lib/nmi_backtrace.c:60
[<00000000c49f9c21>] arch_trigger_cpumask_backtrace+0x14/0x20
arch/x86/kernel/apic/hw_nmi.c:37
[<00000000cd4f82ef>] trigger_all_cpu_backtrace include/linux/nmi.h:58
[inline]
[<00000000cd4f82ef>] check_hung_task kernel/hung_task.c:126 [inline]
[<00000000cd4f82ef>] check_hung_uninterruptible_tasks
kernel/hung_task.c:183 [inline]
[<00000000cd4f82ef>] watchdog+0x670/0xaf0 kernel/hung_task.c:263
[<00000000f90e0bb6>] kthread+0x278/0x310 kernel/kthread.c:211
[<00000000ad6b4e8c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:375
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 29733 Comm: syz-executor865 Not tainted 4.9.178+ #2
task: 000000001506dd5a task.stack: 000000008dc24371
RIP: 0010:[<ffffffff81bb3665>] c [<000000004044d024>]
_parse_integer+0x75/0x1a0 lib/kstrtox.c:70
RSP: 0018:ffff8800b483f9b8 EFLAGS: 00000293
RAX: ffff8800b4fac740 RBX: 0000000000000001 RCX: 0000000000000001
RDX: 0000000000000000 RSI: ffffffff81bb3658 RDI: ffff8800b483fc30
RBP: ffff8800b483f9f0 R08: 1ffff10016907f86 R09: ffffed0016907f87
R10: ffffed0016907f86 R11: ffff8800b483fc33 R12: ffff8800b483fc30
R13: 000000000000000a R14: 0000000000000000 R15: 0000000000000000
FS: 0000000001a54880(0000) GS:ffff8801db600000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000004a6136 CR3: 00000000b5339000 CR4: 00000000001606b0
Stack:
ffff8800b483fa40 c 0000000a16907f3f c ffff8800b483fc30 c 1ffff10016907f40 c
ffff8800b483fc30 c ffff8800b483fae0 c dffffc0000000000 c ffff8800b483faa8 c
ffffffff81bb382a c 0000000041b58ab3 c ffffffff82e596d0 c ffffffff81bb3790 c
Call Trace:
[<00000000c81495d9>] _kstrtoull+0x9a/0x1e0 lib/kstrtox.c:88
[<000000005a8e5905>] kstrtoull lib/kstrtox.c:122 [inline]
[<000000005a8e5905>] kstrtoll+0xda/0x1f0 lib/kstrtox.c:155
[<0000000019a65645>] kstrtoint+0x7f/0x110 lib/kstrtox.c:250
[<000000003c7954d5>] oom_score_adj_write+0x140/0x1b0 fs/proc/base.c:1238
[<00000000621ceb86>] __vfs_write+0x116/0x560 fs/read_write.c:509
[<00000000e48fa021>] vfs_write+0x185/0x520 fs/read_write.c:559
[<00000000653dbf5b>] SYSC_write fs/read_write.c:606 [inline]
[<00000000653dbf5b>] SyS_write+0xdc/0x1c0 fs/read_write.c:598
[<00000000ca436915>] do_syscall_64+0x1ad/0x5c0 arch/x86/entry/common.c:288
[<00000000b7cf46ce>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
Code: c1c c24 c45 c31 cff c45 c31 cf6 c84 cdb c75 c7c ce9 cb3
c00 c00 c00 ce8 c50 cd2 c76 cff c83 ceb c30 ce8 c48 cd2 c76
cff c44 c8b c6d cd4 c44 c39 ceb c0f c83 c99 c00 c00 c00
c<e8> c36 cd2 c76 cff c48 cb8 c00 c00 c00 c00 c00 c00 c00
cf0 c49 c85 cc6 c0f c85 cb7 c
binder: BINDER_SET_CONTEXT_MGR already set
binder: 29733:29733 ioctl 4018620d 200000c0 returned -16
---
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 syzk...@googlegroups.com.
syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches
syzbot found the following crash on:
HEAD commit: df08e347 Merge 4.9.178 into android-4.9
git tree: android-4.9
console output: https://syzkaller.appspot.com/x/log.txt?x=153a88a2a00000
kernel config: https://syzkaller.appspot.com/x/.config?x=6c7d2d319368ebd4
dashboard link: https://syzkaller.appspot.com/bug?extid=88a5a2b6c238e22f7b74
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1124fb9ca00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=152bae54a00000
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+88a5a2...@syzkaller.appspotmail.com
binder: 29731:29731 ioctl 4018620d 200000c0 returned -16
binder: BINDER_SET_CONTEXT_MGR already set
binder: 29732:29732 ioctl 4018620d 200000c0 returned -16
binder: BINDER_SET_CONTEXT_MGR already set
binder: 29735:29735 ioctl 4018620d 200000c0 returned -16
INFO: task kworker/0:1:23 blocked for more than 140 seconds.
Not tainted 4.9.178+ #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:1 D26328 23 2 0x80000000
Workqueue: events binder_deferred_func
0000000000000087 ffff8801da73af80 0000000000000000 ffff8801db621000
ffff8801da6817c0 ffff8801db621018 ffff8801d9c3fa08 ffffffff82808fee
ffff8801da73b830 1ffff1003b387f2a 0000000000000046 ffff8801db6218f0
Call Trace:
[<00000000c5e88402>] schedule+0x92/0x1c0 kernel/sched/core.c:3546
[<00000000406d30b2>] schedule_preempt_disabled+0x13/0x20
kernel/sched/core.c:3579
[<0000000007dc7600>] __mutex_lock_common kernel/locking/mutex.c:582
[inline]
[<0000000007dc7600>] mutex_lock_nested+0x38d/0x920
kernel/locking/mutex.c:621
[<00000000dd02992f>] binder_deferred_release drivers/android/binder.c:5361
[inline]
[<00000000dd02992f>] binder_deferred_func+0x3a1/0xde0
drivers/android/binder.c:5469
[<000000007aa541f5>] process_one_work+0x88b/0x1600 kernel/workqueue.c:2114
[<00000000c49fd61e>] worker_thread+0x5df/0x11d0 kernel/workqueue.c:2251
[<00000000f90e0bb6>] kthread+0x278/0x310 kernel/kthread.c:211
[<00000000ad6b4e8c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:375
Showing all locks held in the system:
3 locks held by kworker/0:1/23:
#0: ("events"){.+.+.+}, at: [<000000002a5add28>]
process_one_work+0x790/0x1600 kernel/workqueue.c:2107
#1: (binder_deferred_work){+.+...}, at: [<000000002074fc00>]
process_one_work+0x7ce/0x1600 kernel/workqueue.c:2111
#2: (&binder_device->context.context_mgr_node_lock){+.+.+.}, at:
[<00000000dd02992f>] binder_deferred_release drivers/android/binder.c:5361
[inline]
#2: (&binder_device->context.context_mgr_node_lock){+.+.+.}, at:
[<00000000dd02992f>] binder_deferred_func+0x3a1/0xde0
drivers/android/binder.c:5469
2 locks held by khungtaskd/24:
#0: (rcu_read_lock){......}, at: [<000000002631a828>]
check_hung_uninterruptible_tasks kernel/hung_task.c:169 [inline]
#0: (rcu_read_lock){......}, at: [<000000002631a828>]
watchdog+0x14b/0xaf0 kernel/hung_task.c:263
#1: (tasklist_lock){.+.+..}, at: [<00000000c37b8025>]
debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4336
1 lock held by rsyslogd/1911:
#0: (&f->f_pos_lock){+.+.+.}, at: [<00000000b09f0aad>]
__fdget_pos+0xa8/0xd0 fs/file.c:782
2 locks held by getty/2038:
#0: (&tty->ldisc_sem){++++++}, at: [<000000003216906c>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+...}, at: [<000000000a2eba59>]
n_tty_read+0x1fe/0x1820 drivers/tty/n_tty.c:2156
1 lock held by init/15758:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15759:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15760:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15761:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15762:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
1 lock held by init/15763:
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open_by_driver
drivers/tty/tty_io.c:2062 [inline]
#0: (tty_mutex){+.+.+.}, at: [<00000000df522fa1>] tty_open+0x3f9/0xe10
drivers/tty/tty_io.c:2140
=============================================
NMI backtrace for cpu 1
CPU: 1 PID: 24 Comm: khungtaskd Not tainted 4.9.178+ #2
ffff8801d98d7cc8 ffffffff81b57351 0000000000000001 0000000000000000
0000000000000001 ffffffff81099901 dffffc0000000000 ffff8801d98d7d00
ffffffff81b625ec 0000000000000001 0000000000000000 0000000000000001
Call Trace:
[<00000000e1d29fd1>] __dump_stack lib/dump_stack.c:15 [inline]
[<00000000e1d29fd1>] dump_stack+0xc1/0x120 lib/dump_stack.c:51
[<000000007ce1f75f>] nmi_cpu_backtrace.cold+0x47/0x87
lib/nmi_backtrace.c:99
[<000000006dddd131>] nmi_trigger_cpumask_backtrace+0x124/0x155
lib/nmi_backtrace.c:60
[<00000000c49f9c21>] arch_trigger_cpumask_backtrace+0x14/0x20
arch/x86/kernel/apic/hw_nmi.c:37
[<00000000cd4f82ef>] trigger_all_cpu_backtrace include/linux/nmi.h:58
[inline]
[<00000000cd4f82ef>] check_hung_task kernel/hung_task.c:126 [inline]
[<00000000cd4f82ef>] check_hung_uninterruptible_tasks
kernel/hung_task.c:183 [inline]
[<00000000cd4f82ef>] watchdog+0x670/0xaf0 kernel/hung_task.c:263
[<00000000f90e0bb6>] kthread+0x278/0x310 kernel/kthread.c:211
[<00000000ad6b4e8c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:375
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 29733 Comm: syz-executor865 Not tainted 4.9.178+ #2
task: 000000001506dd5a task.stack: 000000008dc24371
RIP: 0010:[<ffffffff81bb3665>] c [<000000004044d024>]
_parse_integer+0x75/0x1a0 lib/kstrtox.c:70
RSP: 0018:ffff8800b483f9b8 EFLAGS: 00000293
RAX: ffff8800b4fac740 RBX: 0000000000000001 RCX: 0000000000000001
RDX: 0000000000000000 RSI: ffffffff81bb3658 RDI: ffff8800b483fc30
RBP: ffff8800b483f9f0 R08: 1ffff10016907f86 R09: ffffed0016907f87
R10: ffffed0016907f86 R11: ffff8800b483fc33 R12: ffff8800b483fc30
R13: 000000000000000a R14: 0000000000000000 R15: 0000000000000000
FS: 0000000001a54880(0000) GS:ffff8801db600000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000004a6136 CR3: 00000000b5339000 CR4: 00000000001606b0
Stack:
ffff8800b483fa40 c 0000000a16907f3f c ffff8800b483fc30 c 1ffff10016907f40 c
ffff8800b483fc30 c ffff8800b483fae0 c dffffc0000000000 c ffff8800b483faa8 c
ffffffff81bb382a c 0000000041b58ab3 c ffffffff82e596d0 c ffffffff81bb3790 c
Call Trace:
[<00000000c81495d9>] _kstrtoull+0x9a/0x1e0 lib/kstrtox.c:88
[<000000005a8e5905>] kstrtoull lib/kstrtox.c:122 [inline]
[<000000005a8e5905>] kstrtoll+0xda/0x1f0 lib/kstrtox.c:155
[<0000000019a65645>] kstrtoint+0x7f/0x110 lib/kstrtox.c:250
[<000000003c7954d5>] oom_score_adj_write+0x140/0x1b0 fs/proc/base.c:1238
[<00000000621ceb86>] __vfs_write+0x116/0x560 fs/read_write.c:509
[<00000000e48fa021>] vfs_write+0x185/0x520 fs/read_write.c:559
[<00000000653dbf5b>] SYSC_write fs/read_write.c:606 [inline]
[<00000000653dbf5b>] SyS_write+0xdc/0x1c0 fs/read_write.c:598
[<00000000ca436915>] do_syscall_64+0x1ad/0x5c0 arch/x86/entry/common.c:288
[<00000000b7cf46ce>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
Code: c1c c24 c45 c31 cff c45 c31 cf6 c84 cdb c75 c7c ce9 cb3
c00 c00 c00 ce8 c50 cd2 c76 cff c83 ceb c30 ce8 c48 cd2 c76
cff c44 c8b c6d cd4 c44 c39 ceb c0f c83 c99 c00 c00 c00
c<e8> c36 cd2 c76 cff c48 cb8 c00 c00 c00 c00 c00 c00 c00
cf0 c49 c85 cc6 c0f c85 cb7 c
binder: BINDER_SET_CONTEXT_MGR already set
binder: 29733:29733 ioctl 4018620d 200000c0 returned -16
---
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 syzk...@googlegroups.com.
syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches
Reply all
Reply to author
Forward
0 new messages