Re: suspicious RCU usage at ./include/net/inet_sock.h:LINE

[Eric Biggers]

On Mon, Dec 25, 2017 at 05:45:00PM -0800, syzbot wrote:
> syzkaller has found reproducer for the following crash on
> fba961ab29e5ffb055592442808bb0f7962e05da
> git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git/master
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached
> Raw console output is attached.
> C reproducer is attached
> syzkaller reproducer is attached. See https://goo.gl/kgGztJ
> for information about syzkaller reproducers
> 
> 
> Can not set IPV6_FL_F_REFLECT if flowlabel_consistency sysctl is enable
> 
> =============================
> WARNING: suspicious RCU usage
> 4.15.0-rc4+ #164 Not tainted
> -----------------------------
> ./include/net/inet_sock.h:136 suspicious rcu_dereference_check() usage!
> 
> other info that might help us debug this:
> 
> 
> rcu_scheduler_active = 2, debug_locks = 1
> 1 lock held by syzkaller667189/5780:
>  #0:  (sk_lock-AF_INET6){+.+.}, at: [<000000008d7d4e62>] lock_sock
> include/net/sock.h:1462 [inline]
>  #0:  (sk_lock-AF_INET6){+.+.}, at: [<000000008d7d4e62>]
> do_ipv6_setsockopt.isra.9+0x23d/0x38f0 net/ipv6/ipv6_sockglue.c:167
> 
> stack backtrace:
> CPU: 0 PID: 5780 Comm: syzkaller667189 Not tainted 4.15.0-rc4+ #164
> 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+0x194/0x257 lib/dump_stack.c:53
>  lockdep_rcu_suspicious+0x123/0x170 kernel/locking/lockdep.c:4585
>  ireq_opt_deref include/net/inet_sock.h:135 [inline]
>  inet_csk_route_req+0x824/0xca0 net/ipv4/inet_connection_sock.c:544
>  dccp_v4_send_response+0xa7/0x640 net/dccp/ipv4.c:485
>  dccp_v4_conn_request+0x9ee/0x11b0 net/dccp/ipv4.c:633
>  dccp_v6_conn_request+0xd30/0x1350 net/dccp/ipv6.c:317
>  dccp_rcv_state_process+0x574/0x1620 net/dccp/input.c:612
>  dccp_v4_do_rcv+0xeb/0x160 net/dccp/ipv4.c:682
>  dccp_v6_do_rcv+0x81a/0x9b0 net/dccp/ipv6.c:578
>  sk_backlog_rcv include/net/sock.h:907 [inline]
>  __release_sock+0x124/0x360 net/core/sock.c:2274
>  release_sock+0xa4/0x2a0 net/core/sock.c:2789
>  do_ipv6_setsockopt.isra.9+0x50f/0x38f0 net/ipv6/ipv6_sockglue.c:898
>  ipv6_setsockopt+0xd7/0x150 net/ipv6/ipv6_sockglue.c:922
>  dccp_setsockopt+0x85/0xd0 net/dccp/proto.c:573
>  sock_common_setsockopt+0x95/0xd0 net/core/sock.c:2978
>  SYSC_setsockopt net/socket.c:1821 [inline]
>  SyS_setsockopt+0x189/0x360 net/socket.c:1800
>  entry_SYSCALL_64_fastpath+0x1f/0x96
> RIP: 0033:0x445ec9
> RSP: 002b:00007fa001b58db8 EFLAGS: 00000297 ORIG_RAX: 0000000000000036
> RAX: ffffffffffffffda RBX: 00000000006dbc24 RCX: 0000000000445ec9
> RDX: 0000000000000020 RSI: 0000000000000029 RDI: 0000000000000004
> RBP: 00000000006dbc20 R08: 0000000000000020 R09: 0000000000000000
> R10: 000000002030a000 R11: 0000000000000297 R12: 0000000000000000
> R13: 00007fff809eec1f R14: 00007fa001b599c0 R15: 0000000000000001
> 
> =============================
> WARNING: suspicious RCU usage
> 4.15.0-rc4+ #164 Not tainted
> -----------------------------
> ./include/net/inet_sock.h:136 suspicious rcu_dereference_check() usage!
> 
> other info that might help us debug this:
> 
> 
> rcu_scheduler_active = 2, debug_locks = 1
> 1 lock held by syzkaller667189/5780:
>  #0:  (sk_lock-AF_INET6){+.+.}, at: [<000000008d7d4e62>] lock_sock
> include/net/sock.h:1462 [inline]
>  #0:  (sk_lock-AF_INET6){+.+.}, at: [<000000008d7d4e62>]
> do_ipv6_setsockopt.isra.9+0x23d/0x38f0 net/ipv6/ipv6_sockglue.c:167
> 
> stack backtrace:
> CPU: 0 PID: 5780 Comm: syzkaller667189 Not tainted 4.15.0-rc4+ #164
> 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+0x194/0x257 lib/dump_stack.c:53
>  lockdep_rcu_suspicious+0x123/0x170 kernel/locking/lockdep.c:4585
>  ireq_opt_deref include/net/inet_sock.h:135 [inline]
>  dccp_v4_send_response+0x4b0/0x640 net/dccp/ipv4.c:496
>  dccp_v4_conn_request+0x9ee/0x11b0 net/dccp/ipv4.c:633
>  dccp_v6_conn_request+0xd30/0x1350 net/dccp/ipv6.c:317
>  dccp_rcv_state_process+0x574/0x1620 net/dccp/input.c:612
>  dccp_v4_do_rcv+0xeb/0x160 net/dccp/ipv4.c:682
>  dccp_v6_do_rcv+0x81a/0x9b0 net/dccp/ipv6.c:578
>  sk_backlog_rcv include/net/sock.h:907 [inline]
>  __release_sock+0x124/0x360 net/core/sock.c:2274
>  release_sock+0xa4/0x2a0 net/core/sock.c:2789
>  do_ipv6_setsockopt.isra.9+0x50f/0x38f0 net/ipv6/ipv6_sockglue.c:898
>  ipv6_setsockopt+0xd7/0x150 net/ipv6/ipv6_sockglue.c:922
>  dccp_setsockopt+0x85/0xd0 net/dccp/proto.c:573
>  sock_common_setsockopt+0x95/0xd0 net/core/sock.c:2978
>  SYSC_setsockopt net/socket.c:1821 [inline]
>  SyS_setsockopt+0x189/0x360 net/socket.c:1800
>  entry_SYSCALL_64_fastpath+0x1f/0x96
> RIP: 0033:0x445ec9
> RSP: 002b:00007fa001b58db8 EFLAGS: 00000297 ORIG_RAX: 0000000000000036
> RAX: ffffffffffffffda RBX: 00000000006dbc24 RCX: 0000000000445ec9
> RDX: 0000000000000020 RSI: 0000000000000029 RDI: 0000000000000004
> RBP: 00000000006dbc20 R08: 0000000000000020 R09: 0000000000000000
> R10: 000000002030a000 R11: 0000000000000297 R12: 0000000000000000
> R13: 00007fff809eec1f R14: 00007fa001b599c0 R15: 0000000000000001

syzbot stopped hitting this for some reason, but the bug is still there.
Here's a simplified reproducer that works on Linus' tree as of today:

#include <linux/in.h>
#include <stdlib.h>
#include <sys/socket.h>
#include <unistd.h>

int main()
{
        int is_parent = (fork() != 0);
        for (;;) {
                int fd = socket(AF_INET, SOCK_DCCP, 0);
                struct sockaddr_in addr = {
                        .sin_family = AF_INET,
                        .sin_port = htobe16(0x4e23),
                };
                if (is_parent) {
                        connect(fd, (void *)&addr, sizeof(addr));
                } else {
                        bind(fd, (void *)&addr, sizeof(addr));
                        listen(fd, 100);
                        setsockopt(fd, 0, 0xFFFF, NULL, 0);
                }
                close(fd);
        }
}