Following kernel warnings noticed on arm beagleboard X15 device while running selftests: tc-testing: tdc.sh with stable-rc 6.1.
This is always reproducible with kselftest merge configs. The build, config, vmlinux and test details links provided [1].
[ 228.686798] WARNING: inconsistent lock state [ 228.193450] WARNING: CPU: 1 PID: 2386 at include/linux/u64_stats_sync.h:145 __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.439208] WARNING: CPU: 1 PID: 2386 at include/linux/seqlock.h:269 __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred
Reported-by: Linux Kernel Functional Testing lkft@linaro.org
[ 204.305236] kselftest: Running tests in tc-testing TAP version 13 1..1 # selftests: tc-testing: tdc.sh # considering category actions # -- buildebpf/SubPlugin.__init__ # Unable to import the scapy python module. # # If not already installed, you may do so with: # pip3 install scapy==2.4.2 [ 207.264129] IPv6: ADDRCONF(NETDEV_CHANGE): v0p1: link becomes ready [ 207.271331] IPv6: ADDRCONF(NETDEV_CHANGE): v0p0: link becomes ready [ 228.188781] ------------[ cut here ]------------ [ 228.193450] WARNING: CPU: 1 PID: 2386 at include/linux/u64_stats_sync.h:145 __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.204803] Modules linked in: sch_gred sch_multiq sch_cake netdevsim psample iptable_raw ip6_tables vrf iptable_filter xt_state ip_tables x_tables nft_masq nft_nat nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 veth nf_tables libcrc32c nfnetlink cfg80211 bluetooth snd_soc_simple_card snd_soc_simple_card_utils etnaviv gpu_sched onboard_usb_hub snd_soc_davinci_mcasp snd_soc_ti_udma snd_soc_ti_edma snd_soc_ti_sdma snd_soc_core ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore display_connector sch_fq_codel fuse [ 228.252777] CPU: 1 PID: 2386 Comm: tc Not tainted 6.1.4-rc1 #1 [ 228.258666] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.264770] unwind_backtrace from show_stack+0x18/0x1c [ 228.270050] show_stack from dump_stack_lvl+0x58/0x70 [ 228.275146] dump_stack_lvl from __warn+0xd0/0x1f0 [ 228.279968] __warn from warn_slowpath_fmt+0x64/0xc8 [ 228.284973] warn_slowpath_fmt from __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.292694] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.300689] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.306732] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.312072] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.317260] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.322692] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.328674] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.334533] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.340301] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 228.346099] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 228.351898] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 228.357421] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 228.362579] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 228.367858] Exception stack(0xf03f9fa8 to 0xf03f9ff0) [ 228.372955] 9fa0: 00000000 00000001 00000003 bee09bdc 00000000 00000000 [ 228.381164] 9fc0: 00000000 00000001 b6f78800 00000128 626ad2dc 00000000 00000000 00076000 [ 228.389373] 9fe0: 00000128 bee09b78 b6dff253 b6d71ae6 [ 228.394561] irq event stamp: 25529 [ 228.398040] hardirqs last enabled at (25551): [<c03da980>] __up_console_sem+0x58/0x68 [ 228.406005] hardirqs last disabled at (25558): [<c03da96c>] __up_console_sem+0x44/0x68 [ 228.414001] softirqs last enabled at (25548): [<c0301fc8>] __do_softirq+0x300/0x538 [ 228.421844] softirqs last disabled at (25537): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 228.429870] ---[ end trace 0000000000000000 ]--- [ 228.434509] ------------[ cut here ]------------ [ 228.439208] WARNING: CPU: 1 PID: 2386 at include/linux/seqlock.h:269 __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred] [ 228.449829] Modules linked in: sch_gred sch_multiq sch_cake netdevsim psample iptable_raw ip6_tables vrf iptable_filter xt_state ip_tables x_tables nft_masq nft_nat nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 veth nf_tables libcrc32c nfnetlink cfg80211 bluetooth snd_soc_simple_card snd_soc_simple_card_utils etnaviv gpu_sched onboard_usb_hub snd_soc_davinci_mcasp snd_soc_ti_udma snd_soc_ti_edma snd_soc_ti_sdma snd_soc_core ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore display_connector sch_fq_codel fuse [ 228.497802] CPU: 1 PID: 2386 Comm: tc Tainted: G W 6.1.4-rc1 #1 [ 228.505157] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.511291] unwind_backtrace from show_stack+0x18/0x1c [ 228.516571] show_stack from dump_stack_lvl+0x58/0x70 [ 228.521636] dump_stack_lvl from __warn+0xd0/0x1f0 [ 228.526458] __warn from warn_slowpath_fmt+0x64/0xc8 [ 228.531494] warn_slowpath_fmt from __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred] [ 228.539184] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.547180] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.553222] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.558593] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.563751] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.569183] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.575164] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.581024] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.586822] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 228.592590] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 228.598388] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 228.603912] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 228.609100] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 228.614349] Exception stack(0xf03f9fa8 to 0xf03f9ff0) [ 228.619415] 9fa0: 00000000 00000001 00000003 bee09bdc 00000000 00000000 [ 228.627655] 9fc0: 00000000 00000001 b6f78800 00000128 626ad2dc 00000000 00000000 00076000 [ 228.635864] 9fe0: 00000128 bee09b78 b6dff253 b6d71ae6 [ 228.641052] irq event stamp: 25921 [ 228.644470] hardirqs last enabled at (25929): [<c03da980>] __up_console_sem+0x58/0x68 [ 228.652465] hardirqs last disabled at (25938): [<c03da96c>] __up_console_sem+0x44/0x68 [ 228.660491] softirqs last enabled at (25920): [<c0301fc8>] __do_softirq+0x300/0x538 [ 228.668334] softirqs last disabled at (25957): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 228.676300] ---[ end trace 0000000000000000 ]--- [ 228.680999] [ 228.682495] ================================ [ 228.686798] WARNING: inconsistent lock state [ 228.691070] 6.1.4-rc1 #1 Tainted: G W [ 228.696136] -------------------------------- [ 228.700439] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage. [ 228.706481] tc/2386 [HC0[0]:SC0[0]:HE1:SE1] takes: [ 228.711303] c96870b4 (&syncp->seq#14){+.?.}-{0:0}, at: gred_dump+0x1c0/0x790 [sch_gred] [ 228.719360] {IN-SOFTIRQ-W} state was registered at: [ 228.724273] __u64_stats_update_begin+0x10c/0x1a4 [ 228.729095] __dev_queue_xmit+0xcac/0x1288 [ 228.733306] arp_process+0x8cc/0x95c [ 228.736999] __netif_receive_skb_one_core+0x58/0x74 [ 228.741973] netif_receive_skb+0xe4/0x474 [ 228.746093] cpsw_rx_handler+0x1a0/0x42c [ 228.750122] __cpdma_chan_process+0xf4/0x188 [ 228.754516] cpdma_chan_process+0x44/0x5c [ 228.758636] cpsw_rx_mq_poll+0x4c/0x9c [ 228.762512] __napi_poll+0x3c/0x28c [ 228.766113] net_rx_action+0x160/0x350 [ 228.769958] __do_softirq+0x130/0x538 [ 228.773712] call_with_stack+0x18/0x20 [ 228.777587] do_softirq+0xb0/0xb4 [ 228.781005] __local_bh_enable_ip+0x180/0x1b8 [ 228.785461] ip_finish_output2+0x21c/0xb74 [ 228.789672] ip_send_skb+0x58/0x120 [ 228.793273] udp_send_skb+0x13c/0x38c [ 228.797027] udp_sendmsg+0x920/0xe28 [ 228.800720] ____sys_sendmsg+0x224/0x2bc [ 228.804748] ___sys_sendmsg+0x70/0x9c [ 228.808502] sys_sendmsg+0x54/0x90 [ 228.812011] __sys_trace_return+0x0/0x10 [ 228.816040] irq event stamp: 25991 [ 228.819458] hardirqs last enabled at (25991): [<c03da980>] __up_console_sem+0x58/0x68 [ 228.827423] hardirqs last disabled at (25990): [<c03da96c>] __up_console_sem+0x44/0x68 [ 228.835388] softirqs last enabled at (25970): [<c0301fc8>] __do_softirq+0x300/0x538 [ 228.843170] softirqs last disabled at (25957): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 228.851135] [ 228.851135] other info that might help us debug this: [ 228.857666] Possible unsafe locking scenario: [ 228.857666] [ 228.863616] CPU0 [ 228.866088] ---- [ 228.868530] lock(&syncp->seq#14); [ 228.872039] <Interrupt> [ 228.874694] lock(&syncp->seq#14); [ 228.878387] [ 228.878387] *** DEADLOCK *** [ 228.878387] [ 228.884307] 1 lock held by tc/2386: [ 228.887817] #0: c25b0760 (rtnl_mutex){+.+.}-{3:3}, at: qdisc_create+0x3cc/0x5bc [ 228.895294] [ 228.895294] stack backtrace: [ 228.899658] CPU: 1 PID: 2386 Comm: tc Tainted: G W 6.1.4-rc1 #1 [ 228.907012] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.913146] unwind_backtrace from show_stack+0x18/0x1c [ 228.918395] show_stack from dump_stack_lvl+0x58/0x70 [ 228.923492] dump_stack_lvl from mark_lock.part.0+0xb74/0x128c [ 228.929351] mark_lock.part.0 from __lock_acquire+0x984/0x2a8c [ 228.935211] __lock_acquire from lock_acquire+0x110/0x364 [ 228.940643] lock_acquire from __u64_stats_update_begin+0x10c/0x1a4 [sch_gred] [ 228.947906] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.955871] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.961914] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.967254] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.972442] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.977874] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.983825] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.989685] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.995452] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 229.001220] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 229.007019] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 229.012542] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 229.017700] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 229.022979] Exception stack(0xf03f9fa8 to 0xf03f9ff0) [ 229.028045] 9fa0: 00000000 00000001 00000003 bee09bdc 00000000 00000000 [ 229.036285] 9fc0: 00000000 00000001 b6f78800 00000128 626ad2dc 00000000 00000000 00076000 [ 229.044494] 9fe0: 00000128 bee09b78 b6dff253 b6d71ae6 [ 232.169219] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 232.528900] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 232.913879] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 233.339508] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 233.720397] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.080047] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.460174] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.540374] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.950683] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 235.029327] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! # # -----> teardown stage *** Could not execute: "$TC qdisc del dev $DUMMY handle 1: root" # # -----> teardown stage *** Error message: "Error: Invalid handle. # " # # -----> teardown stage *** Aborting test run. #
[1] https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-6.1.y/build/v6.1.3-... https://lkft.validation.linaro.org/scheduler/job/6022394#L4509
metadata: git_ref: linux-6.1.y git_repo: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc git_sha: a31425cbf493ef8bc7f7ce775a1028b1e0612f32 git_describe: v6.1.3-208-ga31425cbf493 kernel_version: 6.1.4-rc1 kernel-config: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT... build-url: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc/-/pipelines/73... artifact-location: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT... toolchain: gcc-10 vmlinux.xz: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT... System.map: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT...
-- Linaro LKFT https://lkft.linaro.org
On Thu, 5 Jan 2023 20:19:27 +0530 Naresh Kamboju wrote:
Following kernel warnings noticed on arm beagleboard X15 device while running selftests: tc-testing: tdc.sh with stable-rc 6.1.
This is always reproducible with kselftest merge configs. The build, config, vmlinux and test details links provided [1].
[ 228.686798] WARNING: inconsistent lock state [ 228.193450] WARNING: CPU: 1 PID: 2386 at include/linux/u64_stats_sync.h:145 __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.439208] WARNING: CPU: 1 PID: 2386 at include/linux/seqlock.h:269 __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred
commit 44b0c2957adc ("u64_stats: Streamline the implementation") looks like the likely culprit. Would you be able to test a revert?
Reported-by: Linux Kernel Functional Testing lkft@linaro.org
[ 204.305236] kselftest: Running tests in tc-testing TAP version 13 1..1 # selftests: tc-testing: tdc.sh # considering category actions # -- buildebpf/SubPlugin.__init__ # Unable to import the scapy python module. # # If not already installed, you may do so with: # pip3 install scapy==2.4.2 [ 207.264129] IPv6: ADDRCONF(NETDEV_CHANGE): v0p1: link becomes ready [ 207.271331] IPv6: ADDRCONF(NETDEV_CHANGE): v0p0: link becomes ready [ 228.188781] ------------[ cut here ]------------ [ 228.193450] WARNING: CPU: 1 PID: 2386 at include/linux/u64_stats_sync.h:145 __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.204803] Modules linked in: sch_gred sch_multiq sch_cake netdevsim psample iptable_raw ip6_tables vrf iptable_filter xt_state ip_tables x_tables nft_masq nft_nat nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 veth nf_tables libcrc32c nfnetlink cfg80211 bluetooth snd_soc_simple_card snd_soc_simple_card_utils etnaviv gpu_sched onboard_usb_hub snd_soc_davinci_mcasp snd_soc_ti_udma snd_soc_ti_edma snd_soc_ti_sdma snd_soc_core ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore display_connector sch_fq_codel fuse [ 228.252777] CPU: 1 PID: 2386 Comm: tc Not tainted 6.1.4-rc1 #1 [ 228.258666] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.264770] unwind_backtrace from show_stack+0x18/0x1c [ 228.270050] show_stack from dump_stack_lvl+0x58/0x70 [ 228.275146] dump_stack_lvl from __warn+0xd0/0x1f0 [ 228.279968] __warn from warn_slowpath_fmt+0x64/0xc8 [ 228.284973] warn_slowpath_fmt from __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.292694] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.300689] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.306732] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.312072] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.317260] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.322692] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.328674] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.334533] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.340301] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 228.346099] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 228.351898] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 228.357421] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 228.362579] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 228.367858] Exception stack(0xf03f9fa8 to 0xf03f9ff0) [ 228.372955] 9fa0: 00000000 00000001 00000003 bee09bdc 00000000 00000000 [ 228.381164] 9fc0: 00000000 00000001 b6f78800 00000128 626ad2dc 00000000 00000000 00076000 [ 228.389373] 9fe0: 00000128 bee09b78 b6dff253 b6d71ae6 [ 228.394561] irq event stamp: 25529 [ 228.398040] hardirqs last enabled at (25551): [<c03da980>] __up_console_sem+0x58/0x68 [ 228.406005] hardirqs last disabled at (25558): [<c03da96c>] __up_console_sem+0x44/0x68 [ 228.414001] softirqs last enabled at (25548): [<c0301fc8>] __do_softirq+0x300/0x538 [ 228.421844] softirqs last disabled at (25537): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 228.429870] ---[ end trace 0000000000000000 ]--- [ 228.434509] ------------[ cut here ]------------ [ 228.439208] WARNING: CPU: 1 PID: 2386 at include/linux/seqlock.h:269 __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred] [ 228.449829] Modules linked in: sch_gred sch_multiq sch_cake netdevsim psample iptable_raw ip6_tables vrf iptable_filter xt_state ip_tables x_tables nft_masq nft_nat nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 veth nf_tables libcrc32c nfnetlink cfg80211 bluetooth snd_soc_simple_card snd_soc_simple_card_utils etnaviv gpu_sched onboard_usb_hub snd_soc_davinci_mcasp snd_soc_ti_udma snd_soc_ti_edma snd_soc_ti_sdma snd_soc_core ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore display_connector sch_fq_codel fuse [ 228.497802] CPU: 1 PID: 2386 Comm: tc Tainted: G W 6.1.4-rc1 #1 [ 228.505157] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.511291] unwind_backtrace from show_stack+0x18/0x1c [ 228.516571] show_stack from dump_stack_lvl+0x58/0x70 [ 228.521636] dump_stack_lvl from __warn+0xd0/0x1f0 [ 228.526458] __warn from warn_slowpath_fmt+0x64/0xc8 [ 228.531494] warn_slowpath_fmt from __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred] [ 228.539184] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.547180] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.553222] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.558593] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.563751] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.569183] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.575164] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.581024] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.586822] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 228.592590] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 228.598388] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 228.603912] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 228.609100] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 228.614349] Exception stack(0xf03f9fa8 to 0xf03f9ff0) [ 228.619415] 9fa0: 00000000 00000001 00000003 bee09bdc 00000000 00000000 [ 228.627655] 9fc0: 00000000 00000001 b6f78800 00000128 626ad2dc 00000000 00000000 00076000 [ 228.635864] 9fe0: 00000128 bee09b78 b6dff253 b6d71ae6 [ 228.641052] irq event stamp: 25921 [ 228.644470] hardirqs last enabled at (25929): [<c03da980>] __up_console_sem+0x58/0x68 [ 228.652465] hardirqs last disabled at (25938): [<c03da96c>] __up_console_sem+0x44/0x68 [ 228.660491] softirqs last enabled at (25920): [<c0301fc8>] __do_softirq+0x300/0x538 [ 228.668334] softirqs last disabled at (25957): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 228.676300] ---[ end trace 0000000000000000 ]--- [ 228.680999] [ 228.682495] ================================ [ 228.686798] WARNING: inconsistent lock state [ 228.691070] 6.1.4-rc1 #1 Tainted: G W [ 228.696136] -------------------------------- [ 228.700439] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage. [ 228.706481] tc/2386 [HC0[0]:SC0[0]:HE1:SE1] takes: [ 228.711303] c96870b4 (&syncp->seq#14){+.?.}-{0:0}, at: gred_dump+0x1c0/0x790 [sch_gred] [ 228.719360] {IN-SOFTIRQ-W} state was registered at: [ 228.724273] __u64_stats_update_begin+0x10c/0x1a4 [ 228.729095] __dev_queue_xmit+0xcac/0x1288 [ 228.733306] arp_process+0x8cc/0x95c [ 228.736999] __netif_receive_skb_one_core+0x58/0x74 [ 228.741973] netif_receive_skb+0xe4/0x474 [ 228.746093] cpsw_rx_handler+0x1a0/0x42c [ 228.750122] __cpdma_chan_process+0xf4/0x188 [ 228.754516] cpdma_chan_process+0x44/0x5c [ 228.758636] cpsw_rx_mq_poll+0x4c/0x9c [ 228.762512] __napi_poll+0x3c/0x28c [ 228.766113] net_rx_action+0x160/0x350 [ 228.769958] __do_softirq+0x130/0x538 [ 228.773712] call_with_stack+0x18/0x20 [ 228.777587] do_softirq+0xb0/0xb4 [ 228.781005] __local_bh_enable_ip+0x180/0x1b8 [ 228.785461] ip_finish_output2+0x21c/0xb74 [ 228.789672] ip_send_skb+0x58/0x120 [ 228.793273] udp_send_skb+0x13c/0x38c [ 228.797027] udp_sendmsg+0x920/0xe28 [ 228.800720] ____sys_sendmsg+0x224/0x2bc [ 228.804748] ___sys_sendmsg+0x70/0x9c [ 228.808502] sys_sendmsg+0x54/0x90 [ 228.812011] __sys_trace_return+0x0/0x10 [ 228.816040] irq event stamp: 25991 [ 228.819458] hardirqs last enabled at (25991): [<c03da980>] __up_console_sem+0x58/0x68 [ 228.827423] hardirqs last disabled at (25990): [<c03da96c>] __up_console_sem+0x44/0x68 [ 228.835388] softirqs last enabled at (25970): [<c0301fc8>] __do_softirq+0x300/0x538 [ 228.843170] softirqs last disabled at (25957): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 228.851135] [ 228.851135] other info that might help us debug this: [ 228.857666] Possible unsafe locking scenario: [ 228.857666] [ 228.863616] CPU0 [ 228.866088] ---- [ 228.868530] lock(&syncp->seq#14); [ 228.872039] <Interrupt> [ 228.874694] lock(&syncp->seq#14); [ 228.878387] [ 228.878387] *** DEADLOCK *** [ 228.878387] [ 228.884307] 1 lock held by tc/2386: [ 228.887817] #0: c25b0760 (rtnl_mutex){+.+.}-{3:3}, at: qdisc_create+0x3cc/0x5bc [ 228.895294] [ 228.895294] stack backtrace: [ 228.899658] CPU: 1 PID: 2386 Comm: tc Tainted: G W 6.1.4-rc1 #1 [ 228.907012] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.913146] unwind_backtrace from show_stack+0x18/0x1c [ 228.918395] show_stack from dump_stack_lvl+0x58/0x70 [ 228.923492] dump_stack_lvl from mark_lock.part.0+0xb74/0x128c [ 228.929351] mark_lock.part.0 from __lock_acquire+0x984/0x2a8c [ 228.935211] __lock_acquire from lock_acquire+0x110/0x364 [ 228.940643] lock_acquire from __u64_stats_update_begin+0x10c/0x1a4 [sch_gred] [ 228.947906] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.955871] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.961914] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.967254] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.972442] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.977874] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.983825] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.989685] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.995452] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 229.001220] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 229.007019] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 229.012542] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 229.017700] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 229.022979] Exception stack(0xf03f9fa8 to 0xf03f9ff0) [ 229.028045] 9fa0: 00000000 00000001 00000003 bee09bdc 00000000 00000000 [ 229.036285] 9fc0: 00000000 00000001 b6f78800 00000128 626ad2dc 00000000 00000000 00076000 [ 229.044494] 9fe0: 00000128 bee09b78 b6dff253 b6d71ae6 [ 232.169219] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 232.528900] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 232.913879] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 233.339508] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 233.720397] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.080047] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.460174] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.540374] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 234.950683] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 235.029327] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! # # -----> teardown stage *** Could not execute: "$TC qdisc del dev $DUMMY handle 1: root" # # -----> teardown stage *** Error message: "Error: Invalid handle. # " # # -----> teardown stage *** Aborting test run. #
[1] https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-6.1.y/build/v6.1.3-... https://lkft.validation.linaro.org/scheduler/job/6022394#L4509
metadata: git_ref: linux-6.1.y git_repo: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc git_sha: a31425cbf493ef8bc7f7ce775a1028b1e0612f32 git_describe: v6.1.3-208-ga31425cbf493 kernel_version: 6.1.4-rc1 kernel-config: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT... build-url: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc/-/pipelines/73... artifact-location: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT... toolchain: gcc-10 vmlinux.xz: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT... System.map: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3HT...
-- Linaro LKFT https://lkft.linaro.org
On Sat, 7 Jan 2023 at 05:33, Jakub Kicinski kuba@kernel.org wrote:
On Thu, 5 Jan 2023 20:19:27 +0530 Naresh Kamboju wrote:
Following kernel warnings noticed on arm beagleboard X15 device while running selftests: tc-testing: tdc.sh with stable-rc 6.1.
This is always reproducible with kselftest merge configs. The build, config, vmlinux and test details links provided [1].
[ 228.686798] WARNING: inconsistent lock state [ 228.193450] WARNING: CPU: 1 PID: 2386 at include/linux/u64_stats_sync.h:145 __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.439208] WARNING: CPU: 1 PID: 2386 at include/linux/seqlock.h:269 __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred
commit 44b0c2957adc ("u64_stats: Streamline the implementation") looks like the likely culprit. Would you be able to test a revert?
As per your suggestion I have reverted 44b0c2957adc ("u64_stats: Streamline the implementation")
And test shows below warning (seqlock.h:269 gred_dump+0x60c/0x880 [sch_gred])
test log: ----------- # selftests: tc-testing: tdc.sh # considering category actions # -- buildebpf/SubPlugin.__init__ # -- ns/SubPlugin.__init__ # Unable to import the scapy python module. # # If not already installed, you may do so with: # pip3 install scapy==2.4.2 [ 72.334625] IPv6: ADDRCONF(NETDEV_CHANGE): v0p1: link becomes ready [ 72.342132] IPv6: ADDRCONF(NETDEV_CHANGE): v0p0: link becomes ready [ 92.637207] ------------[ cut here ]------------ [ 92.641876] WARNING: CPU: 0 PID: 687 at include/linux/seqlock.h:269 gred_dump+0x60c/0x880 [sch_gred] [ 92.651153] Modules linked in: sch_gred sch_multiq sch_cake veth netdevsim psample cfg80211 bluetooth snd_soc_simple_card etnaviv snd_soc_simple_card_utils gpu_sched onboard_usb_hub snd_soc_davinci_mcasp snd_soc_ti_udma snd_soc_ti_edma snd_soc_ti_sdma snd_soc_core ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore display_connector sch_fq_codel fuse [ 92.683319] CPU: 0 PID: 687 Comm: tc Not tainted 6.1.5-rc1 #1 [ 92.689117] Hardware name: Generic DRA74X (Flattened Device Tree) [ 92.695251] unwind_backtrace from show_stack+0x18/0x1c [ 92.700500] show_stack from dump_stack_lvl+0x58/0x70 [ 92.705596] dump_stack_lvl from __warn+0xd0/0x1f0 [ 92.710449] __warn from warn_slowpath_fmt+0x64/0xc8 [ 92.715454] warn_slowpath_fmt from gred_dump+0x60c/0x880 [sch_gred] [ 92.721862] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 92.727905] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 92.733245] qdisc_notify from qdisc_graft+0x440/0x624 [ 92.738433] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 92.743865] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 92.749816] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 92.755706] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 92.761474] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 92.767272] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 92.773040] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 92.778594] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 92.783752] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 92.789031] Exception stack(0xf10f5fa8 to 0xf10f5ff0) [ 92.794128] 5fa0: 00000000 00000001 00000003 be92cbdc 00000000 00000000 [ 92.802337] 5fc0: 00000000 00000001 b6f44800 00000128 63bfdcd4 00000000 00000000 00076000 [ 92.810577] 5fe0: 00000128 be92cb78 b6dbf253 b6d31ae6 [ 92.815734] irq event stamp: 25413 [ 92.819213] hardirqs last enabled at (25423): [<c03da980>] __up_console_sem+0x58/0x68 [ 92.827239] hardirqs last disabled at (25432): [<c03da96c>] __up_console_sem+0x44/0x68 [ 92.835235] softirqs last enabled at (25412): [<c0301fc8>] __do_softirq+0x300/0x538 [ 92.843078] softirqs last disabled at (25393): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 92.851196] ---[ end trace 0000000000000000 ]--- [ 92.855865] [ 92.857360] ================================ [ 92.861663] WARNING: inconsistent lock state [ 92.865936] 6.1.5-rc1 #1 Tainted: G W [ 92.871032] -------------------------------- [ 92.875305] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage. [ 92.881347] tc/687 [HC0[0]:SC0[0]:HE1:SE1] takes: [ 92.886077] c9d31cb4 (&(&b->syncp)->seq){+.?.}-{0:0}, at: tc_fill_qdisc+0x154/0x44c [ 92.893798] {IN-SOFTIRQ-W} state was registered at: [ 92.898681] __dev_queue_xmit+0xf68/0x1514 [ 92.902893] __neigh_update+0x2b0/0xe78 [ 92.906860] neigh_update+0x24/0x2c [ 92.910430] arp_process+0x264/0x95c [ 92.914123] __netif_receive_skb_one_core+0x58/0x74 [ 92.919128] netif_receive_skb+0xe4/0x474 [ 92.923248] cpsw_rx_handler+0x1a0/0x42c [ 92.927276] __cpdma_chan_process+0xf4/0x188 [ 92.931671] cpdma_chan_process+0x44/0x5c [ 92.935791] cpsw_rx_mq_poll+0x4c/0x9c [ 92.939636] __napi_poll+0x3c/0x28c [ 92.943237] net_rx_action+0x160/0x350 [ 92.947082] __do_softirq+0x130/0x538 [ 92.950866] __irq_exit_rcu+0x14c/0x170 [ 92.954803] irq_exit+0x10/0x30 [ 92.958038] call_with_stack+0x18/0x20 [ 92.961914] __irq_svc+0x9c/0xb8 [ 92.965240] lock_acquire+0x12c/0x364 [ 92.969024] __might_fault+0x5c/0x7c [ 92.972717] __rseq_handle_notify_resume+0x60/0x6e0 [ 92.977691] do_work_pending+0x10c/0x57c [ 92.981719] slow_work_pending+0xc/0x20 [ 92.985687] irq event stamp: 25499 [ 92.989074] hardirqs last enabled at (25499): [<c03da980>] __up_console_sem+0x58/0x68 [ 92.997039] hardirqs last disabled at (25498): [<c03da96c>] __up_console_sem+0x44/0x68 [ 93.005004] softirqs last enabled at (25488): [<c0301fc8>] __do_softirq+0x300/0x538 [ 93.012786] softirqs last disabled at (25461): [<c035a224>] __irq_exit_rcu+0x14c/0x170 [ 93.020751] [ 93.020751] other info that might help us debug this: [ 93.027313] Possible unsafe locking scenario: [ 93.027313] [ 93.033264] CPU0 [ 93.035705] ---- [ 93.038177] lock(&(&b->syncp)->seq); [ 93.041931] <Interrupt> [ 93.044586] lock(&(&b->syncp)->seq); [ 93.048522] [ 93.048522] *** DEADLOCK *** [ 93.048522] [ 93.054473] 1 lock held by tc/687: [ 93.057891] #0: c25b0720 (rtnl_mutex){+.+.}-{3:3}, at: qdisc_create+0x3cc/0x5bc [ 93.065338] [ 93.065338] stack backtrace: [ 93.069732] CPU: 0 PID: 687 Comm: tc Tainted: G W 6.1.5-rc1 #1 [ 93.076995] Hardware name: Generic DRA74X (Flattened Device Tree) [ 93.083099] unwind_backtrace from show_stack+0x18/0x1c [ 93.088378] show_stack from dump_stack_lvl+0x58/0x70 [ 93.093444] dump_stack_lvl from mark_lock.part.0+0xb74/0x128c [ 93.099334] mark_lock.part.0 from __lock_acquire+0x984/0x2a8c [ 93.105194] __lock_acquire from lock_acquire+0x110/0x364 [ 93.110626] lock_acquire from gred_dump+0x20c/0x880 [sch_gred] [ 93.116577] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 93.122619] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 93.127960] qdisc_notify from qdisc_graft+0x440/0x624 [ 93.133117] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 93.138549] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 93.144500] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 93.150390] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 93.156158] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 93.161926] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 93.167724] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 93.173217] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 93.178405] sys_sendmsg from ret_fast_syscall+0x0/0x1c [ 93.183654] Exception stack(0xf10f5fa8 to 0xf10f5ff0) [ 93.188751] 5fa0: 00000000 00000001 00000003 be92cbdc 00000000 00000000 [ 93.196960] 5fc0: 00000000 00000001 b6f44800 00000128 63bfdcd4 00000000 00000000 00076000 [ 93.205169] 5fe0: 00000128 be92cb78 b6dbf253 b6d31ae6 [ 96.129364] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 96.508056] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 96.892181] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 97.278503] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 97.660583] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 98.038024] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 98.428039] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 98.495635] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 98.901245] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) ! [ 98.989288] sch_tbf: burst 1500 is lower than device dummy1 mtu (1514) !
https://lkft.validation.linaro.org/scheduler/job/6047355#L2951
- Naresh
On Fri, 13 Jan 2023 13:11:55 +0530 Naresh Kamboju wrote:
On Sat, 7 Jan 2023 at 05:33, Jakub Kicinski kuba@kernel.org wrote:
On Thu, 5 Jan 2023 20:19:27 +0530 Naresh Kamboju wrote:
Following kernel warnings noticed on arm beagleboard X15 device while running selftests: tc-testing: tdc.sh with stable-rc 6.1.
This is always reproducible with kselftest merge configs. The build, config, vmlinux and test details links provided [1].
[ 228.686798] WARNING: inconsistent lock state [ 228.193450] WARNING: CPU: 1 PID: 2386 at include/linux/u64_stats_sync.h:145 __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.439208] WARNING: CPU: 1 PID: 2386 at include/linux/seqlock.h:269 __u64_stats_update_begin+0x1a0/0x1a4 [sch_gred
commit 44b0c2957adc ("u64_stats: Streamline the implementation") looks like the likely culprit. Would you be able to test a revert?
As per your suggestion I have reverted 44b0c2957adc ("u64_stats: Streamline the implementation")
And test shows below warning (seqlock.h:269 gred_dump+0x60c/0x880 [sch_gred])
Thanks! Fix submitted:
https://lore.kernel.org/all/20230113044137.1383067-1-kuba@kernel.org/
On Thu, 5 Jan 2023 20:19:27 +0530 Naresh Kamboju wrote:
[ 228.252777] CPU: 1 PID: 2386 Comm: tc Not tainted 6.1.4-rc1 #1 [ 228.258666] Hardware name: Generic DRA74X (Flattened Device Tree) [ 228.264770] unwind_backtrace from show_stack+0x18/0x1c [ 228.270050] show_stack from dump_stack_lvl+0x58/0x70 [ 228.275146] dump_stack_lvl from __warn+0xd0/0x1f0 [ 228.279968] __warn from warn_slowpath_fmt+0x64/0xc8 [ 228.284973] warn_slowpath_fmt from __u64_stats_update_begin+0x180/0x1a4 [sch_gred] [ 228.292694] __u64_stats_update_begin [sch_gred] from gred_dump+0x1c0/0x790 [sch_gred] [ 228.300689] gred_dump [sch_gred] from tc_fill_qdisc+0x154/0x44c [ 228.306732] tc_fill_qdisc from qdisc_notify+0x11c/0x130 [ 228.312072] qdisc_notify from qdisc_graft+0x440/0x624 [ 228.317260] qdisc_graft from tc_modify_qdisc+0x558/0x850 [ 228.322692] tc_modify_qdisc from rtnetlink_rcv_msg+0x180/0x56c [ 228.328674] rtnetlink_rcv_msg from netlink_rcv_skb+0xc0/0x118 [ 228.334533] netlink_rcv_skb from netlink_unicast+0x19c/0x268 [ 228.340301] netlink_unicast from netlink_sendmsg+0x1f8/0x484 [ 228.346099] netlink_sendmsg from ____sys_sendmsg+0x224/0x2bc [ 228.351898] ____sys_sendmsg from ___sys_sendmsg+0x70/0x9c [ 228.357421] ___sys_sendmsg from sys_sendmsg+0x54/0x90 [ 228.362579] sys_sendmsg from ret_fast_syscall+0x0/0x1c
I think this is a false positive in the offload handling, but could you run ./scripts/decode_stacktrace.sh on this? u64_stats_update_begin must be inlined somewhere, quick grep does not show any results in gred_dump().
-
Jakub Kicinski -
Naresh Kamboju