syzbot


INFO: task hung in SyS_acct

Status: auto-closed as invalid on 2019/10/25 08:44
Reported-by: syzbot+7ac468385f5320de0713@syzkaller.appspotmail.com
First crash: 1138d, last: 1134d

Sample crash report:
INFO: task syz-executor.3:12899 blocked for more than 140 seconds.
      Not tainted 4.14.121 #15
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3  D30000 12899   6833 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3485
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 SYSC_acct kernel/acct.c:285 [inline]
 SyS_acct+0x68/0x870 kernel/acct.c:273
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x459279
RSP: 002b:00007fc95cbc8c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3
RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 0000000000459279
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000040
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fc95cbc96d4
R13: 00000000004bf21b R14: 00000000004d0390 R15: 00000000ffffffff
INFO: task syz-executor.3:12906 blocked for more than 140 seconds.
      Not tainted 4.14.121 #15
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3  D29184 12906   6833 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3485
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 SYSC_acct kernel/acct.c:285 [inline]
 SyS_acct+0x68/0x870 kernel/acct.c:273
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x459279
RSP: 002b:00007fc95cbc8c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3
RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 0000000000459279
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000000
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fc95cbc96d4
R13: 00000000004bf21b R14: 00000000004d0390 R15: 00000000ffffffff
INFO: task syz-executor.3:12908 blocked for more than 140 seconds.
      Not tainted 4.14.121 #15
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3  D29920 12908  12906 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3485
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 SYSC_acct kernel/acct.c:285 [inline]
 SyS_acct+0x68/0x870 kernel/acct.c:273
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x459279
RSP: 002b:00007fc95cbc8c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3
RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 0000000000459279
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000040
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fc95cbc96d4
R13: 00000000004bf21b R14: 00000000004d0390 R15: 00000000ffffffff

Showing all locks held in the system:
1 lock held by khungtaskd/1008:
 #0:  (tasklist_lock){.+.+}, at: [<ffffffff814830d8>] debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4541
2 locks held by getty/6782:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/6783:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/6784:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/6785:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/6786:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/6787:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/6788:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff861a2083>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83104596>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
1 lock held by syz-executor.4/12898:
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SYSC_acct kernel/acct.c:285 [inline]
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SyS_acct+0x68/0x870 kernel/acct.c:273
1 lock held by syz-executor.3/12899:
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SYSC_acct kernel/acct.c:285 [inline]
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SyS_acct+0x68/0x870 kernel/acct.c:273
1 lock held by syz-executor.3/12906:
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SYSC_acct kernel/acct.c:285 [inline]
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SyS_acct+0x68/0x870 kernel/acct.c:273
1 lock held by syz-executor.3/12908:
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SYSC_acct kernel/acct.c:285 [inline]
 #0:  (acct_on_mutex){+.+.}, at: [<ffffffff81554688>] SyS_acct+0x68/0x870 kernel/acct.c:273

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

