sp0: Synchronizing with TNC Bluetooth: hci0 command 0x1003 tx timeout Bluetooth: hci0 sending frame failed (-49) Bluetooth: hci0 command 0x1001 tx timeout Bluetooth: hci0 sending frame failed (-49) BUG: sleeping function called from invalid context at kernel/locking/mutex.c:747 in_atomic(): 1, irqs_disabled(): 0, pid: 0, name: swapper/0 1 lock held by swapper/0/0: #0: ((&sp->resync_t)){+.-.}, at: [] lockdep_copy_map include/linux/lockdep.h:174 [inline] #0: ((&sp->resync_t)){+.-.}, at: [] call_timer_fn+0xc8/0x670 kernel/time/timer.c:1269 Preemption disabled at: [] schedule_preempt_disabled+0x1d/0x20 kernel/sched/core.c:3487 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.14.158-syzkaller #0 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+0x142/0x197 lib/dump_stack.c:58 ___might_sleep.cold+0x1bd/0x1f6 kernel/sched/core.c:6040 __might_sleep+0x93/0xb0 kernel/sched/core.c:5993 __mutex_lock_common kernel/locking/mutex.c:747 [inline] __mutex_lock+0xb9/0x1470 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 tpk_write+0x5d/0x2c0 drivers/char/ttyprintk.c:123 resync_tnc+0x1bc/0x3d0 drivers/net/hamradio/6pack.c:522 call_timer_fn+0x161/0x670 kernel/time/timer.c:1279 expire_timers kernel/time/timer.c:1318 [inline] __run_timers kernel/time/timer.c:1636 [inline] __run_timers kernel/time/timer.c:1604 [inline] run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649 __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] smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102 apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792 RIP: 0010:native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:61 RSP: 0018:ffffffff87e07de8 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10 RAX: 1ffffffff0fe2d2c RBX: ffffffff87e76240 RCX: 0000000000000000 RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffffffff87e76abc RBP: ffffffff87e07e10 R08: 1ffffffff1164501 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff87f16950 R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff87e76240 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+0x1d9/0x1e2 init/main.c:434 start_kernel+0x6df/0x6fd init/main.c:708 x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:399 x86_64_start_kernel+0x77/0x7b arch/x86/kernel/head64.c:380 secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:240 ================================ WARNING: inconsistent lock state 4.14.158-syzkaller #0 Tainted: G W -------------------------------- inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: (&tpk_port.port_write_mutex){+.?.}, at: [] tpk_write+0x5d/0x2c0 drivers/char/ttyprintk.c:123 {SOFTIRQ-ON-W} state was registered at: mark_irqflags kernel/locking/lockdep.c:3086 [inline] __lock_acquire+0xc33/0x4620 kernel/locking/lockdep.c:3444 lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994 __mutex_lock_common kernel/locking/mutex.c:756 [inline] __mutex_lock+0xe8/0x1470 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 tpk_write+0x5d/0x2c0 drivers/char/ttyprintk.c:123 tnc_init drivers/net/hamradio/6pack.c:541 [inline] sixpack_open+0x9b2/0xc85 drivers/net/hamradio/6pack.c:643 tty_ldisc_open.isra.0+0x73/0xb0 drivers/tty/tty_ldisc.c:474 tty_set_ldisc+0x29a/0x610 drivers/tty/tty_ldisc.c:599 tiocsetd drivers/tty/tty_io.c:2351 [inline] tty_ioctl+0x95b/0x1320 drivers/tty/tty_io.c:2595 vfs_ioctl fs/ioctl.c:46 [inline] file_ioctl fs/ioctl.c:500 [inline] do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684 SYSC_ioctl fs/ioctl.c:701 [inline] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 irq event stamp: 263882 hardirqs last enabled at (263882): [] dump_stack+0x17d/0x197 lib/dump_stack.c:63 hardirqs last disabled at (263881): [] dump_stack+0xa9/0x197 lib/dump_stack.c:40 softirqs last enabled at (263796): [] _local_bh_enable+0x1c/0x30 kernel/softirq.c:159 softirqs last disabled at (263797): [] invoke_softirq kernel/softirq.c:368 [inline] softirqs last disabled at (263797): [] irq_exit+0x160/0x1b0 kernel/softirq.c:409 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&tpk_port.port_write_mutex); lock(&tpk_port.port_write_mutex); *** DEADLOCK *** 1 lock held by swapper/0/0: #0: ((&sp->resync_t)){+.-.}, at: [] lockdep_copy_map include/linux/lockdep.h:174 [inline] #0: ((&sp->resync_t)){+.-.}, at: [] call_timer_fn+0xc8/0x670 kernel/time/timer.c:1269 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 4.14.158-syzkaller #0 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+0x142/0x197 lib/dump_stack.c:58 print_usage_bug.cold+0x330/0x42a kernel/locking/lockdep.c:2585 valid_state kernel/locking/lockdep.c:2598 [inline] mark_lock_irq kernel/locking/lockdep.c:2792 [inline] mark_lock+0xdbd/0x1240 kernel/locking/lockdep.c:3190 mark_irqflags kernel/locking/lockdep.c:3068 [inline] __lock_acquire+0xb57/0x4620 kernel/locking/lockdep.c:3444 lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994 __mutex_lock_common kernel/locking/mutex.c:756 [inline] __mutex_lock+0xe8/0x1470 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 tpk_write+0x5d/0x2c0 drivers/char/ttyprintk.c:123 resync_tnc+0x1bc/0x3d0 drivers/net/hamradio/6pack.c:522 call_timer_fn+0x161/0x670 kernel/time/timer.c:1279 expire_timers kernel/time/timer.c:1318 [inline] __run_timers kernel/time/timer.c:1636 [inline] __run_timers kernel/time/timer.c:1604 [inline] run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649 __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] smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102 apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792 RIP: 0010:native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:61 RSP: 0018:ffffffff87e07de8 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10 RAX: 1ffffffff0fe2d2c RBX: ffffffff87e76240 RCX: 0000000000000000 RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffffffff87e76abc RBP: ffffffff87e07e10 R08: 1ffffffff1164501 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff87f16950 R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff87e76240 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+0x1d9/0x1e2 init/main.c:434 start_kernel+0x6df/0x6fd init/main.c:708 x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:399 x86_64_start_kernel+0x77/0x7b arch/x86/kernel/head64.c:380 secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:240 Bluetooth: hci0 command 0x1009 tx timeout kobject: 'rfkill4' (ffff88808e38ef28): kobject_uevent_env kobject: 'rfkill4' (ffff88808e38ef28): fill_kobj_path: path = '/devices/virtual/bluetooth/hci0/rfkill4' kobject: 'rfkill4' (ffff88808e38ef28): kobject_cleanup, parent (null) kobject: 'rfkill4' (ffff88808e38ef28): calling ktype release kobject: 'rfkill4': free name kobject: 'hci0' (ffff88809388a8a8): kobject_uevent_env kobject: 'hci0' (ffff88809388a8a8): fill_kobj_path: path = '/devices/virtual/bluetooth/hci0' kobject: 'bluetooth' (ffff88809b1c2200): kobject_cleanup, parent (null) kobject: 'bluetooth' (ffff88809b1c2200): calling ktype release kobject: 'bluetooth': free name kobject: 'hci0' (ffff88809388a8a8): kobject_cleanup, parent (null) kobject: 'hci0' (ffff88809388a8a8): calling ktype release kobject: 'hci0': free name [U] è`è kobject: 'rx-0' (ffff88809c329250): kobject_cleanup, parent ffff8880a1314348 kobject: 'rx-0' (ffff88809c329250): auto cleanup 'remove' event kobject: 'rx-0' (ffff88809c329250): kobject_uevent_env kobject: 'rx-0' (ffff88809c329250): fill_kobj_path: path = '/devices/virtual/net/sp0/queues/rx-0' kobject: 'rx-0' (ffff88809c329250): auto cleanup kobject_del kobject: 'rx-0' (ffff88809c329250): calling ktype release kobject: 'rx-0': free name kobject: 'tx-0' (ffff88809d8a87d8): kobject_cleanup, parent ffff8880a1314348 kobject: 'tx-0' (ffff88809d8a87d8): auto cleanup 'remove' event kobject: 'tx-0' (ffff88809d8a87d8): kobject_uevent_env kobject: 'tx-0' (ffff88809d8a87d8): fill_kobj_path: path = '/devices/virtual/net/sp0/queues/tx-0' kobject: 'tx-0' (ffff88809d8a87d8): auto cleanup kobject_del kobject: 'tx-0' (ffff88809d8a87d8): calling ktype release kobject: 'tx-0': free name kobject: 'queues' (ffff8880a1314348): kobject_cleanup, parent (null) kobject: 'queues' (ffff8880a1314348): calling ktype release kobject: 'queues' (ffff8880a1314348): kset_release kobject: 'queues': free name kobject: 'sp0' (ffff88808e2df0f0): kobject_uevent_env kobject: 'sp0' (ffff88808e2df0f0): fill_kobj_path: path = '/devices/virtual/net/sp0' kobject: 'sp0' (ffff88808e2df0f0): kobject_cleanup, parent (null) kobject: 'sp0' (ffff88808e2df0f0): calling ktype release kobject: 'sp0': free name