INFO: task hung in linkwatch_event

10 views
Skip to first unread message

syzbot

unread,
Jun 18, 2019, 5:12:07 AM6/18/19
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 6500aa43 Linux 4.19.52
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=16e348eaa00000
kernel config: https://syzkaller.appspot.com/x/.config?x=c23804fab7069177
dashboard link: https://syzkaller.appspot.com/bug?extid=a028160ba279156cf97b
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+a02816...@syzkaller.appspotmail.com

INFO: task kworker/1:0:19 blocked for more than 140 seconds.
Not tainted 4.19.52 #24
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
kworker/1:0 D26528 19 2 0x80000000
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
Workqueue: events linkwatch_event
kobject: 'loop4' (00000000668ac452): kobject_uevent_env
Call Trace:
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
kobject: 'loop3' (00000000ba9c5bb5): kobject_uevent_env
kobject: 'loop3' (00000000ba9c5bb5): fill_kobj_path: path
= '/devices/virtual/block/loop3'
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3576
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x726/0x1300 kernel/locking/mutex.c:1072
kobject: 'loop5' (00000000cf7dfd8c): kobject_uevent_env
kobject: 'loop5' (00000000cf7dfd8c): fill_kobj_path: path
= '/devices/virtual/block/loop5'
kobject: 'loop1' (00000000a56435cf): kobject_uevent_env
kobject: 'loop1' (00000000a56435cf): fill_kobj_path: path
= '/devices/virtual/block/loop1'
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
rtnl_lock+0x17/0x20 net/core/rtnetlink.c:77
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
linkwatch_event+0xf/0x70 net/core/link_watch.c:236
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kobject: 'loop3' (00000000ba9c5bb5): kobject_uevent_env
kthread+0x354/0x420 kernel/kthread.c:246
kobject: 'loop3' (00000000ba9c5bb5): fill_kobj_path: path
= '/devices/virtual/block/loop3'
kobject: 'loop5' (00000000cf7dfd8c): kobject_uevent_env
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
kobject: 'loop5' (00000000cf7dfd8c): fill_kobj_path: path
= '/devices/virtual/block/loop5'
INFO: task kworker/1:1:23468 blocked for more than 140 seconds.
Not tainted 4.19.52 #24
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kobject: 'loop1' (00000000a56435cf): kobject_uevent_env
kobject: 'loop1' (00000000a56435cf): fill_kobj_path: path
= '/devices/virtual/block/loop1'
kworker/1:1 D29976 23468 2 0x80000000
Workqueue: events switchdev_deferred_process_work
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3576
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x726/0x1300 kernel/locking/mutex.c:1072
kobject: 'loop4' (00000000668ac452): kobject_uevent_env
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'
kobject: 'loop5' (00000000cf7dfd8c): kobject_uevent_env
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
kobject: 'loop5' (00000000cf7dfd8c): fill_kobj_path: path
= '/devices/virtual/block/loop5'
rtnl_lock+0x17/0x20 net/core/rtnetlink.c:77
switchdev_deferred_process_work+0xe/0x20 net/switchdev/switchdev.c:150
kobject: 'loop1' (00000000a56435cf): kobject_uevent_env
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
kobject: 'loop1' (00000000a56435cf): fill_kobj_path: path
= '/devices/virtual/block/loop1'
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
kobject: 'loop4' (00000000668ac452): kobject_uevent_env