NMI backtrace for cpu 1
CPU: 1 PID: 1008 Comm: khungtaskd Not tainted 4.14.121 #15
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x138/0x19c lib/dump_stack.c:53
 nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x141/0x189 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:140 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
 watchdog+0x5e7/0xb90 kernel/hung_task.c:274
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.14.121 #15
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffffffff87676240 task.stack: ffffffff87600000
RIP: 0010:ktime_get_with_offset+0x176/0x320 kernel/time/timekeeping.c:804
RSP: 0018:ffff8880aee06d28 EFLAGS: 00000206
RAX: 00000063abd6aaff RBX: 1ffffffff0ee29f0 RCX: 1ffffffff0eced7f
RDX: 0000000000000100 RSI: ffffffff87676c00 RDI: 0000000000000206
RBP: ffff8880aee06d80 R08: ffffffff87676240 R09: ffffffff87676bf8
R10: 0000000000000000 R11: 0000000000000000 R12: dffffc0000000000
R13: 1ffffffff0ee29f2 R14: ffffffff8779dda8 R15: 00000000000134ea
FS:  0000000000000000(0000) GS:ffff8880aee00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c4271a3000 CR3: 0000000096633000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 ktime_get_real include/linux/timekeeping.h:185 [inline]
 __net_timestamp include/linux/skbuff.h:3450 [inline]
 net_timestamp_set net/core/dev.c:1807 [inline]
 dev_queue_xmit_nit+0x4e7/0x8c0 net/core/dev.c:1947
 xmit_one net/core/dev.c:3005 [inline]
 dev_hard_start_xmit+0xa7/0x8b0 net/core/dev.c:3025
 sch_direct_xmit+0x27a/0x550 net/sched/sch_generic.c:186
 __dev_xmit_skb net/core/dev.c:3218 [inline]
 __dev_queue_xmit+0x1b6e/0x25e0 net/core/dev.c:3493
 dev_queue_xmit+0x18/0x20 net/core/dev.c:3558
 neigh_hh_output include/net/neighbour.h:490 [inline]
 neigh_output include/net/neighbour.h:498 [inline]
 ip_finish_output2+0xddc/0x14a0 net/ipv4/ip_output.c:229
 ip_finish_output+0x56d/0xc60 net/ipv4/ip_output.c:317
 NF_HOOK_COND include/linux/netfilter.h:239 [inline]
 ip_output+0x1e6/0x590 net/ipv4/ip_output.c:405
 dst_output include/net/dst.h:459 [inline]
 ip_local_out+0x97/0x170 net/ipv4/ip_output.c:124
 ip_queue_xmit+0x7d7/0x1b10 net/ipv4/ip_output.c:504
 __tcp_transmit_skb+0x172c/0x2fe0 net/ipv4/tcp_output.c:1130
 __tcp_send_ack.part.0+0x3c8/0x5b0 net/ipv4/tcp_output.c:3617
 __tcp_send_ack net/ipv4/tcp_output.c:3623 [inline]
 tcp_send_ack+0x7a/0xa0 net/ipv4/tcp_output.c:3623
 __tcp_ack_snd_check+0x107/0x3a0 net/ipv4/tcp_input.c:5125
 tcp_rcv_established+0x1179/0x1650 net/ipv4/tcp_input.c:5515
 tcp_v4_do_rcv+0x563/0x7e0 net/ipv4/tcp_ipv4.c:1467
 tcp_v4_rcv+0x241e/0x3170 net/ipv4/tcp_ipv4.c:1741
 ip_local_deliver_finish+0x25e/0xad0 net/ipv4/ip_input.c:216
 NF_HOOK include/linux/netfilter.h:250 [inline]
 NF_HOOK include/linux/netfilter.h:244 [inline]
 ip_local_deliver+0x1c3/0x4a0 net/ipv4/ip_input.c:257
 dst_input include/net/dst.h:465 [inline]
 ip_rcv_finish+0x7be/0x1a50 net/ipv4/ip_input.c:396
 NF_HOOK include/linux/netfilter.h:250 [inline]
 NF_HOOK include/linux/netfilter.h:244 [inline]
 ip_rcv+0xaa5/0x112b net/ipv4/ip_input.c:493
 __netif_receive_skb_core+0x1d58/0x2aa0 net/core/dev.c:4477
 __netif_receive_skb+0x2c/0x1b0 net/core/dev.c:4515
 netif_receive_skb_internal+0xe4/0x5a0 net/core/dev.c:4588
 napi_skb_finish net/core/dev.c:4949 [inline]
 napi_gro_receive+0x2f8/0x410 net/core/dev.c:4980
 receive_buf+0x532/0x3fc0 drivers/net/virtio_net.c:852
 virtnet_receive drivers/net/virtio_net.c:1098 [inline]
 virtnet_poll+0x515/0xa6e drivers/net/virtio_net.c:1189
 napi_poll net/core/dev.c:5598 [inline]
 net_rx_action+0x490/0xf80 net/core/dev.c:5664
 __do_softirq+0x244/0x9a0 kernel/softirq.c:288
 invoke_softirq kernel/softirq.c:368 [inline]
 irq_exit+0x160/0x1b0 kernel/softirq.c:409
 exiting_irq arch/x86/include/asm/apic.h:648 [inline]
 do_IRQ+0x11b/0x1d0 arch/x86/kernel/irq.c:242
 common_interrupt+0x8e/0x8e arch/x86/entry/entry_64.S:573
 </IRQ>
RIP: 0010:native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:61
RSP: 0018:ffffffff87607de8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff6e
RAX: 1ffffffff0ee29f4 RBX: ffffffff87676240 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffffffff87676abc
RBP: ffffffff87607e10 R08: 1ffffffff1049d01 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff87714f90
R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff87676240
 arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:557
 default_idle_call+0x36/0x90 kernel/sched/idle.c:98
 cpuidle_idle_call kernel/sched/idle.c:156 [inline]
 do_idle+0x262/0x3d0 kernel/sched/idle.c:246
 cpu_startup_entry+0x1b/0x20 kernel/sched/idle.c:351
 rest_init+0xf1/0xf6 init/main.c:435
 start_kernel+0x6df/0x6fd init/main.c:709
 x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:380
 x86_64_start_kernel+0x77/0x7b arch/x86/kernel/head64.c:361
 secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:240
Code: 89 ff 57 9d 0f 1f 44 00 00 e8 17 3f 0c 00 44 8b 3d 90 78 29 06 41 f6 c7 01 0f 85 07 01 00 00 e8 01 3f 0c 00 48 8b 05 ca 78 29 06 <48> 89 45 c8 4c 89 f0 48 c1 e8 03 42 80 3c 20 00 0f 85 53 01 00 

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2019/05/22 04:35 linux-4.14.y bbcb3c09eae4 84b9d384 .config log report
ci2-linux-4-14 2019/05/18 07:20 linux-4.14.y e6fedb8802c7 5a4461b0 .config log report