syzbot


possible deadlock in br_multicast_rcv

Status: upstream: reported C repro on 2023/01/24 01:03
Reported-by: syzbot+72264d699f39e9540b5e@syzkaller.appspotmail.com
First crash: 249d, last: 249d
Fix bisection: failed (error log, bisect log)
  
Similar bugs (5)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 possible deadlock in br_multicast_rcv 1 66d 66d 0/3 upstream: reported on 2023/07/26 02:43
linux-4.14 possible deadlock in br_multicast_rcv C 1 222d 252d 0/1 upstream: reported C repro on 2023/01/21 00:08
upstream possible deadlock in br_multicast_rcv (3) bridge C 9 25d 257d 0/25 upstream: reported C repro on 2023/01/16 16:40
upstream possible deadlock in br_multicast_rcv (2) bridge 11 621d 750d 0/25 auto-closed as invalid on 2022/05/17 09:29
upstream possible deadlock in br_multicast_rcv bridge 2 858d 859d 0/25 auto-closed as invalid on 2021/09/03 11:13

Sample crash report:
device vlan442 entered promiscuous mode
device bridge141 entered promiscuous mode
bridge140: port 1(vlan70) entered blocking state
bridge140: port 1(vlan70) entered forwarding state
============================================
WARNING: possible recursive locking detected
4.19.211-syzkaller #0 Not tainted
--------------------------------------------
systemd-sysctl/421 is trying to acquire lock:
00000000cb4503fb (&(&br->multicast_lock)->rlock){+.-.}, at: spin_lock include/linux/spinlock.h:329 [inline]
00000000cb4503fb (&(&br->multicast_lock)->rlock){+.-.}, at: br_ip6_multicast_query net/bridge/br_multicast.c:1526 [inline]
00000000cb4503fb (&(&br->multicast_lock)->rlock){+.-.}, at: br_multicast_ipv6_rcv net/bridge/br_multicast.c:1890 [inline]
00000000cb4503fb (&(&br->multicast_lock)->rlock){+.-.}, at: br_multicast_rcv+0x1fdf/0x3ce0 net/bridge/br_multicast.c:1925

but task is already holding lock:
00000000b422b3c9 (&(&br->multicast_lock)->rlock){+.-.}, at: spin_lock include/linux/spinlock.h:329 [inline]
00000000b422b3c9 (&(&br->multicast_lock)->rlock){+.-.}, at: br_multicast_port_query_expired+0x40/0x180 net/bridge/br_multicast.c:1003

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

       CPU0
       ----
  lock(&(&br->multicast_lock)->rlock);
  lock(&(&br->multicast_lock)->rlock);

 *** DEADLOCK ***

 May be due to missing lock nesting notation

8 locks held by systemd-sysctl/421:
 #0: 0000000063359a59 (&mm->mmap_sem){++++}, at: do_mprotect_pkey+0x1dc/0x9b0 mm/mprotect.c:517
 #1: 00000000280bd5a2 (&mapping->i_mmap_rwsem){+.+.}, at: i_mmap_lock_write include/linux/fs.h:491 [inline]
 #1: 00000000280bd5a2 (&mapping->i_mmap_rwsem){+.+.}, at: __vma_adjust+0x20d/0x17f0 mm/mmap.c:794
 #2: 0000000066a5bfe0 (&anon_vma->rwsem){++++}, at: anon_vma_lock_write include/linux/rmap.h:121 [inline]
 #2: 0000000066a5bfe0 (&anon_vma->rwsem){++++}, at: __vma_adjust+0x2d7/0x17f0 mm/mmap.c:812
 #3: 000000006aa0c400 ((&port->ip6_own_query.timer)){+.-.}, at: lockdep_copy_map include/linux/lockdep.h:168 [inline]
 #3: 000000006aa0c400 ((&port->ip6_own_query.timer)){+.-.}, at: call_timer_fn+0xc9/0x700 kernel/time/timer.c:1328
 #4: 00000000b422b3c9 (&(&br->multicast_lock)->rlock){+.-.}, at: spin_lock include/linux/spinlock.h:329 [inline]
 #4: 00000000b422b3c9 (&(&br->multicast_lock)->rlock){+.-.}, at: br_multicast_port_query_expired+0x40/0x180 net/bridge/br_multicast.c:1003
 #5: 00000000dc2cb97c (rcu_read_lock_bh){....}, at: __dev_queue_xmit+0x1e2/0x2e00 net/core/dev.c:3773
 #6: 00000000dc2cb97c (rcu_read_lock_bh){....}, at: __dev_queue_xmit+0x1e2/0x2e00 net/core/dev.c:3773
 #7: 00000000c230b582 (rcu_read_lock){....}, at: br_dev_xmit+0xcd/0x13e0 net/bridge/br_device.c:39

