[syzkaller] Warning in icsk_get_port

[mjmartineau]

Syzkaller is frequently hitting a warning in icsk_get_port()

This has already been reported by syzbot (sometimes with mptcp_listen() in the stack trace, but also using other callers), so it appears to be a broader issue, and continues to be encountered by syzbot on net-next. More context:

https://lore.kernel.org/netdev/0000000000003f33bc05dfaf44fe@google.com/
https://syzkaller.appspot.com/bug?extid=015d756bbd1f8b5c8f09

Tracking the issue here so we can confirm the fix when it's posted.

------------[ cut here ]------------
WARNING: CPU: 1 PID: 5604 at net/ipv4/inet_connection_sock.c:525 inet_csk_get_port+0x938/0xe80 net/ipv4/inet_connection_sock.c:525
Modules linked in:
CPU: 1 PID: 5604 Comm: syz-executor.1 Not tainted 5.18.0-04967-g9612da020913 #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
RIP: 0010:inet_csk_get_port+0x938/0xe80 net/ipv4/inet_connection_sock.c:525
Code: ff 48 89 84 24 b0 00 00 00 48 85 c0 0f 84 6a 01 00 00 e8 3b 16 db fd 48 8b 6c 24 70 c6 04 24 01 e9 fb fb ff ff e8 28 16 db fd <0f> 0b e9 70 f9 ff ff e8 1c 16 db fd 0f 0b e9 28 f9 ff ff e8 10 16
RSP: 0018:ffffc9000e1ffbc0 EFLAGS: 00010212
RAX: 000000000000027d RBX: ffff888119613d80 RCX: ffffc900013da000
RDX: 0000000000040000 RSI: ffffffff836f40d8 RDI: ffff888119614420
RBP: ffff8881020ff440 R08: 0000000000000001 R09: 0000000000000001
R10: fffffbfff0f64303 R11: 0000000000000001 R12: 0000000000000000
R13: ffff8881060b53b0 R14: ffffffff88606040 R15: 0000000000000000
FS:  00007f6fa6a4d640(0000) GS:ffff88811ad00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2d224000 CR3: 00000001088d2005 CR4: 0000000000770ee0
PKRU: 55555554
Call Trace:
 <TASK>
 inet_csk_listen_start+0x143/0x3d0 net/ipv4/inet_connection_sock.c:1178
 inet_listen+0x22f/0x650 net/ipv4/af_inet.c:228
 mptcp_listen+0x205/0x440 net/mptcp/protocol.c:3564
 __sys_listen+0x189/0x260 net/socket.c:1810
 __do_sys_listen net/socket.c:1819 [inline]
 __se_sys_listen net/socket.c:1817 [inline]
 __x64_sys_listen+0x54/0x80 net/socket.c:1817
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x38/0x90 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f6fa72d98ed
Code: 02 b8 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa 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 b0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f6fa6a4d028 EFLAGS: 00000246 ORIG_RAX: 0000000000000032
RAX: ffffffffffffffda RBX: 00007f6fa73f9f60 RCX: 00007f6fa72d98ed
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 00007f6fa734a0a0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007f6fa73f9f60 R15: 00007f6fa6a2d000
 </TASK>
irq event stamp: 2568
hardirqs last  enabled at (2574): [<ffffffff812f5404>] console_trylock_spinning+0x2f4/0x330 kernel/printk/printk.c:2034
hardirqs last disabled at (2579): [<ffffffff812f53e6>] console_trylock_spinning+0x2d6/0x330 kernel/printk/printk.c:2013
softirqs last  enabled at (2074): [<ffffffff838076c4>] lock_sock include/net/sock.h:1691 [inline]
softirqs last  enabled at (2074): [<ffffffff838076c4>] inet_listen+0x94/0x650 net/ipv4/af_inet.c:199
softirqs last disabled at (2076): [<ffffffff836f3b4c>] spin_lock_bh include/linux/spinlock.h:354 [inline]
softirqs last disabled at (2076): [<ffffffff836f3b4c>] inet_csk_get_port+0x3ac/0xe80 net/ipv4/inet_connection_sock.c:483
---[ end trace 0000000000000000 ]---

In 6 days, it has been encountered over 300 times.

Code is tag export/20220524T075839 merged with net-next from 2022-05-25 (commit 7e062cd).

inet_connection_sock.c:525 is this:

WARN_ON(inet_csk(sk)->icsk_bind2_hash != tb2);

which was introduced by https://lore.kernel.org/netdev/20220520001834.2247810-1-kuba@kernel.org/ (d5a42de)

config-bhash2.gz
log-bhash2.gz

[mjmartineau]

Apparently there's an invisible fix:

https://lore.kernel.org/netdev/CANn89i+pg8guF+XeOngSMa4vUD81g=u-pCBpi0Yp2WB9PQZvdg@mail.gmail.com/

(I saw some other mailing list context that something mysterious is going on with vger/patchwork not seeing messages from this sender).

[mjmartineau]

I've started syzkaller with this proposed fix applied:

https://patchwork.kernel.org/project/netdevbpf/list/?series=646663

[mjmartineau]

Still reproduced the warning with the v1 fix. It only happened once over two days. Attaching logs:

syzkaller-log-mptcp.gz
syzkaller-report-mptcp.gz

Kernel code is a merge of the export/2F20220526T055531 tag from this repo and net/master from Tuesday (2022-05-31) 09e545f, with the v1 series from Joanna applied.

[mjmartineau]

Another warning after another week;

report-warn-2.gz
log-warn-2.gz

This time, the warning was triggered on a regular TCP socket.

[mjmartineau]

Patches causing this upstream have been reverted