INFO: task hung in start_sync_thread

4 views
Skip to first unread message

syzbot

unread,
Dec 5, 2022, 11:08:39 AM12/5/22
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 3f8a27f9e27b Linux 4.19.211
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=156fe397880000
kernel config: https://syzkaller.appspot.com/x/.config?x=9b9277b418617afe
dashboard link: https://syzkaller.appspot.com/bug?extid=85c1190b41d83fd880fd
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

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

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/98c0bdb4abb3/disk-3f8a27f9.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/ea228ff02669/vmlinux-3f8a27f9.xz

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

INFO: task syz-executor.5:11515 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.5 D28248 11515 2725 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1016 [inline]
__mutex_lock+0x5f0/0x1190 kernel/locking/mutex.c:1078
start_sync_thread+0x109/0x24a0 net/netfilter/ipvs/ip_vs_sync.c:1775
do_ip_vs_set_ctl+0x34b/0xec0 net/netfilter/ipvs/ip_vs_ctl.c:2380
nf_sockopt net/netfilter/nf_sockopt.c:106 [inline]
nf_setsockopt+0x6f/0xc0 net/netfilter/nf_sockopt.c:115
ip_setsockopt net/ipv4/ip_sockglue.c:1258 [inline]
ip_setsockopt+0xd8/0xf0 net/ipv4/ip_sockglue.c:1238
raw_setsockopt+0xd8/0x100 net/ipv4/raw.c:861
__sys_setsockopt+0x14d/0x240 net/socket.c:2013
__do_sys_setsockopt net/socket.c:2024 [inline]
__se_sys_setsockopt net/socket.c:2021 [inline]
__x64_sys_setsockopt+0xba/0x150 net/socket.c:2021
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fee2c7880d9
Code: Bad RIP value.
RSP: 002b:00007fee2acfa168 EFLAGS: 00000246 ORIG_RAX: 0000000000000036
RAX: ffffffffffffffda RBX: 00007fee2c8a7f80 RCX: 00007fee2c7880d9
RDX: 000000000000048b RSI: 0000000000000000 RDI: 0000000000000009
RBP: 00007fee2c7e3ae9 R08: 0000000000000018 R09: 0000000000000000
R10: 0000000020000040 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffc6c1a1a1f R14: 00007fee2acfa300 R15: 0000000000022000
INFO: task syz-executor.1:11514 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.1 D28248 11514 2665 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1016 [inline]
__mutex_lock+0x5f0/0x1190 kernel/locking/mutex.c:1078
start_sync_thread+0x109/0x24a0 net/netfilter/ipvs/ip_vs_sync.c:1775
do_ip_vs_set_ctl+0x34b/0xec0 net/netfilter/ipvs/ip_vs_ctl.c:2380
nf_sockopt net/netfilter/nf_sockopt.c:106 [inline]
nf_setsockopt+0x6f/0xc0 net/netfilter/nf_sockopt.c:115
ip_setsockopt net/ipv4/ip_sockglue.c:1258 [inline]
ip_setsockopt+0xd8/0xf0 net/ipv4/ip_sockglue.c:1238
raw_setsockopt+0xd8/0x100 net/ipv4/raw.c:861
__sys_setsockopt+0x14d/0x240 net/socket.c:2013
__do_sys_setsockopt net/socket.c:2024 [inline]
__se_sys_setsockopt net/socket.c:2021 [inline]
__x64_sys_setsockopt+0xba/0x150 net/socket.c:2021
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fcea2fbb0d9
Code: Bad RIP value.
RSP: 002b:00007fcea152d168 EFLAGS: 00000246 ORIG_RAX: 0000000000000036
RAX: ffffffffffffffda RBX: 00007fcea30daf80 RCX: 00007fcea2fbb0d9
RDX: 000000000000048b RSI: 0000000000000000 RDI: 0000000000000009
RBP: 00007fcea3016ae9 R08: 0000000000000018 R09: 0000000000000000
R10: 0000000020000040 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd91cd21ef R14: 00007fcea152d300 R15: 0000000000022000

Showing all locks held in the system:
3 locks held by systemd/1:
3 locks held by kworker/0:0/5:
#0: 00000000dd32f371 ((wq_completion)"events"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2124
#1: 00000000b0a07730 (deferred_process_work){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2128
#2: 0000000060a21350 (rtnl_mutex){+.+.}, at: switchdev_deferred_process_work+0xa/0x20 net/switchdev/switchdev.c:150
3 locks held by kworker/u4:1/23:
1 lock held by khungtaskd/1570:
#0: 000000002115531e (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4441
1 lock held by systemd-journal/4687:
4 locks held by systemd-udevd/4707:
1 lock held by in:imklog/7779:
#0: 000000007d873705 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
4 locks held by syz-fuzzer/8129:
2 locks held by kworker/u4:6/9374:
3 locks held by kworker/u4:8/23663:
3 locks held by kworker/1:1/23821:
3 locks held by kworker/1:5/31434:
#0: 0000000074b7f63b ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2124
#1: 00000000033a93b6 ((addr_chk_work).work){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2128
#2: 0000000060a21350 (rtnl_mutex){+.+.}, at: addrconf_verify_work+0xa/0x20 net/ipv6/addrconf.c:4476
5 locks held by kworker/0:5/31520:
4 locks held by syz-executor.0/2688:
5 locks held by kworker/u4:10/6864:
3 locks held by kworker/u4:11/8254:
3 locks held by kworker/u4:12/9603:
2 locks held by kworker/u4:13/9732:
1 lock held by syz-executor.3/9799:
#0: 0000000060a21350 (rtnl_mutex){+.+.}, at: tun_detach drivers/net/tun.c:759 [inline]
#0: 0000000060a21350 (rtnl_mutex){+.+.}, at: tun_chr_close+0x3a/0x180 drivers/net/tun.c:3323
1 lock held by syz-executor.2/9837:
#0: 0000000060a21350 (rtnl_mutex){+.+.}, at: tun_detach drivers/net/tun.c:759 [inline]
#0: 0000000060a21350 (rtnl_mutex){+.+.}, at: tun_chr_close+0x3a/0x180 drivers/net/tun.c:3323
2 locks held by syz-executor.4/11502:
1 lock held by syz-executor.5/11515:
#0: 0000000060a21350 (rtnl_mutex){+.+.}, at: start_sync_thread+0x109/0x24a0 net/netfilter/ipvs/ip_vs_sync.c:1775
1 lock held by syz-executor.1/11514:
#0: 0000000060a21350 (rtnl_mutex){+.+.}, at: start_sync_thread+0x109/0x24a0 net/netfilter/ipvs/ip_vs_sync.c:1775
1 lock held by kworker/u4:11/11534:
2 locks held by kworker/u4:13/11535:

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

NMI backtrace for cpu 1
CPU: 1 PID: 1570 Comm: khungtaskd Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1a6/0x1f0 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0x991/0xe60 kernel/hung_task.c:287
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 31520 Comm: kworker/0:5 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Workqueue: events_power_efficient fb_flashcursor
RIP: 0010:debug_lockdep_rcu_enabled kernel/rcu/update.c:254 [inline]
RIP: 0010:debug_lockdep_rcu_enabled kernel/rcu/update.c:251 [inline]
RIP: 0010:rcu_read_lock_bh_held+0x9e/0x160 kernel/rcu/update.c:308
Code: 84 9b 00 00 00 65 48 8b 1c 25 c0 df 01 00 48 8d bb 84 08 00 00 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 0f b6 14 02 <48> 89 f8 83 e0 07 83 c0 03 38 d0 7c 08 84 d2 0f 85 8e 00 00 00 8b
RSP: 0018:ffff8880ba007ae0 EFLAGS: 00000a07
RAX: dffffc0000000000 RBX: ffff8880a5848280 RCX: 1ffffffff148be2c
RDX: 0000000000000000 RSI: ffffffff86768946 RDI: ffff8880a5848b04
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000001 R11: 000000005f2d98df R12: ffff8880720d1a80
R13: 0000000000000048 R14: 0000000000000000 R15: ffff888031781640
FS: 0000000000000000(0000) GS:ffff8880ba000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c00d0c3010 CR3: 0000000097a00000 CR4: 00000000003406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 00000000b8fecd19 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
__dev_queue_xmit+0x1f3b/0x2e00 net/core/dev.c:3803
can_send+0x4be/0xa00 net/can/af_can.c:297
bcm_can_tx+0x565/0x800 net/can/bcm.c:300
bcm_tx_timeout_tsklet+0x1f0/0x3a0 net/can/bcm.c:414
tasklet_action_common.constprop.0+0x265/0x360 kernel/softirq.c:522
__do_softirq+0x265/0x980 kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x215/0x260 kernel/softirq.c:412
exiting_irq arch/x86/include/asm/apic.h:536 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1098
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
</IRQ>
RIP: 0010:slow_down_io arch/x86/include/asm/paravirt.h:268 [inline]
RIP: 0010:outb_p arch/x86/include/asm/io.h:333 [inline]
RIP: 0010:vga_io_w include/video/vga.h:209 [inline]
RIP: 0010:vga_io_rgfx include/video/vga.h:388 [inline]
RIP: 0010:setcolor drivers/video/fbdev/vga16fb.c:170 [inline]
RIP: 0010:vga_imageblit_expand drivers/video/fbdev/vga16fb.c:1164 [inline]
RIP: 0010:vga16fb_imageblit+0x93e/0x2260 drivers/video/fbdev/vga16fb.c:1260
Code: fc ff df 48 89 fa 48 c1 ea 03 0f b6 04 02 84 c0 74 09 3c 03 7f 05 e8 51 e6 f9 fd 48 8b 04 24 ba ce 03 00 00 8b 58 10 31 c0 ee <48> c7 c2 10 82 f1 89 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 80
RSP: 0018:ffff88806ebbfa50 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000000 RBX: 0000000000000007 RCX: ffffffff839e79cc
RDX: 00000000000003ce RSI: ffffffff839e79da RDI: ffff88823a551810
RBP: ffff88823a551804 R08: ffff8880b078963f R09: 0000000000000000
R10: 0000000000000005 R11: 0000000000000000 R12: ffff8880b0791b48
R13: ffff8880b0789630 R14: ffff88823a551820 R15: 0000000000000001
soft_cursor+0x514/0xa30 drivers/video/fbdev/core/softcursor.c:74
bit_cursor+0x1126/0x1740 drivers/video/fbdev/core/bitblit.c:377
fb_flashcursor+0x38c/0x430 drivers/video/fbdev/core/fbcon.c:379
process_one_work+0x864/0x1570 kernel/workqueue.c:2153
worker_thread+0x64c/0x1130 kernel/workqueue.c:2296
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415


---
This report 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 issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

syzbot

unread,
Apr 4, 2023, 12:08:41 PM4/4/23
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