stack backtrace:
CPU: 1 PID: 421 Comm: systemd-sysctl Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 print_deadlock_bug kernel/locking/lockdep.c:1764 [inline]
 check_deadlock kernel/locking/lockdep.c:1808 [inline]
 validate_chain kernel/locking/lockdep.c:2404 [inline]
 __lock_acquire.cold+0x121/0x57e kernel/locking/lockdep.c:3416
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3908
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
 spin_lock include/linux/spinlock.h:329 [inline]
 br_ip6_multicast_query net/bridge/br_multicast.c:1526 [inline]
 br_multicast_ipv6_rcv net/bridge/br_multicast.c:1890 [inline]
 br_multicast_rcv+0x1fdf/0x3ce0 net/bridge/br_multicast.c:1925
 br_dev_xmit+0x9af/0x13e0 net/bridge/br_device.c:93
 __netdev_start_xmit include/linux/netdevice.h:4349 [inline]
 netdev_start_xmit include/linux/netdevice.h:4363 [inline]
 xmit_one net/core/dev.c:3256 [inline]
 dev_hard_start_xmit+0x1a8/0x920 net/core/dev.c:3272
 __dev_queue_xmit+0x269d/0x2e00 net/core/dev.c:3838
 vlan_dev_hard_start_xmit+0x38f/0x800 net/8021q/vlan_dev.c:131
 __netdev_start_xmit include/linux/netdevice.h:4349 [inline]
 netdev_start_xmit include/linux/netdevice.h:4363 [inline]
 xmit_one net/core/dev.c:3256 [inline]
 dev_hard_start_xmit+0x1a8/0x920 net/core/dev.c:3272
 __dev_queue_xmit+0x269d/0x2e00 net/core/dev.c:3838
 br_dev_queue_push_xmit+0x25a/0x6c0 net/bridge/br_forward.c:56
 NF_HOOK include/linux/netfilter.h:289 [inline]
 __br_multicast_send_query+0x1b81/0x2dc0 net/bridge/br_multicast.c:949
 br_multicast_send_query+0x216/0x3a0 net/bridge/br_multicast.c:988
 br_multicast_port_query_expired+0x121/0x180 net/bridge/br_multicast.c:1011
 call_timer_fn+0x177/0x700 kernel/time/timer.c:1338
 expire_timers+0x243/0x4e0 kernel/time/timer.c:1375
 __run_timers kernel/time/timer.c:1696 [inline]
 run_timer_softirq+0x21c/0x670 kernel/time/timer.c:1709
 __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:__sanitizer_cov_trace_pc+0x0/0x50 kernel/kcov.c:97
Code: ff 48 89 df e8 11 dd 35 00 e9 ab fe ff ff 4c 89 ef e8 04 dd 35 00 e9 23 fe ff ff 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 <48> 8b 34 24 65 48 8b 04 25 c0 df 01 00 65 8b 15 cc 59 9f 7e 81 e2
RSP: 0018:ffff88807eeffaf0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: ffff8880a565f180 RBX: ffff88809f4e2000 RCX: 000000000000408f
RDX: 1ffff11014acbe31 RSI: ffff88809f4e2020 RDI: ffff88809f4e2028
RBP: ffff888096a313a0 R08: ffffffff8cd379b8 R09: 0000000000000002
R10: ffff8880823a2ed8 R11: 0000000028e0a3ed R12: ffff8880a565f188
R13: ffff88809385c778 R14: 0000000000000000 R15: dffffc0000000000
 __rb_erase_augmented include/linux/rbtree_augmented.h:174 [inline]
 rb_erase_augmented_cached include/linux/rbtree_augmented.h:285 [inline]
 __anon_vma_interval_tree_remove mm/interval_tree.c:72 [inline]
 anon_vma_interval_tree_remove+0xac9/0xf80 mm/interval_tree.c:89
 anon_vma_interval_tree_pre_update_vma mm/mmap.c:482 [inline]
 __vma_adjust+0x326/0x17f0 mm/mmap.c:813
 vma_adjust include/linux/mm.h:2256 [inline]
 __split_vma+0x2bd/0x560 mm/mmap.c:2653
 split_vma+0x95/0xd0 mm/mmap.c:2682
 mprotect_fixup+0x7d9/0x9b0 mm/mprotect.c:451
 do_mprotect_pkey+0x562/0x9b0 mm/mprotect.c:589
 __do_sys_mprotect mm/mprotect.c:614 [inline]
 __se_sys_mprotect mm/mprotect.c:611 [inline]
 __x64_sys_mprotect+0x74/0xb0 mm/mprotect.c:611
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7f9ec004f3a7
Code: ff 66 90 b8 0b 00 00 00 0f 05 48 3d 01 f0 ff ff 73 01 c3 48 8d 0d 89 bd 20 00 f7 d8 89 01 48 83 c8 ff c3 b8 0a 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8d 0d 69 bd 20 00 f7 d8 89 01 48 83
RSP: 002b:00007fffc6ca3948 EFLAGS: 00000206 ORIG_RAX: 000000000000000a
RAX: ffffffffffffffda RBX: 00007f9ec02538b0 RCX: 00007f9ec004f3a7
RDX: 0000000000000001 RSI: 0000000000017000 RDI: 00007f9ebe688000
RBP: 00007fffc6ca3a80 R08: 0000000000000000 R09: 000000000000000e
R10: 00007f9ebe69efe0 R11: 0000000000000206 R12: 00007f9ec02538b0
R13: 0000000000000000 R14: 00007f9ebe45a000 R15: 00007f9ebe45a560
device bridge157 entered promiscuous mode
bridge156: port 1(vlan78) entered blocking state
bridge156: port 1(vlan78) entered forwarding state
device bridge275 entered promiscuous mode
bridge274: port 1(vlan137) entered blocking state
bridge274: port 1(vlan137) entered forwarding state
nla_parse: 31 callbacks suppressed
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
device bridge311 entered promiscuous mode
bridge310: port 1(vlan155) entered blocking state
bridge310: port 1(vlan155) entered forwarding state
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
device bridge361 entered promiscuous mode
bridge360: port 1(vlan180) entered blocking state
bridge360: port 1(vlan180) entered forwarding state
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
device bridge393 entered promiscuous mode
bridge392: port 1(vlan196) entered blocking state
bridge392: port 1(vlan196) entered forwarding state
device bridge439 entered promiscuous mode
bridge438: port 1(vlan219) entered blocking state
bridge438: port 1(vlan219) entered forwarding state
syz-executor322 (1158) used greatest stack depth: 23448 bytes left
device bridge499 entered promiscuous mode
bridge498: port 1(vlan249) entered blocking state
bridge498: port 1(vlan249) entered forwarding state
device bridge621 entered promiscuous mode
bridge620: port 1(vlan310) entered blocking state
bridge620: port 1(vlan310) entered forwarding state
device bridge637 entered promiscuous mode
bridge636: port 1(vlan318) entered blocking state
bridge636: port 1(vlan318) entered forwarding state
nla_parse: 59 callbacks suppressed
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor322'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor322'.
bridge943: port 1(vlan443) entered blocking state
bridge943: port 1(vlan443) entered disabled state
device vlan443 entered promiscuous mode
bridge947: port 1(vlan444) entered blocking state
bridge947: port 1(vlan444) entered disabled state
device vlan444 entered promiscuous mode
bridge949: port 1(vlan445) entered blocking state
bridge949: port 1(vlan445) entered disabled state
device vlan445 entered promiscuous mode
bridge951: port 1(vlan446) entered blocking state
bridge951: port 1(vlan446) entered disabled state
device vlan446 entered promiscuous mode
----------------
Code disassembly (best guess), 1 bytes skipped:
   0:	48 89 df             	mov    %rbx,%rdi
   3:	e8 11 dd 35 00       	callq  0x35dd19
   8:	e9 ab fe ff ff       	jmpq   0xfffffeb8
   d:	4c 89 ef             	mov    %r13,%rdi
  10:	e8 04 dd 35 00       	callq  0x35dd19
  15:	e9 23 fe ff ff       	jmpq   0xfffffe3d
  1a:	90                   	nop
  1b:	90                   	nop
  1c:	90                   	nop
  1d:	90                   	nop
  1e:	90                   	nop
  1f:	90                   	nop
  20:	90                   	nop
  21:	90                   	nop
  22:	90                   	nop
  23:	90                   	nop
  24:	90                   	nop
  25:	90                   	nop
  26:	90                   	nop
  27:	90                   	nop
  28:	90                   	nop
* 29:	48 8b 34 24          	mov    (%rsp),%rsi <-- trapping instruction
  2d:	65 48 8b 04 25 c0 df 	mov    %gs:0x1dfc0,%rax
  34:	01 00
  36:	65 8b 15 cc 59 9f 7e 	mov    %gs:0x7e9f59cc(%rip),%edx        # 0x7e9f5a09
  3d:	81                   	.byte 0x81
  3e:	e2                   	.byte 0xe2

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/01/24 01:03 linux-4.19.y 3f8a27f9e27b 9dfcf09c .config console log report syz C [disk image] [vmlinux] ci2-linux-4-19 possible deadlock in br_multicast_rcv
* Struck through repros no longer work on HEAD.