i386: selftests: net: bareudp.sh: Warning DEADLOCK lock(&(&stat->syncp)->seq#15);

From: Naresh Kamboju
Date: Mon May 09 2022 - 04:21:24 EST


Following kernel warning noticed while running selftests: net: bareudp.sh on
i386 running Linux 5.18.0-rc6 logs [1] and [2].

Reported-by: Linux Kernel Functional Testing <lkft@xxxxxxxxxx>

# selftests: net: bareudp.sh
[ 635.997890] device eth1 left promiscuous mode
[ 636.002374] br0: port 2(eth1) entered disabled state
[ 636.011078] device eth0 left promiscuous mode
[ 636.015527] br0: port 1(eth0) entered disabled state
[ 636.235841] device eth1 left promiscuous mode
[ 636.240316] br0: port 2(eth1) entered disabled state
[ 636.254328] device eth0 left promiscuous mode
[ 636.258799] br0: port 1(eth0) entered disabled state
[ 636.389226] IPv6: ADDRCONF(NETDEV_CHANGE): veth01: link becomes ready
[ 636.469276] IPv6: ADDRCONF(NETDEV_CHANGE): veth12: link becomes ready
[ 636.531585] IPv6: ADDRCONF(NETDEV_CHANGE): veth23: link becomes ready
[ 636.982172] mpls_gso: MPLS GSO support
[ 637.184288]
[ 637.185806] ================================
[ 637.190078] WARNING: inconsistent lock state
[ 637.194352] 5.18.0-rc6 #1 Not tainted
[ 637.198024] --------------------------------
[ 637.202296] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
[ 637.208326] tc/17481 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 637.213198] fefaf3a4 (&(&stat->syncp)->seq#15){+.?.}-{0:0}, at:
tcf_stats_update+0x52/0x80 [act_mirred]
[ 637.222601] {IN-SOFTIRQ-W} state was registered at:
[ 637.227473] lock_acquire+0xbd/0x2e0
[ 637.231136] tcf_mirred_act+0xf1/0x750 [act_mirred]
[ 637.236095] tcf_action_exec+0x7e/0x200
[ 637.240019] mall_classify+0x6c/0xe0 [cls_matchall]
[ 637.244978] __tcf_classify.constprop.0+0x52/0x150
[ 637.249850] tcf_classify+0x3c/0x60
[ 637.253427] __netif_receive_skb_core.constprop.0+0x6af/0x1170
[ 637.259338] __netif_receive_skb_one_core+0x34/0xa0
[ 637.264295] __netif_receive_skb+0x1d/0x70
[ 637.268472] process_backlog+0x77/0x240
[ 637.272390] __napi_poll.constprop.0+0x31/0x150
[ 637.277001] net_rx_action+0x11a/0x290
[ 637.280839] __do_softirq+0x14f/0x4ae
[ 637.284583] call_on_stack+0x4c/0x60
[ 637.288242] do_softirq_own_stack+0x2f/0x40
[ 637.292506] do_softirq+0xa5/0xd0
[ 637.295932] __local_bh_enable_ip+0xdb/0x100
[ 637.300286] ip_finish_output2+0x239/0xbe0
[ 637.304464] __ip_finish_output+0x14b/0x2a0
[ 637.308728] ip_finish_output+0x2a/0xd0
[ 637.312646] ip_output+0xf6/0x320
[ 637.316041] ip_send_skb+0x1f1/0x230
[ 637.319700] ip_push_pending_frames+0x33/0x50
[ 637.324137] raw_sendmsg+0xb45/0x1240
[ 637.327892] inet_sendmsg+0x6c/0x80
[ 637.331469] sock_sendmsg+0x6d/0x90
[ 637.335047] __sys_sendto+0xda/0x130
[ 637.338705] __ia32_sys_socketcall+0x35c/0x3c0
[ 637.343230] __do_fast_syscall_32+0x77/0xd0
[ 637.347502] do_fast_syscall_32+0x32/0x70
[ 637.351591] do_SYSENTER_32+0x15/0x20
[ 637.355336] entry_SYSENTER_32+0x98/0xf1
[ 637.359339] irq event stamp: 11769
[ 637.362739] hardirqs last enabled at (11769): [<d2fd19df>]
call_rcu+0x26f/0x430
[ 637.370130] hardirqs last disabled at (11768): [<d2fd19f5>]
call_rcu+0x285/0x430
[ 637.377512] softirqs last enabled at (11764): [<d3ca1d96>]
tc_setup_action.part.0+0x196/0x320
[ 637.386110] softirqs last disabled at (11762): [<d3ca1c61>]
tc_setup_action.part.0+0x61/0x320
[ 637.394622]
[ 637.394622] other info that might help us debug this:
[ 637.401138] Possible unsafe locking scenario:
[ 637.401138]
[ 637.407047] CPU0
[ 637.409491] ----
[ 637.411935] lock(&(&stat->syncp)->seq#15);
[ 637.416199] <Interrupt>
[ 637.418816] lock(&(&stat->syncp)->seq#15);
[ 637.423256]
[ 637.423256] *** DEADLOCK ***
[ 637.423256]
[ 637.429164] 1 lock held by tc/17481:
[ 637.432735] #0: d498eb38 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock+0x14/0x20
[ 637.439693]
[ 637.439693] stack backtrace:
[ 637.444045] CPU: 1 PID: 17481 Comm: tc Not tainted 5.18.0-rc6 #1
[ 637.450041] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
2.0b 07/27/2017
[ 637.457512] Call Trace:
[ 637.459959] dump_stack_lvl+0x44/0x57
[ 637.463623] dump_stack+0xd/0x10
[ 637.466847] print_usage_bug.part.0+0x189/0x194
[ 637.471379] mark_lock.part.0.cold+0x4d/0x78
[ 637.475643] ? lock_release+0x1e1/0x2e0
[ 637.479475] __lock_acquire+0x321/0x2800
[ 637.483399] ? kernel_text_address+0xff/0x110
[ 637.487752] ? __kernel_text_address+0x10/0x40
[ 637.492195] ? __lock_acquire+0x33f/0x2800
[ 637.496285] ? __lock_acquire+0x33f/0x2800
[ 637.500380] ? __this_cpu_preempt_check+0xf/0x11
[ 637.504996] ? lock_is_held_type+0xb6/0x120
[ 637.509176] lock_acquire+0xbd/0x2e0
[ 637.512752] ? tcf_stats_update+0x52/0x80 [act_mirred]
[ 637.517895] ? __this_cpu_preempt_check+0xf/0x11
[ 637.522509] ? lock_is_held_type+0xb6/0x120
[ 637.526687] tcf_action_update_stats+0x87/0x320
[ 637.531214] ? tcf_stats_update+0x52/0x80 [act_mirred]
[ 637.536354] tcf_stats_update+0x52/0x80 [act_mirred]
[ 637.541319] ? tcf_mirred_get_fill_size+0x10/0x10 [act_mirred]
[ 637.547150] fl_hw_update_stats+0x15b/0x1c0 [cls_flower]
[ 637.552468] fl_dump+0x1d1/0x1f7 [cls_flower]
[ 637.556832] ? fl_tmplt_dump+0xb0/0xb0 [cls_flower]
[ 637.561709] tcf_fill_node+0x16a/0x220
[ 637.565452] ? fl_tmplt_dump+0xb0/0xb0 [cls_flower]
[ 637.570325] tfilter_notify+0x9e/0x110
[ 637.574078] tc_new_tfilter+0x50e/0xd60
[ 637.577936] ? tc_del_tfilter+0x930/0x930
[ 637.581946] rtnetlink_rcv_msg+0x409/0x520
[ 637.586045] ? rtnetlink_rcv_msg+0x69/0x520
[ 637.590232] ? __this_cpu_preempt_check+0xf/0x11
[ 637.594848] ? lock_release+0x12a/0x2e0
[ 637.598681] ? lock_is_held_type+0xb6/0x120
[ 637.602894] ? netlink_deliver_tap+0x130/0x490
[ 637.607355] ? rtnl_fdb_dump+0x420/0x420
[ 637.611273] netlink_rcv_skb+0x78/0xe0
[ 637.615017] ? netlink_deliver_tap+0x5/0x490
[ 637.619290] rtnetlink_rcv+0x12/0x20
[ 637.622874] netlink_unicast+0x185/0x290
[ 637.626796] netlink_sendmsg+0x21f/0x4b0
[ 637.630723] ? netlink_unicast+0x290/0x290
[ 637.634818] sock_sendmsg+0x75/0x90
[ 637.638304] ____sys_sendmsg+0x1ea/0x240
[ 637.642230] ? import_iovec+0x28/0x30
[ 637.645899] ___sys_sendmsg+0xa8/0xe0
[ 637.649563] ? __this_cpu_preempt_check+0xf/0x11
[ 637.654179] ? __this_cpu_preempt_check+0xf/0x11
[ 637.658791] ? lock_is_held_type+0xb6/0x120
[ 637.662978] ? __this_cpu_preempt_check+0xf/0x11
[ 637.667596] ? lock_is_held_type+0xb6/0x120
[ 637.671781] ? __fdget+0x12/0x20
[ 637.675015] __sys_sendmsg+0x50/0x90
[ 637.678586] __ia32_sys_socketcall+0x39f/0x3c0
[ 637.683032] __do_fast_syscall_32+0x77/0xd0
[ 637.687217] ? __this_cpu_preempt_check+0xf/0x11
[ 637.691836] ? lock_is_held_type+0xb6/0x120
[ 637.696021] ? do_int80_syscall_32+0x59/0x70
[ 637.700283] ? __this_cpu_preempt_check+0xf/0x11
[ 637.704898] ? lockdep_hardirqs_on+0x87/0x120
[ 637.709271] ? lockdep_hardirqs_on_prepare+0xda/0x1f0
[ 637.714315] ? syscall_exit_to_user_mode+0x38/0x50
[ 637.719100] ? do_int80_syscall_32+0x59/0x70
[ 637.723364] ? lockdep_hardirqs_on+0x87/0x120
[ 637.727724] ? lockdep_hardirqs_on_prepare+0xda/0x1f0
[ 637.732776] ? irqentry_exit_to_user_mode+0x26/0x30
[ 637.737656] do_fast_syscall_32+0x32/0x70
[ 637.741669] do_SYSENTER_32+0x15/0x20
[ 637.745333] entry_SYSENTER_32+0x98/0xf1
[ 637.749251] EIP: 0xb7fb4549
[ 637.752040] Code: 03 74 c0 01 10 05 03 74 b8 01 10 06 03 74 b4 01
10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 51 52 55 89 e5 0f
34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90
8d 76
[ 637.770776] EAX: ffffffda EBX: 00000010 ECX: bfe416b4 EDX: 00000000
[ 637.777035] ESI: 00000000 EDI: 080e5840 EBP: 00000010 ESP: bfe416a0
[ 637.783292] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000282
# TEST: IPv4 packets over UDPv4


metadata:
git_ref: master
git_repo: https://gitlab.com/Linaro/lkft/mirrors/torvalds/linux-mainline
git_sha: c5eb0a61238dd6faf37f58c9ce61c9980aaffd7a
git_describe: v5.18-rc6
kernel_version: 5.18.0-rc6
kernel-config: https://builds.tuxbuild.com/28toZBX67g0hle8cic5YCYCkXyy/config
build-url: https://gitlab.com/Linaro/lkft/mirrors/torvalds/linux-mainline/-/pipelines/534026340
artifact-location: https://builds.tuxbuild.com/28toZBX67g0hle8cic5YCYCkXyy
toolchain: gcc-11


Full test log links,

[1] https://lkft.validation.linaro.org/scheduler/job/4998250#L6279
[2] https://qa-reports.linaro.org/lkft/linux-mainline-master/build/v5.18-rc6/testrun/9390418/suite/linux-log-parser/test/check-kernel-warning-4998250/log


--
Linaro LKFT
https://lkft.linaro.org