Showing all locks held in the system:
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'
3 locks held by kworker/1:0/19:
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
#1: 000000003869cd29 ((linkwatch_work).work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
#2: 00000000b749dd4f (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:77
kobject: 'loop5' (00000000cf7dfd8c): kobject_uevent_env
4 locks held by kworker/u4:1/23:
kobject: 'loop5' (00000000cf7dfd8c): fill_kobj_path: path
= '/devices/virtual/block/loop5'
3 locks held by kworker/u4:2/46:
1 lock held by khungtaskd/1033:
kobject: 'loop1' (00000000a56435cf): kobject_uevent_env
#0:
kobject: 'loop1' (00000000a56435cf): fill_kobj_path: path
= '/devices/virtual/block/loop1'
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
00000000332ba042 (rcu_read_lock){....}, at: debug_show_all_locks+0x5f/0x27e
kernel/locking/lockdep.c:4435
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
3 locks held by udevd/3594:
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
1 lock held by rsyslogd/7340:
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
#0: 00000000b44b3381 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110
fs/file.c:767
kobject: 'loop4' (00000000668ac452): kobject_uevent_env
2 locks held by getty/7463:
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'
#0: 000000008ab366bb (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
kobject: 'loop3' (00000000ba9c5bb5): kobject_uevent_env
#1: 00000000c0125a14 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop3' (00000000ba9c5bb5): fill_kobj_path: path
= '/devices/virtual/block/loop3'
2 locks held by getty/7464:
kobject: 'loop1' (00000000a56435cf): kobject_uevent_env
#0: 00000000a4cd1565 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
kobject: 'loop1' (00000000a56435cf): fill_kobj_path: path
= '/devices/virtual/block/loop1'
#1: 0000000004c1a898 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
2 locks held by getty/7465:
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
#0: 000000004db5b41f (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000bc9cf513 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
2 locks held by getty/7466:
kobject: 'loop3' (00000000ba9c5bb5): kobject_uevent_env
#0: 0000000029a7ac5a (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
kobject: 'loop3' (00000000ba9c5bb5): fill_kobj_path: path
= '/devices/virtual/block/loop3'
#1: 0000000073da6ccf (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop4' (00000000668ac452): kobject_uevent_env
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'
2 locks held by getty/7467:
#0: 000000009da03067 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
kobject: 'loop1' (00000000a56435cf): kobject_uevent_env
#1: 000000003fc9cb78 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop1' (00000000a56435cf): fill_kobj_path: path
= '/devices/virtual/block/loop1'
2 locks held by getty/7468:
#0: 000000006c1461a8 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
#1: 00000000316db8d5 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
2 locks held by getty/7469:
#0: 000000002f145f7f (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
#1: 0000000025a56847 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
kobject: 'loop3' (00000000ba9c5bb5): kobject_uevent_env
kobject: 'loop3' (00000000ba9c5bb5): fill_kobj_path: path
= '/devices/virtual/block/loop3'
3 locks held by kworker/1:1/23468:
kobject: 'loop4' (00000000668ac452): kobject_uevent_env
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000055a60d8 ((wq_completion)"events"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'
#1: 00000000f8cb0d24 (deferred_process_work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
#2: 00000000b749dd4f (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:77
3 locks held by kworker/0:1/32511:
kobject: 'loop0' (000000000450bf04): kobject_uevent_env
kobject: 'loop0' (000000000450bf04): fill_kobj_path: path
= '/devices/virtual/block/loop0'
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
set_work_data kernel/workqueue.c:617 [inline]
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 000000000946f631 ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
kobject: 'loop2' (00000000e61ebf28): kobject_uevent_env
#1: 00000000d03ea1d3 ((addr_chk_work).work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
kobject: 'loop2' (00000000e61ebf28): fill_kobj_path: path
= '/devices/virtual/block/loop2'
#2: 00000000b749dd4f (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:77
kobject: 'loop3' (00000000ba9c5bb5): kobject_uevent_env
2 locks held by kworker/1:2/10246:
kobject: 'loop3' (00000000ba9c5bb5): fill_kobj_path: path
= '/devices/virtual/block/loop3'
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:59 [inline]
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 000000004b71caff ((wq_completion)"rcu_gp"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
kobject: 'loop5' (00000000cf7dfd8c): kobject_uevent_env
#1: 0000000079c78c0b ((work_completion)(&rew.rew_work)){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
kobject: 'loop5' (00000000cf7dfd8c): fill_kobj_path: path
= '/devices/virtual/block/loop5'

=============================================

kobject: 'loop4' (00000000668ac452): kobject_uevent_env
NMI backtrace for cpu 0
CPU: 0 PID: 1033 Comm: khungtaskd Not tainted 4.19.52 #24
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+0x172/0x1f0 lib/dump_stack.c:113
nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1f8 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:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0x9df/0xee0 kernel/hung_task.c:287
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 10246 Comm: kworker/1:2 Not tainted 4.19.52 #24
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events free_obj_work
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:788
[inline]
RIP: 0010:debug_check_no_locks_freed+0x164/0x290
kernel/locking/lockdep.c:4399
Code: 8d 34 34 4c 39 f2 73 4c e8 c9 f8 ce 01 85 c0 75 4e 48 c7 c0 48 36 72
88 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 <0f> 85 c8 00 00
00 48 83 3d 96 62 20 07 00 74 6a 48 8b 7d d0 57 9d
RSP: 0018:ffff888068c67bf8 EFLAGS: 00000046
RAX: 1ffffffff10e46c9 RBX: ffff88807d78cca0 RCX: dffffc0000000000
RDX: dffffc0000000000 RSI: 0000000000000028 RDI: ffff88807d78cc38
RBP: ffff888068c67c38 R08: ffff88807d78cca0 R09: ffff88812c3e8dc0
R10: ffffed1015d24732 R11: ffff8880ae923993 R12: ffff8880648c58c0
R13: ffff88807d78c3c0 R14: ffff8880648c58e8 R15: ffff88807d78cc68
FS: 0000000000000000(0000) GS:ffff8880ae900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fd25f23cdb8 CR3: 00000000956ff000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
kmem_cache_free+0x68/0x260 mm/slab.c:3762
free_obj_work+0x2ef/0x900 lib/debugobjects.c:242
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
kobject: 'loop4' (00000000668ac452): fill_kobj_path: path
= '/devices/virtual/block/loop4'


---
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

unread,
Feb 6, 2020, 8:11:08 PM2/6/20
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages