possible deadlock in match_revfn

8 views
Skip to first unread message

syzbot

unread,
Mar 17, 2021, 4:44:18 PM3/17/21
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: cb83ddcd Linux 4.14.226
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=11d3ff76d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=124f4e6b89b71fac
dashboard link: https://syzkaller.appspot.com/bug?extid=ccc814e152212af64c66

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+ccc814...@syzkaller.appspotmail.com

======================================================
WARNING: possible circular locking dependency detected
4.14.226-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/27092 is trying to acquire lock:
(&xt[i].mutex){+.+.}, at: [<ffffffff85ef57f3>] match_revfn+0x43/0x210 net/netfilter/x_tables.c:332

but task is already holding lock:
(&table[i].mutex){+.+.}, at: [<ffffffff85e219e6>] nfnl_lock net/netfilter/nfnetlink.c:61 [inline]
(&table[i].mutex){+.+.}, at: [<ffffffff85e219e6>] nfnetlink_rcv_msg+0x726/0xc00 net/netfilter/nfnetlink.c:209

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&table[i].mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
nf_tables_netdev_event+0x10d/0x4d0 net/netfilter/nf_tables_netdev.c:122
notifier_call_chain+0x108/0x1a0 kernel/notifier.c:93
call_netdevice_notifiers_info net/core/dev.c:1667 [inline]
call_netdevice_notifiers net/core/dev.c:1683 [inline]
rollback_registered_many+0x765/0xba0 net/core/dev.c:7203
rollback_registered+0xca/0x170 net/core/dev.c:7245
unregister_netdevice_queue+0x1b4/0x360 net/core/dev.c:8266
unregister_netdevice include/linux/netdevice.h:2443 [inline]
__tun_detach+0xca2/0xf60 drivers/net/tun.c:576
tun_detach drivers/net/tun.c:586 [inline]
tun_chr_close+0x41/0x60 drivers/net/tun.c:2679
__fput+0x25f/0x7a0 fs/file_table.c:210
task_work_run+0x11f/0x190 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xa44/0x2850 kernel/exit.c:868
do_group_exit+0x100/0x2e0 kernel/exit.c:965
SYSC_exit_group kernel/exit.c:976 [inline]
SyS_exit_group+0x19/0x20 kernel/exit.c:974
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #1 (rtnl_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
unregister_netdevice_notifier+0x5e/0x2b0 net/core/dev.c:1630
tee_tg_destroy+0x5c/0xb0 net/netfilter/xt_TEE.c:123
cleanup_entry+0x232/0x310 net/ipv6/netfilter/ip6_tables.c:684
__do_replace+0x38d/0x580 net/ipv6/netfilter/ip6_tables.c:1105
do_replace net/ipv6/netfilter/ip6_tables.c:1161 [inline]
do_ip6t_set_ctl+0x256/0x3b0 net/ipv6/netfilter/ip6_tables.c:1685
nf_sockopt net/netfilter/nf_sockopt.c:106 [inline]
nf_setsockopt+0x5f/0xb0 net/netfilter/nf_sockopt.c:115
ipv6_setsockopt+0xc0/0x120 net/ipv6/ipv6_sockglue.c:937
tcp_setsockopt+0x7b/0xc0 net/ipv4/tcp.c:2828
SYSC_setsockopt net/socket.c:1865 [inline]
SyS_setsockopt+0x110/0x1e0 net/socket.c:1844
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #0 (&xt[i].mutex){+.+.}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
match_revfn+0x43/0x210 net/netfilter/x_tables.c:332
xt_find_revision+0x8d/0x1d0 net/netfilter/x_tables.c:380
nfnl_compat_get+0x1f7/0x870 net/netfilter/nft_compat.c:678
nfnetlink_rcv_msg+0x9bb/0xc00 net/netfilter/nfnetlink.c:214
netlink_rcv_skb+0x125/0x390 net/netlink/af_netlink.c:2433
nfnetlink_rcv+0x1ab/0x1da0 net/netfilter/nfnetlink.c:515
netlink_unicast_kernel net/netlink/af_netlink.c:1287 [inline]
netlink_unicast+0x437/0x610 net/netlink/af_netlink.c:1313
netlink_sendmsg+0x62e/0xb80 net/netlink/af_netlink.c:1878
sock_sendmsg_nosec net/socket.c:646 [inline]
sock_sendmsg+0xb5/0x100 net/socket.c:656
___sys_sendmsg+0x6c8/0x800 net/socket.c:2062
__sys_sendmsg+0xa3/0x120 net/socket.c:2096
SYSC_sendmsg net/socket.c:2107 [inline]
SyS_sendmsg+0x27/0x40 net/socket.c:2103
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb

other info that might help us debug this:

Chain exists of:
&xt[i].mutex --> rtnl_mutex --> &table[i].mutex

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&table[i].mutex);
lock(rtnl_mutex);
lock(&table[i].mutex);
lock(&xt[i].mutex);

*** DEADLOCK ***

1 lock held by syz-executor.3/27092:
#0: (&table[i].mutex){+.+.}, at: [<ffffffff85e219e6>] nfnl_lock net/netfilter/nfnetlink.c:61 [inline]
#0: (&table[i].mutex){+.+.}, at: [<ffffffff85e219e6>] nfnetlink_rcv_msg+0x726/0xc00 net/netfilter/nfnetlink.c:209

stack backtrace:
CPU: 1 PID: 27092 Comm: syz-executor.3 Not tainted 4.14.226-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+0x1b2/0x281 lib/dump_stack.c:58
print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1258
check_prev_add kernel/locking/lockdep.c:1905 [inline]
check_prevs_add kernel/locking/lockdep.c:2022 [inline]
validate_chain kernel/locking/lockdep.c:2464 [inline]
__lock_acquire+0x2e0e/0x3f20 kernel/locking/lockdep.c:3491
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
match_revfn+0x43/0x210 net/netfilter/x_tables.c:332
xt_find_revision+0x8d/0x1d0 net/netfilter/x_tables.c:380
nfnl_compat_get+0x1f7/0x870 net/netfilter/nft_compat.c:678
nfnetlink_rcv_msg+0x9bb/0xc00 net/netfilter/nfnetlink.c:214
netlink_rcv_skb+0x125/0x390 net/netlink/af_netlink.c:2433
nfnetlink_rcv+0x1ab/0x1da0 net/netfilter/nfnetlink.c:515
netlink_unicast_kernel net/netlink/af_netlink.c:1287 [inline]
netlink_unicast+0x437/0x610 net/netlink/af_netlink.c:1313
netlink_sendmsg+0x62e/0xb80 net/netlink/af_netlink.c:1878
sock_sendmsg_nosec net/socket.c:646 [inline]
sock_sendmsg+0xb5/0x100 net/socket.c:656
___sys_sendmsg+0x6c8/0x800 net/socket.c:2062
__sys_sendmsg+0xa3/0x120 net/socket.c:2096
SYSC_sendmsg net/socket.c:2107 [inline]
SyS_sendmsg+0x27/0x40 net/socket.c:2103
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x465f69
RSP: 002b:00007fe43f287188 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465f69
RDX: 000000000000c854 RSI: 0000000020000580 RDI: 0000000000000003
RBP: 00000000004bfa8f R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60
R13: 00007ffcc0c08a0f R14: 00007fe43f287300 R15: 0000000000022000
audit: type=1804 audit(1616013786.038:58): pid=27200 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir756994254/syzkaller.Q06Ucx/1664/file0" dev="sda1" ino=15209 res=1
netlink: 1744 bytes leftover after parsing attributes in process `syz-executor.1'.
netlink: 1744 bytes leftover after parsing attributes in process `syz-executor.1'.
audit: type=1804 audit(1616013786.108:59): pid=27219 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir756994254/syzkaller.Q06Ucx/1664/file0" dev="sda1" ino=15209 res=1
audit: type=1804 audit(1616013787.168:60): pid=27538 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir297965247/syzkaller.yLGGje/2406/bus" dev="sda1" ino=15246 res=1
audit: type=1804 audit(1616013787.198:61): pid=27538 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir297965247/syzkaller.yLGGje/2406/bus" dev="sda1" ino=15246 res=1
audit: type=1804 audit(1616013787.448:62): pid=27554 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir297965247/syzkaller.yLGGje/2406/bus" dev="sda1" ino=15246 res=1
ucma_write: process 4078 (syz-executor.4) changed security contexts after opening file descriptor, this is not allowed.
print_req_error: I/O error, dev loop4, sector 2
Buffer I/O error on dev loop4, logical block 2, async page read
print_req_error: I/O error, dev loop4, sector 3
Buffer I/O error on dev loop4, logical block 3, async page read
print_req_error: I/O error, dev loop4, sector 4
Buffer I/O error on dev loop4, logical block 4, async page read
print_req_error: I/O error, dev loop4, sector 5
Buffer I/O error on dev loop4, logical block 5, async page read
print_req_error: I/O error, dev loop4, sector 6
Buffer I/O error on dev loop4, logical block 6, async page read
print_req_error: I/O error, dev loop4, sector 7
Buffer I/O error on dev loop4, logical block 7, async page read
audit: type=1804 audit(1616013790.498:63): pid=28389 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2353/bus" dev="sda1" ino=15291 res=1
audit: type=1804 audit(1616013790.518:64): pid=28389 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2353/bus" dev="sda1" ino=15291 res=1
audit: type=1804 audit(1616013791.358:65): pid=28454 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2354/bus" dev="sda1" ino=14145 res=1
audit: type=1804 audit(1616013791.388:66): pid=28454 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2354/bus" dev="sda1" ino=14145 res=1
audit: type=1804 audit(1616013791.868:67): pid=28544 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2355/bus" dev="sda1" ino=14098 res=1
audit: type=1804 audit(1616013791.868:68): pid=28544 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2355/bus" dev="sda1" ino=14098 res=1
audit: type=1804 audit(1616013792.318:69): pid=28621 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2356/bus" dev="sda1" ino=14274 res=1
audit: type=1804 audit(1616013792.338:70): pid=28621 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2356/bus" dev="sda1" ino=14274 res=1
audit: type=1804 audit(1616013792.768:71): pid=28680 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2357/bus" dev="sda1" ino=14050 res=1
audit: type=1804 audit(1616013792.768:72): pid=28680 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir298860256/syzkaller.DO7li3/2357/bus" dev="sda1" ino=14050 res=1


---
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

unread,
Oct 30, 2021, 5:02:19 PM10/30/21
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages