Closed matttbe closed 4 years ago
Probably since commit 4769ab7324160:
During mptcp_join.sh selftest with KASAN
01:02:14.328 # 18 single subflow IPv6 syn[ ok ] - synack[ ok ] - ack[ ok ] 01:02:14.328 [ 320.472291] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth1: link becomes ready 01:02:14.328 [ 320.989680] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready 01:02:14.328 [ 321.174046] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth1: link becomes ready 01:02:14.328 [ 321.491711] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth3: link becomes ready 01:02:14.328 [ 321.972137] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth4: link becomes ready 01:02:14.328 [ 322.181944] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth3: link becomes ready 01:02:14.328 [ 323.242101] 01:02:14.328 [ 323.242402] ============================= 01:02:14.328 [ 323.243163] WARNING: suspicious RCU usage 01:02:14.329 [ 323.243810] 5.9.0+ #52 Not tainted 01:02:14.329 [ 323.244480] ----------------------------- 01:02:14.329 [ 323.245043] include/net/sock.h:1915 suspicious rcu_dereference_check() usage! 01:02:14.329 [ 323.245979] 01:02:14.329 [ 323.245979] other info that might help us debug this: 01:02:14.329 [ 323.245979] 01:02:14.329 [ 323.247195] 01:02:14.329 [ 323.247195] rcu_scheduler_active = 2, debug_locks = 1 01:02:14.329 [ 323.248116] 3 locks held by kworker/0:3/1400: 01:02:14.624 [ 323.248689] #0: ffff888023858d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work (./include/linux/instrumented.h:86) 01:02:14.626 [ 323.249936] #1: ffff88801e117dc8 ((work_completion)(&msk->work)){+.+.}-{0:0}, at: process_one_work (./include/linux/instrumented.h:86) 01:02:14.899 [ 323.251275] #2: ffff88802072a120 (sk_lock-AF_INET6){+.+.}-{0:0}, at: mptcp_worker (./include/linux/instrumented.h:86) 01:02:14.899 [ 323.252493] 01:02:14.899 [ 323.252493] stack backtrace: 01:02:14.899 [ 323.253327] CPU: 0 PID: 1400 Comm: kworker/0:3 Not tainted 5.9.0+ #52 01:02:14.899 [ 323.254156] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.13.0-1ubuntu1 04/01/2014 01:02:14.899 [ 323.255324] Workqueue: events mptcp_worker 01:02:14.899 [ 323.255904] Call Trace: 01:02:15.169 [ 323.256371] dump_stack (lib/dump_stack.c:120) 01:02:15.424 [ 323.256823] __sk_dst_check (./include/net/sock.h:1915) 01:02:15.690 [ 323.257334] inet6_csk_route_socket (net/ipv6/inet6_connection_sock.c:76) 01:02:15.960 [ 323.257909] ? inet6_csk_route_req (net/ipv6/inet6_connection_sock.c:81) 01:02:16.227 [ 323.258476] ? kasan_unpoison_shadow (./include/linux/kasan.h:34) 01:02:16.468 [ 323.259061] ? __kmalloc_node_track_caller (mm/slab.h:530) 01:02:16.739 [ 323.259756] ? mptcp_pm_create_subflow_or_signal_addr (net/mptcp/pm_netlink.c:314) 01:02:16.909 [ 323.260565] ? mptcp_worker (net/mptcp/protocol.c:1795) 01:02:17.177 [ 323.261107] ? inet6_csk_xmit (net/ipv6/inet6_connection_sock.c:121) 01:02:17.179 [ 323.261625] inet6_csk_xmit (net/ipv6/inet6_connection_sock.c:121) 01:02:17.451 [ 323.262184] ? mptcp_space (net/mptcp/subflow.c:977) 01:02:17.719 [ 323.262713] ? inet6_csk_update_pmtu (net/ipv6/inet6_connection_sock.c:115) 01:02:17.993 [ 323.263494] ? print_usage_bug (kernel/locking/lockdep.c:4369) 01:02:18.248 [ 323.264061] __tcp_transmit_skb (net/ipv4/tcp_output.c:1404 (discriminator 1)) 01:02:18.501 [ 323.264716] ? __tcp_select_window (net/ipv4/tcp_output.c:1241) 01:02:18.669 [ 323.265285] ? __kmalloc_node_track_caller (./include/trace/events/kmem.h:100) 01:02:18.938 [ 323.266064] ? mark_held_locks (kernel/locking/lockdep.c:4011) 01:02:19.210 [ 323.266651] mptcp_pm_check_send_dedicated_add_addr_packet.part.0 (./include/linux/spinlock.h:359) 01:02:19.212 [ 323.267520] mptcp_pm_create_subflow_or_signal_addr (net/mptcp/pm_netlink.c:314) 01:02:19.483 [ 323.268322] ? mptcp_nl_cmd_get_addr (net/mptcp/pm_netlink.c:335) 01:02:19.757 [ 323.268936] ? rwlock_bug.part.0 (kernel/locking/spinlock_debug.c:111) 01:02:19.758 [ 323.269562] mptcp_worker (net/mptcp/protocol.c:1795) 01:02:20.031 [ 323.270080] ? mptcp_sendmsg (net/mptcp/protocol.c:1839) 01:02:20.305 [ 323.270655] ? rcu_read_lock_bh_held (kernel/rcu/update.c:131) 01:02:20.576 [ 323.271326] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:435) 01:02:20.749 [ 323.272140] process_one_work (./arch/x86/include/asm/jump_label.h:25) 01:02:21.025 [ 323.272797] ? pwq_dec_nr_in_flight (kernel/workqueue.c:2165) 01:02:21.027 [ 323.273536] ? rwlock_bug.part.0 (kernel/locking/spinlock_debug.c:111) 01:02:21.283 [ 323.274188] ? _raw_spin_lock_irq (./include/linux/spinlock_api_smp.h:126) 01:02:21.563 [ 323.274847] worker_thread (./include/linux/list.h:282) 01:02:21.837 [ 323.275373] ? preempt_count_sub (kernel/sched/core.c:4207) 01:02:22.004 [ 323.276004] ? process_one_work (kernel/workqueue.c:2358) 01:02:22.272 [ 323.276530] kthread (kernel/kthread.c:292) 01:02:22.538 [ 323.277002] ? kthread_create_on_node (kernel/kthread.c:245) 01:02:22.812 [ 323.277610] ret_from_fork (arch/x86/entry/entry_64.S:302) 01:02:22.812 # 19 unused signal address IPv6 syn[ ok ] - synack[ ok ] - ack[ ok ] 01:02:22.812 # add[ ok ] - echo [ ok ] 01:02:22.812 [ 330.516881] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth1: link becomes ready 01:02:22.812 [ 330.967586] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready 01:02:22.812 [ 331.277924] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth1: link becomes ready
KConfig:
-e KASAN -e KASAN_OUTLINE -d TEST_KASAN -e PROVE_LOCKING -e DEBUG_LOCKDEP -e PREEMPT -e DEBUG_PREEMPT -e DEBUG_SLAVE -e DEBUG_PAGEALLOC -e DEBUG_MUTEXES -e DEBUG_SPINLOCK -e DEBUG_ATOMIC_SLEEP -e PROVE_RCU -e DEBUG_OBJECTS_RCU_HEAD
cc: @geliangtang
@matttbe I'll try to fix it.
Should be closed with commit 4b03a9d34ff3c178a4f725a63bee0706454afdc4.
Probably since commit 4769ab7324160:
During mptcp_join.sh selftest with KASAN
KConfig:
cc: @geliangtang