possible deadlock in vm_mmap_pgoff
10 views
Skip to first unread message
syzbot
Apr 4, 2021, 2:32:17 PM4/4/21
to syzkaller...@googlegroups.com
Hello,
syzbot found the following issue on:
HEAD commit: 2034d6f0 Linux 4.19.184
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1244b16ed00000
kernel config: https://syzkaller.appspot.com/x/.config?x=42af7daace4bc0cc
dashboard link: https://syzkaller.appspot.com/bug?extid=5e358dd53781fed47144
Unfortunately, I don't have any reproducer for this issue yet.
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+5e358d...@syzkaller.appspotmail.com
wlan1: Created IBSS using preconfigured BSSID 50:50:50:50:50:50
wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
kvm [15814]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc1 data 0x0
kvm [15814]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc1 data 0x0
======================================================
WARNING: possible circular locking dependency detected
4.19.184-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.5/15794 is trying to acquire lock:
00000000f9da3b3c (event_mutex){+.+.}, at: perf_trace_destroy+0x23/0xf0 kernel/trace/trace_event_perf.c:236
but task is already holding lock:
00000000c8f2c612 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x152/0x200 mm/util.c:355
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #3 (&mm->mmap_sem){++++}:
dup_mmap kernel/fork.c:436 [inline]
dup_mm kernel/fork.c:1284 [inline]
copy_mm kernel/fork.c:1340 [inline]
copy_process.part.0+0x2bcf/0x8260 kernel/fork.c:1912
copy_process kernel/fork.c:1709 [inline]
_do_fork+0x22f/0xf30 kernel/fork.c:2218
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #2 (&dup_mmap_sem){++++}:
percpu_down_write+0x62/0x3f0 kernel/locking/percpu-rwsem.c:145
register_for_each_vma+0x91/0xe40 kernel/events/uprobes.c:793
__uprobe_register kernel/events/uprobes.c:929 [inline]
uprobe_register+0x3dc/0x730 kernel/events/uprobes.c:944
probe_event_enable+0x425/0xbb0 kernel/trace/trace_uprobe.c:915
trace_uprobe_register+0x2d8/0x790 kernel/trace/trace_uprobe.c:1200
perf_trace_event_reg kernel/trace/trace_event_perf.c:124 [inline]
perf_trace_event_init+0x4c1/0x920 kernel/trace/trace_event_perf.c:199
perf_uprobe_init+0x165/0x200 kernel/trace/trace_event_perf.c:330
perf_uprobe_event_init+0xf8/0x190 kernel/events/core.c:8589
perf_try_init_event+0x124/0x2e0 kernel/events/core.c:9860
perf_init_event kernel/events/core.c:9891 [inline]
perf_event_alloc.part.0+0x1b16/0x2eb0 kernel/events/core.c:10165
perf_event_alloc kernel/events/core.c:10535 [inline]
__do_sys_perf_event_open kernel/events/core.c:10636 [inline]
__se_sys_perf_event_open+0x550/0x2720 kernel/events/core.c:10525
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #1 (&uprobe->register_rwsem){+.+.}:
__uprobe_register kernel/events/uprobes.c:925 [inline]
uprobe_register+0x34b/0x730 kernel/events/uprobes.c:944
probe_event_enable+0x425/0xbb0 kernel/trace/trace_uprobe.c:915
trace_uprobe_register+0x2d8/0x790 kernel/trace/trace_uprobe.c:1200
perf_trace_event_reg kernel/trace/trace_event_perf.c:124 [inline]
perf_trace_event_init+0x4c1/0x920 kernel/trace/trace_event_perf.c:199
perf_uprobe_init+0x165/0x200 kernel/trace/trace_event_perf.c:330
perf_uprobe_event_init+0xf8/0x190 kernel/events/core.c:8589
perf_try_init_event+0x124/0x2e0 kernel/events/core.c:9860
perf_init_event kernel/events/core.c:9891 [inline]
perf_event_alloc.part.0+0x1b16/0x2eb0 kernel/events/core.c:10165
perf_event_alloc kernel/events/core.c:10535 [inline]
__do_sys_perf_event_open kernel/events/core.c:10636 [inline]
__se_sys_perf_event_open+0x550/0x2720 kernel/events/core.c:10525
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #0 (event_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:925 [inline]
__mutex_lock+0xd7/0x1260 kernel/locking/mutex.c:1072
perf_trace_destroy+0x23/0xf0 kernel/trace/trace_event_perf.c:236
_free_event+0x32c/0x1150 kernel/events/core.c:4460
put_event kernel/events/core.c:4554 [inline]
perf_mmap_close+0x6f6/0xea0 kernel/events/core.c:5558
remove_vma+0xa9/0x170 mm/mmap.c:176
remove_vma_list mm/mmap.c:2550 [inline]
do_munmap+0x6f9/0xde0 mm/mmap.c:2786
mmap_region+0x2a3/0x16b0 mm/mmap.c:1700
do_mmap+0x8e8/0x1080 mm/mmap.c:1530
do_mmap_pgoff include/linux/mm.h:2326 [inline]
vm_mmap_pgoff+0x197/0x200 mm/util.c:357
ksys_mmap_pgoff+0x298/0x5a0 mm/mmap.c:1580
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
other info that might help us debug this:
Chain exists of:
event_mutex --> &dup_mmap_sem --> &mm->mmap_sem
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&mm->mmap_sem);
lock(&dup_mmap_sem);
lock(&mm->mmap_sem);
lock(event_mutex);
*** DEADLOCK ***
1 lock held by syz-executor.5/15794:
#0: 00000000c8f2c612 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x152/0x200 mm/util.c:355
stack backtrace:
CPU: 1 PID: 15794 Comm: syz-executor.5 Not tainted 4.19.184-syzkaller #0
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+0x1fc/0x2ef lib/dump_stack.c:118
print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1221
check_prev_add kernel/locking/lockdep.c:1865 [inline]
check_prevs_add kernel/locking/lockdep.c:1978 [inline]
validate_chain kernel/locking/lockdep.c:2419 [inline]
__lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3415
lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
__mutex_lock_common kernel/locking/mutex.c:925 [inline]
__mutex_lock+0xd7/0x1260 kernel/locking/mutex.c:1072
perf_trace_destroy+0x23/0xf0 kernel/trace/trace_event_perf.c:236
_free_event+0x32c/0x1150 kernel/events/core.c:4460
put_event kernel/events/core.c:4554 [inline]
perf_mmap_close+0x6f6/0xea0 kernel/events/core.c:5558
remove_vma+0xa9/0x170 mm/mmap.c:176
remove_vma_list mm/mmap.c:2550 [inline]
do_munmap+0x6f9/0xde0 mm/mmap.c:2786
mmap_region+0x2a3/0x16b0 mm/mmap.c:1700
do_mmap+0x8e8/0x1080 mm/mmap.c:1530
do_mmap_pgoff include/linux/mm.h:2326 [inline]
vm_mmap_pgoff+0x197/0x200 mm/util.c:357
ksys_mmap_pgoff+0x298/0x5a0 mm/mmap.c:1580
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x466459
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f19b1024188 EFLAGS: 00000246 ORIG_RAX: 0000000000000009
RAX: ffffffffffffffda RBX: 000000000056c0b0 RCX: 0000000000466459
RDX: 0000000000000000 RSI: 0000000000003000 RDI: 0000000020ffc000
RBP: 00000000004bf9fb R08: 0000000000000006 R09: 0000000000000000
R10: 0000000000000011 R11: 0000000000000246 R12: 000000000056c0b0
R13: 00007fff0c1390bf R14: 00007f19b1024300 R15: 0000000000022000
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.5'.
IPv6: ADDRCONF(NETDEV_CHANGE): gtp0: link becomes ready
kauditd_printk_skb: 11 callbacks suppressed
audit: type=1804 audit(1617561086.379:261): pid=15901 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/182/bus" dev="sda1" ino=14569 res=1
audit: type=1804 audit(1617561086.549:262): pid=15906 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/183/bus" dev="sda1" ino=14581 res=1
IPv6: ADDRCONF(NETDEV_CHANGE): gtp0: link becomes ready
audit: type=1804 audit(1617561086.649:263): pid=15914 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/183/bus" dev="sda1" ino=14581 res=1
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
bond0: team0 is up - this may be due to an out of date ifenslave
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
bridge0: port 3(team0) entered blocking state
audit: type=1804 audit(1617561086.939:264): pid=15945 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/184/bus" dev="sda1" ino=14581 res=1
bridge0: port 3(team0) entered disabled state
device team0 entered promiscuous mode
device team_slave_0 entered promiscuous mode
device team_slave_1 entered promiscuous mode
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered forwarding state
netlink: 'syz-executor.4': attribute type 1 has an invalid length.
bond2: Enslaving bridge2 as a backup interface with an up link
bond2: Enslaving bridge3 as a backup interface with a down link
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
device team0 left promiscuous mode
device team_slave_0 left promiscuous mode
device team_slave_1 left promiscuous mode
bridge0: port 3(team0) entered disabled state
bond0: team0 is up - this may be due to an out of date ifenslave
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered disabled state
device team0 entered promiscuous mode
device team_slave_0 entered promiscuous mode
device team_slave_1 entered promiscuous mode
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered forwarding state
bond2 (unregistering): Releasing backup interface bridge2
9pnet: Insufficient options for proto=fd
9pnet: Insufficient options for proto=fd
bond2 (unregistering): Releasing backup interface bridge3
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(4)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
bond2 (unregistering): Released all slaves
audit: type=1804 audit(1617561087.749:265): pid=15956 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/184/bus" dev="sda1" ino=14581 res=1
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'.
netlink: 14 bytes leftover after parsing attributes in process `syz-executor.0'.
bridge0: port 3(team0) entered disabled state
bridge0: port 2(bridge_slave_1) entered disabled state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge0 entered promiscuous mode
netlink: 'syz-executor.4': attribute type 1 has an invalid length.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 28 bytes leftover after parsing attributes in process `syz-executor.5'.
usb 19-1: new high-speed USB device number 2 using vhci_hcd
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 14 bytes leftover after parsing attributes in process `syz-executor.0'.
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered forwarding state
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered forwarding state
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
device bridge0 left promiscuous mode
bridge0: port 3(team0) entered disabled state
bridge0: port 2(bridge_slave_1) entered disabled state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge0 entered promiscuous mode
vhci_hcd: connection reset by peer
vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd: disconnect device
audit: type=1804 audit(1617561088.229:266): pid=16118 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/185/bus" dev="sda1" ino=14575 res=1
audit: type=1804 audit(1617561088.289:267): pid=16118 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/185/bus" dev="sda1" ino=14575 res=1
A link change request failed with some changes committed already. Interface ipvlan1 may have been left with an inconsistent configuration, please check.
A link change request failed with some changes committed already. Interface ipvlan1 may have been left with an inconsistent configuration, please check.
audit: type=1804 audit(1617561088.449:268): pid=16133 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/186/bus" dev="sda1" ino=14595 res=1
audit: type=1804 audit(1617561088.499:269): pid=16143 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/186/bus" dev="sda1" ino=14595 res=1
device wlan1 entered promiscuous mode
ubi0: attaching mtd0
audit: type=1804 audit(1617561088.609:270): pid=16155 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/187/bus" dev="sda1" ino=14585 res=1
ubi0: scanning is finished
ubi0: empty MTD device detected
vhci_hcd vhci_hcd.0: pdev(5) rhport(1) sockfd(4)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd: disconnect device
ubi0: attached mtd0 (name "mtdram test device", size 0 MiB)
ubi0: PEB size: 4096 bytes (4 KiB), LEB size: 3968 bytes
ubi0: min./max. I/O unit sizes: 1/64, sub-page size 1
ieee802154 phy0 wpan0: encryption failed: -22
ieee802154 phy1 wpan1: encryption failed: -22
ubi0: VID header offset: 64 (aligned 64), data offset: 128
ubi0: good PEBs: 32, bad PEBs: 0, corrupted PEBs: 0
ubi0: user volume: 0, internal volumes: 1, max. volumes count: 23
ubi0: max/mean erase counter: 0/0, WL threshold: 4096, image sequence number: 2984873490
ubi0: available PEBs: 28, total reserved PEBs: 4, PEBs reserved for bad PEB handling: 0
affs: Unrecognized mount option "default_permissions" or missing value
affs: Error parsing options
ubi0: background thread "ubi_bgt0d" started, PID 16182
ubi0: detaching mtd0
ubi0: mtd0 is detached
ubi0: attaching mtd0
ubi0: scanning is finished
EXT4-fs (loop5): VFS: Can't find ext4 filesystem
ubi0 error: ubi_attach_mtd_dev: cannot spawn "ubi_bgt0d", error -4
affs: Unrecognized mount option "default_permissions" or missing value
affs: Error parsing options
netlink: 'syz-executor.3': attribute type 10 has an invalid length.
IPVS: ftp: loaded support on port[0] = 21
bond0: team0 is up - this may be due to an out of date ifenslave
overlayfs: upperdir is in-use as upperdir/workdir of another mount, mount with '-o index=off' to override exclusive upperdir protection.
nla_parse: 1 callbacks suppressed
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.5'.
IPVS: ftp: loaded support on port[0] = 21
squashfs: SQUASHFS error: Can't find a SQUASHFS superblock on loop5
9pnet: p9_fd_create_tcp (16437): problem connecting socket to 127.0.0.1
overlayfs: upperdir is in-use as upperdir/workdir of another mount, mount with '-o index=off' to override exclusive upperdir protection.
9pnet: p9_fd_create_tcp (16449): problem connecting socket to 127.0.0.1
Bluetooth: hci5: command 0x0406 tx timeout
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
EXT4-fs (loop5): VFS: Can't find ext4 filesystem
IPVS: ftp: loaded support on port[0] = 21
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
kauditd_printk_skb: 9 callbacks suppressed
audit: type=1804 audit(1617561091.870:280): pid=16479 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/194/bus" dev="sda1" ino=13947 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
9pnet: p9_fd_create_tcp (16508): problem connecting socket to 127.0.0.1
audit: type=1804 audit(1617561091.950:281): pid=16495 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/194/bus" dev="sda1" ino=13947 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1800 audit(1617561092.140:282): pid=16517 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.1" name="bus" dev="sda1" ino=14242 res=0
new mount options do not match the existing superblock, will be ignored
audit: type=1804 audit(1617561092.160:283): pid=16524 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/195/bus" dev="sda1" ino=14354 res=1
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1804 audit(1617561092.240:284): pid=16532 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/195/bus" dev="sda1" ino=14354 res=1
new mount options do not match the existing superblock, will be ignored
audit: type=1804 audit(1617561092.410:285): pid=16527 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.5" name="/root/syzkaller-testdir383681739/syzkaller.NdE7oW/124/bus" dev="sda1" ino=14369 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1804 audit(1617561092.550:286): pid=16560 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/196/bus" dev="sda1" ino=14002 res=1
audit: type=1804 audit(1617561092.610:287): pid=16570 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/196/bus" dev="sda1" ino=14002 res=1
IPVS: ftp: loaded support on port[0] = 21
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1804 audit(1617561092.750:288): pid=16563 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.5" name="/root/syzkaller-testdir383681739/syzkaller.NdE7oW/125/bus" dev="sda1" ino=13993 res=1
audit: type=1800 audit(1617561092.950:289): pid=16606 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.1" name="bus" dev="sda1" ino=14242 res=0
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
vhci_hcd: vhci_device speed not set
IPVS: ftp: loaded support on port[0] = 21
overlayfs: missing 'lowerdir'
orangefs_mount: mount request failed with -4
mac80211_hwsim: wmediumd released netlink socket, switching to perfect channel medium
IPVS: ftp: loaded support on port[0] = 21
mac80211_hwsim: wmediumd released netlink socket, switching to perfect channel medium
---
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 found the following issue on:
HEAD commit: 2034d6f0 Linux 4.19.184
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1244b16ed00000
kernel config: https://syzkaller.appspot.com/x/.config?x=42af7daace4bc0cc
dashboard link: https://syzkaller.appspot.com/bug?extid=5e358dd53781fed47144
Unfortunately, I don't have any reproducer for this issue yet.
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+5e358d...@syzkaller.appspotmail.com
wlan1: Created IBSS using preconfigured BSSID 50:50:50:50:50:50
wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
kvm [15814]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc1 data 0x0
kvm [15814]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc1 data 0x0
======================================================
WARNING: possible circular locking dependency detected
4.19.184-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.5/15794 is trying to acquire lock:
00000000f9da3b3c (event_mutex){+.+.}, at: perf_trace_destroy+0x23/0xf0 kernel/trace/trace_event_perf.c:236
but task is already holding lock:
00000000c8f2c612 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x152/0x200 mm/util.c:355
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #3 (&mm->mmap_sem){++++}:
dup_mmap kernel/fork.c:436 [inline]
dup_mm kernel/fork.c:1284 [inline]
copy_mm kernel/fork.c:1340 [inline]
copy_process.part.0+0x2bcf/0x8260 kernel/fork.c:1912
copy_process kernel/fork.c:1709 [inline]
_do_fork+0x22f/0xf30 kernel/fork.c:2218
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #2 (&dup_mmap_sem){++++}:
percpu_down_write+0x62/0x3f0 kernel/locking/percpu-rwsem.c:145
register_for_each_vma+0x91/0xe40 kernel/events/uprobes.c:793
__uprobe_register kernel/events/uprobes.c:929 [inline]
uprobe_register+0x3dc/0x730 kernel/events/uprobes.c:944
probe_event_enable+0x425/0xbb0 kernel/trace/trace_uprobe.c:915
trace_uprobe_register+0x2d8/0x790 kernel/trace/trace_uprobe.c:1200
perf_trace_event_reg kernel/trace/trace_event_perf.c:124 [inline]
perf_trace_event_init+0x4c1/0x920 kernel/trace/trace_event_perf.c:199
perf_uprobe_init+0x165/0x200 kernel/trace/trace_event_perf.c:330
perf_uprobe_event_init+0xf8/0x190 kernel/events/core.c:8589
perf_try_init_event+0x124/0x2e0 kernel/events/core.c:9860
perf_init_event kernel/events/core.c:9891 [inline]
perf_event_alloc.part.0+0x1b16/0x2eb0 kernel/events/core.c:10165
perf_event_alloc kernel/events/core.c:10535 [inline]
__do_sys_perf_event_open kernel/events/core.c:10636 [inline]
__se_sys_perf_event_open+0x550/0x2720 kernel/events/core.c:10525
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #1 (&uprobe->register_rwsem){+.+.}:
__uprobe_register kernel/events/uprobes.c:925 [inline]
uprobe_register+0x34b/0x730 kernel/events/uprobes.c:944
probe_event_enable+0x425/0xbb0 kernel/trace/trace_uprobe.c:915
trace_uprobe_register+0x2d8/0x790 kernel/trace/trace_uprobe.c:1200
perf_trace_event_reg kernel/trace/trace_event_perf.c:124 [inline]
perf_trace_event_init+0x4c1/0x920 kernel/trace/trace_event_perf.c:199
perf_uprobe_init+0x165/0x200 kernel/trace/trace_event_perf.c:330
perf_uprobe_event_init+0xf8/0x190 kernel/events/core.c:8589
perf_try_init_event+0x124/0x2e0 kernel/events/core.c:9860
perf_init_event kernel/events/core.c:9891 [inline]
perf_event_alloc.part.0+0x1b16/0x2eb0 kernel/events/core.c:10165
perf_event_alloc kernel/events/core.c:10535 [inline]
__do_sys_perf_event_open kernel/events/core.c:10636 [inline]
__se_sys_perf_event_open+0x550/0x2720 kernel/events/core.c:10525
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #0 (event_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:925 [inline]
__mutex_lock+0xd7/0x1260 kernel/locking/mutex.c:1072
perf_trace_destroy+0x23/0xf0 kernel/trace/trace_event_perf.c:236
_free_event+0x32c/0x1150 kernel/events/core.c:4460
put_event kernel/events/core.c:4554 [inline]
perf_mmap_close+0x6f6/0xea0 kernel/events/core.c:5558
remove_vma+0xa9/0x170 mm/mmap.c:176
remove_vma_list mm/mmap.c:2550 [inline]
do_munmap+0x6f9/0xde0 mm/mmap.c:2786
mmap_region+0x2a3/0x16b0 mm/mmap.c:1700
do_mmap+0x8e8/0x1080 mm/mmap.c:1530
do_mmap_pgoff include/linux/mm.h:2326 [inline]
vm_mmap_pgoff+0x197/0x200 mm/util.c:357
ksys_mmap_pgoff+0x298/0x5a0 mm/mmap.c:1580
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
other info that might help us debug this:
Chain exists of:
event_mutex --> &dup_mmap_sem --> &mm->mmap_sem
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&mm->mmap_sem);
lock(&dup_mmap_sem);
lock(&mm->mmap_sem);
lock(event_mutex);
*** DEADLOCK ***
1 lock held by syz-executor.5/15794:
#0: 00000000c8f2c612 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x152/0x200 mm/util.c:355
stack backtrace:
CPU: 1 PID: 15794 Comm: syz-executor.5 Not tainted 4.19.184-syzkaller #0
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+0x1fc/0x2ef lib/dump_stack.c:118
print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1221
check_prev_add kernel/locking/lockdep.c:1865 [inline]
check_prevs_add kernel/locking/lockdep.c:1978 [inline]
validate_chain kernel/locking/lockdep.c:2419 [inline]
__lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3415
lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
__mutex_lock_common kernel/locking/mutex.c:925 [inline]
__mutex_lock+0xd7/0x1260 kernel/locking/mutex.c:1072
perf_trace_destroy+0x23/0xf0 kernel/trace/trace_event_perf.c:236
_free_event+0x32c/0x1150 kernel/events/core.c:4460
put_event kernel/events/core.c:4554 [inline]
perf_mmap_close+0x6f6/0xea0 kernel/events/core.c:5558
remove_vma+0xa9/0x170 mm/mmap.c:176
remove_vma_list mm/mmap.c:2550 [inline]
do_munmap+0x6f9/0xde0 mm/mmap.c:2786
mmap_region+0x2a3/0x16b0 mm/mmap.c:1700
do_mmap+0x8e8/0x1080 mm/mmap.c:1530
do_mmap_pgoff include/linux/mm.h:2326 [inline]
vm_mmap_pgoff+0x197/0x200 mm/util.c:357
ksys_mmap_pgoff+0x298/0x5a0 mm/mmap.c:1580
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x466459
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f19b1024188 EFLAGS: 00000246 ORIG_RAX: 0000000000000009
RAX: ffffffffffffffda RBX: 000000000056c0b0 RCX: 0000000000466459
RDX: 0000000000000000 RSI: 0000000000003000 RDI: 0000000020ffc000
RBP: 00000000004bf9fb R08: 0000000000000006 R09: 0000000000000000
R10: 0000000000000011 R11: 0000000000000246 R12: 000000000056c0b0
R13: 00007fff0c1390bf R14: 00007f19b1024300 R15: 0000000000022000
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.5'.
IPv6: ADDRCONF(NETDEV_CHANGE): gtp0: link becomes ready
kauditd_printk_skb: 11 callbacks suppressed
audit: type=1804 audit(1617561086.379:261): pid=15901 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/182/bus" dev="sda1" ino=14569 res=1
audit: type=1804 audit(1617561086.549:262): pid=15906 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/183/bus" dev="sda1" ino=14581 res=1
IPv6: ADDRCONF(NETDEV_CHANGE): gtp0: link becomes ready
audit: type=1804 audit(1617561086.649:263): pid=15914 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/183/bus" dev="sda1" ino=14581 res=1
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
bond0: team0 is up - this may be due to an out of date ifenslave
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
bridge0: port 3(team0) entered blocking state
audit: type=1804 audit(1617561086.939:264): pid=15945 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/184/bus" dev="sda1" ino=14581 res=1
bridge0: port 3(team0) entered disabled state
device team0 entered promiscuous mode
device team_slave_0 entered promiscuous mode
device team_slave_1 entered promiscuous mode
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered forwarding state
netlink: 'syz-executor.4': attribute type 1 has an invalid length.
bond2: Enslaving bridge2 as a backup interface with an up link
bond2: Enslaving bridge3 as a backup interface with a down link
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
device team0 left promiscuous mode
device team_slave_0 left promiscuous mode
device team_slave_1 left promiscuous mode
bridge0: port 3(team0) entered disabled state
bond0: team0 is up - this may be due to an out of date ifenslave
netlink: 'syz-executor.0': attribute type 10 has an invalid length.
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered disabled state
device team0 entered promiscuous mode
device team_slave_0 entered promiscuous mode
device team_slave_1 entered promiscuous mode
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered forwarding state
bond2 (unregistering): Releasing backup interface bridge2
9pnet: Insufficient options for proto=fd
9pnet: Insufficient options for proto=fd
bond2 (unregistering): Releasing backup interface bridge3
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(4)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
bond2 (unregistering): Released all slaves
audit: type=1804 audit(1617561087.749:265): pid=15956 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/184/bus" dev="sda1" ino=14581 res=1
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'.
netlink: 14 bytes leftover after parsing attributes in process `syz-executor.0'.
bridge0: port 3(team0) entered disabled state
bridge0: port 2(bridge_slave_1) entered disabled state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge0 entered promiscuous mode
netlink: 'syz-executor.4': attribute type 1 has an invalid length.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 28 bytes leftover after parsing attributes in process `syz-executor.5'.
usb 19-1: new high-speed USB device number 2 using vhci_hcd
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 14 bytes leftover after parsing attributes in process `syz-executor.0'.
bridge0: port 3(team0) entered blocking state
bridge0: port 3(team0) entered forwarding state
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered forwarding state
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
device bridge0 left promiscuous mode
bridge0: port 3(team0) entered disabled state
bridge0: port 2(bridge_slave_1) entered disabled state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge0 entered promiscuous mode
vhci_hcd: connection reset by peer
vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd: disconnect device
audit: type=1804 audit(1617561088.229:266): pid=16118 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/185/bus" dev="sda1" ino=14575 res=1
audit: type=1804 audit(1617561088.289:267): pid=16118 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/185/bus" dev="sda1" ino=14575 res=1
A link change request failed with some changes committed already. Interface ipvlan1 may have been left with an inconsistent configuration, please check.
A link change request failed with some changes committed already. Interface ipvlan1 may have been left with an inconsistent configuration, please check.
audit: type=1804 audit(1617561088.449:268): pid=16133 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/186/bus" dev="sda1" ino=14595 res=1
audit: type=1804 audit(1617561088.499:269): pid=16143 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/186/bus" dev="sda1" ino=14595 res=1
device wlan1 entered promiscuous mode
ubi0: attaching mtd0
audit: type=1804 audit(1617561088.609:270): pid=16155 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/187/bus" dev="sda1" ino=14585 res=1
ubi0: scanning is finished
ubi0: empty MTD device detected
vhci_hcd vhci_hcd.0: pdev(5) rhport(1) sockfd(4)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd: disconnect device
ubi0: attached mtd0 (name "mtdram test device", size 0 MiB)
ubi0: PEB size: 4096 bytes (4 KiB), LEB size: 3968 bytes
ubi0: min./max. I/O unit sizes: 1/64, sub-page size 1
ieee802154 phy0 wpan0: encryption failed: -22
ieee802154 phy1 wpan1: encryption failed: -22
ubi0: VID header offset: 64 (aligned 64), data offset: 128
ubi0: good PEBs: 32, bad PEBs: 0, corrupted PEBs: 0
ubi0: user volume: 0, internal volumes: 1, max. volumes count: 23
ubi0: max/mean erase counter: 0/0, WL threshold: 4096, image sequence number: 2984873490
ubi0: available PEBs: 28, total reserved PEBs: 4, PEBs reserved for bad PEB handling: 0
affs: Unrecognized mount option "default_permissions" or missing value
affs: Error parsing options
ubi0: background thread "ubi_bgt0d" started, PID 16182
ubi0: detaching mtd0
ubi0: mtd0 is detached
ubi0: attaching mtd0
ubi0: scanning is finished
EXT4-fs (loop5): VFS: Can't find ext4 filesystem
ubi0 error: ubi_attach_mtd_dev: cannot spawn "ubi_bgt0d", error -4
affs: Unrecognized mount option "default_permissions" or missing value
affs: Error parsing options
netlink: 'syz-executor.3': attribute type 10 has an invalid length.
IPVS: ftp: loaded support on port[0] = 21
bond0: team0 is up - this may be due to an out of date ifenslave
overlayfs: upperdir is in-use as upperdir/workdir of another mount, mount with '-o index=off' to override exclusive upperdir protection.
nla_parse: 1 callbacks suppressed
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.5'.
IPVS: ftp: loaded support on port[0] = 21
squashfs: SQUASHFS error: Can't find a SQUASHFS superblock on loop5
9pnet: p9_fd_create_tcp (16437): problem connecting socket to 127.0.0.1
overlayfs: upperdir is in-use as upperdir/workdir of another mount, mount with '-o index=off' to override exclusive upperdir protection.
9pnet: p9_fd_create_tcp (16449): problem connecting socket to 127.0.0.1
Bluetooth: hci5: command 0x0406 tx timeout
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
EXT4-fs (loop5): VFS: Can't find ext4 filesystem
IPVS: ftp: loaded support on port[0] = 21
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
kauditd_printk_skb: 9 callbacks suppressed
audit: type=1804 audit(1617561091.870:280): pid=16479 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/194/bus" dev="sda1" ino=13947 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.2'.
9pnet: p9_fd_create_tcp (16508): problem connecting socket to 127.0.0.1
audit: type=1804 audit(1617561091.950:281): pid=16495 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/194/bus" dev="sda1" ino=13947 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1800 audit(1617561092.140:282): pid=16517 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.1" name="bus" dev="sda1" ino=14242 res=0
new mount options do not match the existing superblock, will be ignored
audit: type=1804 audit(1617561092.160:283): pid=16524 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/195/bus" dev="sda1" ino=14354 res=1
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1804 audit(1617561092.240:284): pid=16532 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/195/bus" dev="sda1" ino=14354 res=1
new mount options do not match the existing superblock, will be ignored
audit: type=1804 audit(1617561092.410:285): pid=16527 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.5" name="/root/syzkaller-testdir383681739/syzkaller.NdE7oW/124/bus" dev="sda1" ino=14369 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1804 audit(1617561092.550:286): pid=16560 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/196/bus" dev="sda1" ino=14002 res=1
audit: type=1804 audit(1617561092.610:287): pid=16570 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir866096835/syzkaller.dINJOr/196/bus" dev="sda1" ino=14002 res=1
IPVS: ftp: loaded support on port[0] = 21
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1804 audit(1617561092.750:288): pid=16563 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.5" name="/root/syzkaller-testdir383681739/syzkaller.NdE7oW/125/bus" dev="sda1" ino=13993 res=1
audit: type=1800 audit(1617561092.950:289): pid=16606 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.1" name="bus" dev="sda1" ino=14242 res=0
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
vhci_hcd: vhci_device speed not set
IPVS: ftp: loaded support on port[0] = 21
overlayfs: missing 'lowerdir'
orangefs_mount: mount request failed with -4
mac80211_hwsim: wmediumd released netlink socket, switching to perfect channel medium
IPVS: ftp: loaded support on port[0] = 21
mac80211_hwsim: wmediumd released netlink socket, switching to perfect channel medium
---
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
Dec 2, 2021, 3:13:18 PM12/2/21
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages