syzbot


inconsistent lock state in ax25_rt_autobind

Status: fixed on 2019/07/10 21:40
Subsystems: hams
[Documentation on labels]
Fix commit: d4d5d8e83c96 ax25: fix inconsistent lock state in ax25_destroy_timer
First crash: 1784d, last: 1783d

Sample crash report:
ax25_connect(): syz-executor.0 uses autobind, please contact jreuter@yaina.de
================================
WARNING: inconsistent lock state
5.2.0-rc3+ #35 Not tainted
--------------------------------
inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
syz-executor.0/13636 [HC0[0]:SC0[0]:HE1:SE1] takes:
00000000bfcce1b2 (slock-AF_AX25){+.?.}, at: spin_lock include/linux/spinlock.h:338 [inline]
00000000bfcce1b2 (slock-AF_AX25){+.?.}, at: ax25_rt_autobind+0x3ca/0x720 net/ax25/ax25_route.c:429
{IN-SOFTIRQ-W} state was registered at:
  lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4303
  __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
  _raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
  spin_lock include/linux/spinlock.h:338 [inline]
  ax25_destroy_timer+0x53/0xc0 net/ax25/af_ax25.c:275
  call_timer_fn+0x193/0x720 kernel/time/timer.c:1322
  expire_timers kernel/time/timer.c:1366 [inline]
  __run_timers kernel/time/timer.c:1685 [inline]
  __run_timers kernel/time/timer.c:1653 [inline]
  run_timer_softirq+0x66f/0x1740 kernel/time/timer.c:1698
  __do_softirq+0x25c/0x94c kernel/softirq.c:293
  invoke_softirq kernel/softirq.c:374 [inline]
  irq_exit+0x180/0x1d0 kernel/softirq.c:414
  exiting_irq arch/x86/include/asm/apic.h:536 [inline]
  smp_apic_timer_interrupt+0x13b/0x550 arch/x86/kernel/apic/apic.c:1068
  apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:806
  batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:404 [inline]
  batadv_nc_worker+0x229/0x760 net/batman-adv/network-coding.c:718
  process_one_work+0x989/0x1790 kernel/workqueue.c:2269
  worker_thread+0x98/0xe40 kernel/workqueue.c:2415
  kthread+0x354/0x420 kernel/kthread.c:255
  ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
irq event stamp: 467
hardirqs last  enabled at (467): [<ffffffff871f643b>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
hardirqs last  enabled at (467): [<ffffffff871f643b>] _raw_spin_unlock_irqrestore+0x6b/0xe0 kernel/locking/spinlock.c:191
hardirqs last disabled at (466): [<ffffffff871f66cf>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (466): [<ffffffff871f66cf>] _raw_spin_lock_irqsave+0x6f/0xcd kernel/locking/spinlock.c:159
softirqs last  enabled at (456): [<ffffffff87400654>] __do_softirq+0x654/0x94c kernel/softirq.c:320
softirqs last disabled at (363): [<ffffffff81449010>] invoke_softirq kernel/softirq.c:374 [inline]
softirqs last disabled at (363): [<ffffffff81449010>] irq_exit+0x180/0x1d0 kernel/softirq.c:414

other info that might help us debug this:
 Possible unsafe locking scenario:

       CPU0
       ----
  lock(slock-AF_AX25);
  <Interrupt>
    lock(slock-AF_AX25);

 *** DEADLOCK ***

2 locks held by syz-executor.0/13636:
 #0: 00000000f7388db4 (sk_lock-AF_AX25){+.+.}, at: lock_sock include/net/sock.h:1520 [inline]
 #0: 00000000f7388db4 (sk_lock-AF_AX25){+.+.}, at: ax25_connect+0x188/0x13f0 net/ax25/af_ax25.c:1149
 #1: 00000000ce5dacaa (ax25_route_lock){++.+}, at: ax25_route_lock_use include/net/ax25.h:208 [inline]
 #1: 00000000ce5dacaa (ax25_route_lock){++.+}, at: ax25_rt_autobind+0x28/0x720 net/ax25/ax25_route.c:395

stack backtrace:
CPU: 1 PID: 13636 Comm: syz-executor.0 Not tainted 5.2.0-rc3+ #35
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
 print_usage_bug.cold+0x393/0x4a2 kernel/locking/lockdep.c:2935
 valid_state kernel/locking/lockdep.c:2948 [inline]
 mark_lock_irq kernel/locking/lockdep.c:3138 [inline]
 mark_lock+0xd46/0x1370 kernel/locking/lockdep.c:3513
 mark_irqflags kernel/locking/lockdep.c:3409 [inline]
 __lock_acquire+0x12df/0x5490 kernel/locking/lockdep.c:3745
 lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4303
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
 spin_lock include/linux/spinlock.h:338 [inline]
 ax25_rt_autobind+0x3ca/0x720 net/ax25/ax25_route.c:429
 ax25_connect.cold+0x30/0xa4 net/ax25/af_ax25.c:1221
 __sys_connect+0x264/0x330 net/socket.c:1834
 __do_sys_connect net/socket.c:1845 [inline]
 __se_sys_connect net/socket.c:1842 [inline]
 __x64_sys_connect+0x73/0xb0 net/socket.c:1842
 do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4592c9
Code: fd b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 cb b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f924775ac78 EFLAGS: 00000246 ORIG_RAX: 000000000000002a
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00000000004592c9
RDX: 0000000000000048 RSI: 0000000020000040 RDI: 0000000000000004
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f924775b6d4
R13: 00000000004bf741 R14: 00000000004d0e78 R15: 00000000ffffffff

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/06/17 05:05 net-next-old f464100f5766 442206d7 .config console log report ci-upstream-net-kasan-gce
2019/06/16 15:21 net-next-old 9d9f3fba4c46 442206d7 .config console log report ci-upstream-net-kasan-gce
* Struck through repros no longer work on HEAD.