January 2023 - Linux-kselftest-mirror

[PATCH 0/3] selftests/tracing: Fix some testcases for recent change

by Masami Hiramatsu (Google)

This includes some patches to fix 2 issues on ftrace selftests. - eprobe filter and eprobe syntax test case were introduced but it doesn't check whether the kernel supports eprobe filter. Thus the new test case fails on the kernel which has eprobe but not support eprobe filter. To solve this issue, add a filter description to README file [1/3] and run the filter syntax error test only if the description is found in the README file [2/3]. - Recently objtool adds prefix symbols for the function padding nops, and the probepoint test case fails because this probepoint test case tests whether the kprobe event can probe the target function and the functions next to the target function. But the prefix symbols can not be probed. Thus these prefix symbols must be skipped [3/3]. Thank you, --- Masami Hiramatsu (Google) (3): tracing/eprobe: Fix to add filter on eprobe description in README file selftests/ftrace: Fix eprobe syntax test case to check filter support selftests/ftrace: Fix probepoint testcase to ignore __pfx_* symbols kernel/trace/trace.c | 2 +- .../test.d/dynevent/eprobes_syntax_errors.tc | 4 +++- .../selftests/ftrace/test.d/kprobe/probepoint.tc | 2 +- 3 files changed, 5 insertions(+), 3 deletions(-) -- Masami Hiramatsu (Google) <mhiramat(a)kernel.org>

2 years, 9 months

1
0
0 0

[PATCH] proc: fix PIE proc-empty-vm, proc-pid-vm tests

by Alexey Dobriyan

vsyscall detection code uses direct call to the beginning of the vsyscall page: asm ("call %P0" :: "i" (0xffffffffff600000)) It generates "call rel32" instruction but it is not relocated if binary is PIE, so binary segfaults into random userspace address and vsyscall page status is detected incorrectly. Do more direct: asm ("call *%rax") which doesn't do need any relocaltions. Mark g_vsyscall as volatile for a good measure, I didn't find instruction setting it to 0. Now the code is obviously correct: xor eax, eax mov rdi, rbp mov rsi, rbp mov DWORD PTR [rip+0x2d15], eax # g_vsyscall = 0 mov rax, 0xffffffffff600000 call rax mov DWORD PTR [rip+0x2d02], 1 # g_vsyscall = 1 mov eax, DWORD PTR ds:0xffffffffff600000 mov DWORD PTR [rip+0x2cf1], 2 # g_vsyscall = 2 mov edi, [rip+0x2ceb] # exit(g_vsyscall) call exit Note: fixed proc-empty-vm test oopses 5.19.0-28-generic kernel but this is separate story. Signed-off-by: Alexey Dobriyan <adobriyan(a)gmail.com> Reported-by: Mirsad Goran Todorovac <mirsad.todorovac(a)alu.unizg.hr> --- tools/testing/selftests/proc/proc-empty-vm.c | 12 +++++++----- tools/testing/selftests/proc/proc-pid-vm.c | 9 +++++---- 2 files changed, 12 insertions(+), 9 deletions(-) --- a/tools/testing/selftests/proc/proc-empty-vm.c +++ b/tools/testing/selftests/proc/proc-empty-vm.c @@ -25,6 +25,7 @@ #undef NDEBUG #include <assert.h> #include <errno.h> +#include <stdint.h> #include <stdio.h> #include <stdlib.h> #include <string.h> @@ -41,7 +42,7 @@ * 1: vsyscall VMA is --xp vsyscall=xonly * 2: vsyscall VMA is r-xp vsyscall=emulate */ -static int g_vsyscall; +static volatile int g_vsyscall; static const char *g_proc_pid_maps_vsyscall; static const char *g_proc_pid_smaps_vsyscall; @@ -147,11 +148,12 @@ static void vsyscall(void) g_vsyscall = 0; /* gettimeofday(NULL, NULL); */ + uint64_t rax = 0xffffffffff600000; asm volatile ( - "call %P0" - : - : "i" (0xffffffffff600000), "D" (NULL), "S" (NULL) - : "rax", "rcx", "r11" + "call *%[rax]" + : [rax] "+a" (rax) + : "D" (NULL), "S" (NULL) + : "rcx", "r11" ); g_vsyscall = 1; --- a/tools/testing/selftests/proc/proc-pid-vm.c +++ b/tools/testing/selftests/proc/proc-pid-vm.c @@ -257,11 +257,12 @@ static void vsyscall(void) g_vsyscall = 0; /* gettimeofday(NULL, NULL); */ + uint64_t rax = 0xffffffffff600000; asm volatile ( - "call %P0" - : - : "i" (0xffffffffff600000), "D" (NULL), "S" (NULL) - : "rax", "rcx", "r11" + "call *%[rax]" + : [rax] "+a" (rax) + : "D" (NULL), "S" (NULL) + : "rcx", "r11" ); g_vsyscall = 1;

2 years, 9 months

2
3
0 0

Re: [PATCH HID for-next v1 8/9] HID: bpf: clean up entrypoint

by Benjamin Tissoires

On Fri, Jan 6, 2023 at 2:42 PM kernel test robot <lkp(a)intel.com> wrote: > > Hi Benjamin, > > I love your patch! Perhaps something to improve: > > [auto build test WARNING on hid/for-next] > [also build test WARNING on next-20230106] > [cannot apply to shuah-kselftest/next shuah-kselftest/fixes char-misc/char-misc-testing char-misc/char-misc-next char-misc/char-misc-linus linus/master v6.2-rc2] > [If your patch is applied to the wrong git tree, kindly drop us a note. > And when submitting patch, we suggest to use '--base' as documented in > https://git-scm.com/docs/git-format-patch#_base_tree_information] > > url: https://github.com/intel-lab-lkp/linux/commits/Benjamin-Tissoires/selftests… > base: https://git.kernel.org/pub/scm/linux/kernel/git/hid/hid.git for-next > patch link: https://lore.kernel.org/r/20230106102332.1019632-9-benjamin.tissoires%40red… > patch subject: [PATCH HID for-next v1 8/9] HID: bpf: clean up entrypoint > config: i386-randconfig-a013 > compiler: clang version 14.0.6 (https://github.com/llvm/llvm-project f28c006a5895fc0e329fe15fead81e37457cb1d1) > reproduce (this is a W=1 build): > wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross > chmod +x ~/bin/make.cross > # https://github.com/intel-lab-lkp/linux/commit/46336953b47885c5111b7c1a92403… > git remote add linux-review https://github.com/intel-lab-lkp/linux > git fetch --no-tags linux-review Benjamin-Tissoires/selftests-hid-add-vmtest-sh/20230106-182823 > git checkout 46336953b47885c5111b7c1a92403b3d94cf3d41 > # save the config file > mkdir build_dir && cp config build_dir/.config > COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 olddefconfig > COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash drivers/hid/bpf/ > > If you fix the issue, kindly add following tag where applicable > | Reported-by: kernel test robot <lkp(a)intel.com> > > All warnings (new ones prefixed by >>): > > >> drivers/hid/bpf/hid_bpf_jmp_table.c:502:6: warning: no previous prototype for function 'call_hid_bpf_prog_put_deferred' [-Wmissing-prototypes] > void call_hid_bpf_prog_put_deferred(struct work_struct *work) > ^ > drivers/hid/bpf/hid_bpf_jmp_table.c:502:1: note: declare 'static' if the function is not intended to be used outside of this translation unit > void call_hid_bpf_prog_put_deferred(struct work_struct *work) > ^ > static > 1 warning generated. > > > vim +/call_hid_bpf_prog_put_deferred +502 drivers/hid/bpf/hid_bpf_jmp_table.c > > f5c27da4e3c8a2 Benjamin Tissoires 2022-11-03 501 > 0baef37335dd4d Benjamin Tissoires 2022-11-03 @502 void call_hid_bpf_prog_put_deferred(struct work_struct *work) > f5c27da4e3c8a2 Benjamin Tissoires 2022-11-03 503 { > ade9207f04dc40 Benjamin Tissoires 2023-01-06 504 /* kept around for patch readability, to be dropped in the next commmit */ > f5c27da4e3c8a2 Benjamin Tissoires 2022-11-03 505 } > f5c27da4e3c8a2 Benjamin Tissoires 2022-11-03 506 > Oops, this function should have been dropped in 8/9 "HID: bpf: clean up entrypoint". It's now dead code. I'll fix it in v2. Cheers, Benjamin > -- > 0-DAY CI Kernel Test Service > https://github.com/intel/lkp-tests

2 years, 9 months

1
0
0 0

Re: BUG: core dump in selftest of proc fs

by Alexey Dobriyan

On Wed, Jan 04, 2023 at 07:27:40PM +0100, Mirsad Goran Todorovac wrote: > Dear all, > > Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong? > > Or we are having a regression in 6.2-rc2 release candidate ... > > However, the output of selftest run is: > > make[2]: Entering directory '.../linux_torvalds/tools/testing/selftests/proc' > TAP version 13 > 1..21 > # selftests: proc: fd-001-lookup > ok 1 selftests: proc: fd-001-lookup > # selftests: proc: fd-002-posix-eq > ok 2 selftests: proc: fd-002-posix-eq > # selftests: proc: fd-003-kthread > ok 3 selftests: proc: fd-003-kthread > # selftests: proc: proc-loadavg-001 > ok 4 selftests: proc: proc-loadavg-001 > # selftests: proc: proc-empty-vm > # proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed. > # /usr/bin/timeout: the monitored command dumped core > # Aborted > not ok 5 selftests: proc: proc-empty-vm # exit=134 > # selftests: proc: proc-pid-vm > # proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed. > # /usr/bin/timeout: the monitored command dumped core > # Aborted > > Please find attached lshw output, dmesg, config and lsmod. > > I am available for further diagnostics. > > The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop. The "bug" is that "call rel32" instruction testing for executable vsyscall page which should be relocated to "call 0xffffffffff600000" is messed up. Ubuntu 22.10 ships with "vsyscall=xonly" so there should not be any faults when executing from it. But segfault happens with normal randomised userspace address. I'll change it to "call *rax" which should be more robust (and works) and free from relocations.

2 years, 9 months

2
1
0 0

Re: BUG: core dump in selftest of proc fs

by Alexey Dobriyan

On Wed, Jan 04, 2023 at 07:27:40PM +0100, Mirsad Goran Todorovac wrote: > Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong? > > Or we are having a regression in 6.2-rc2 release candidate ... > > However, the output of selftest run is: > # proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed. > # /usr/bin/timeout: the monitored command dumped core > # Aborted > not ok 5 selftests: proc: proc-empty-vm # exit=134 > # selftests: proc: proc-pid-vm > # proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed. > # /usr/bin/timeout: the monitored command dumped core > # Aborted > > Please find attached lshw output, dmesg, config and lsmod. > > I am available for further diagnostics. > > The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop. What the output of "cat /proc/self/maps" ?

2 years, 9 months

2
1
0 0

[PATCH v3 0/2] bpftool: improve error handing for missing .BTF section

by Changbin Du

Display error message for missing ".BTF" section and clean up empty vmlinux.h file. v3: - fix typo and make error message consistent. (Andrii Nakryiko) - split out perf change. v2: - remove vmlinux specific error info. - use builtin target .DELETE_ON_ERROR: to delete empty vmlinux.h Changbin Du (2): libbpf: show error info about missing ".BTF" section bpf: makefiles: do not generate empty vmlinux.h tools/bpf/bpftool/Makefile | 3 +++ tools/lib/bpf/btf.c | 1 + tools/testing/selftests/bpf/Makefile | 3 +++ 3 files changed, 7 insertions(+) -- 2.37.2

2 years, 10 months

5
17
0 0

selftests: tc-testing: tdc.sh - WARNING: inconsistent lock state on arm x15

by Naresh Kamboju

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(a)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/2JrzrHzfFQKu8CwO4A3H… build-url: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc/-/pipelines/7… artifact-location: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3H… toolchain: gcc-10 vmlinux.xz: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3H… System.map: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3H… -- Linaro LKFT https://lkft.linaro.org

2 years, 10 months

1
0
0 0

selftests: netfilter: nft_fib.sh - BUG: spinlock recursion on CPU#0, modprobe/762

by Naresh Kamboju

Following kernel BUG noticed on qemu_arm and BeagleBoard x15 while running selftests: netfilter: nft_fib.sh test case. This is always reproducible on stable-rc 6.1 and 6.0 [1]. Build, config, vmlinux and System.map links provided. unwind: Unknown symbol address bf02e1c8 BUG: spinlock recursion on CPU#0, modprobe/762 lock: unwind_lock+0x0/0x24, .magic: dead4ead, .owner: modprobe/762, .owner_cpu: 0 Reported-by: Linux Kernel Functional Testing <lkft(a)linaro.org> [ 49.898742] kselftest: Running tests in netfilter TAP version 13 1..14 # selftests: netfilter: nft_fib.sh # /dev/stdin:4:10-28: Error: Could not process rule: No such file or directory # fib saddr . iif oif missing counter log prefix \"nsrouter-L7wUUW2r nft_rpfilter: \" drop # ^^^^^^^^^^^^^^^^^^^ # /dev/stdin:4:10-28: Error: Could not process rule: No such file or directory # fib saddr . iif oif missing counter log prefix \"ns1-L7wUUW2r nft_rpfilter: \" drop # ^^^^^^^^^^^^^^^^^^^ # /dev/stdin:4:10-28: Error: Could not process rule: No such file or directory # fib saddr . iif oif missing counter log prefix \"ns2-L7wUUW2r nft_rpfilter: \" drop # ^^^^^^^^^^^^^^^^^^^ [ 55.484253] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 55.569226] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 55.670281] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 55.674377] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready # PASS: fib expression did not cause unwanted packet drops # Error: Could not process rule: No such file or directory # flush table inet filter # ^^^^^^ # /dev/stdin:4:20-38: Error: Could not process rule: No such file or directory # ip daddr 1.1.1.1 fib saddr . iif oif missing counter drop # ^^^^^^^^^^^^^^^^^^^ # /dev/stdin:5:23-41: Error: Could not process rule: No such file or directory # ip6 daddr 1c3::c01d fib saddr . iif oif missing counter drop # ^^^^^^^^^^^^^^^^^^^ # Error: No such file or directory # list table inet filter # ^^^^^^ # Netns nsrouter-L7wUUW2r fib counter doesn't match expected packet count of 0 for 1.1.1.1 # Error: No such file or directory # list table inet filter # ^^^^^^ not ok 1 selftests: netfilter: nft_fib.sh # exit=1 # selftests: netfilter: nft_nat.sh [ 70.428411] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 70.961660] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 70.965547] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready [ 71.027372] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready # /dev/stdin:52:16-40: Error: Could not process rule: No such file or directory # counter name ip saddr map @nsincounter # ^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:53:61-87: Error: Could not process rule: No such file or directory # icmpv6 type { \"echo-request\", \"echo-reply\" } counter name ip6 saddr map @nsincounter6 # ^^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:57:16-41: Error: Could not process rule: No such file or directory # counter name ip daddr map @nsoutcounter # ^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:58:61-88: Error: Could not process rule: No such file or directory # icmpv6 type { \"echo-request\", \"echo-reply\" } counter name ip6 daddr map @nsoutcounter6 # ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:52:16-40: Error: Could not process rule: No such file or directory # counter name ip saddr map @nsincounter # ^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:53:61-87: Error: Could not process rule: No such file or directory # icmpv6 type { \"echo-request\", \"echo-reply\" } counter name ip6 saddr map @nsincounter6 # ^^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:57:16-41: Error: Could not process rule: No such file or directory # counter name ip daddr map @nsoutcounter # ^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:58:61-88: Error: Could not process rule: No such file or directory # icmpv6 type { \"echo-request\", \"echo-reply\" } counter name ip6 daddr map @nsoutcounter6 # ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:52:16-40: Error: Could not process rule: No such file or directory # counter name ip saddr map @nsincounter # ^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:53:61-87: Error: Could not process rule: No such file or directory # icmpv6 type { \"echo-request\", \"echo-reply\" } counter name ip6 saddr map @nsincounter6 # ^^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:57:16-41: Error: Could not process rule: No such file or directory # counter name ip daddr map @nsoutcounter # ^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:58:61-88: Error: Could not process rule: No such file or directory # icmpv6 type { \"echo-request\", \"echo-reply\" } counter name ip6 daddr map @nsoutcounter6 # ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ # /dev/stdin:6:34-42: Error: Could not process rule: No such file or directory # ip saddr 10.0.2.2 counter name \"ns0insl\" # ^^^^^^^^^ # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # ERROR: ns0in counter in ns1-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_counters 1 # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # ERROR: ns0out counter in ns1-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_counters 2 # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # ERROR: ns0in6 counter in ns1-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_counters 3 # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # ERROR: ns0out6 counter in ns1-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_counters 4 # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # ERROR: ns0in counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at check_ns0_counters 1 # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # ERROR: ns0in6 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # ERROR: ns0out counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at check_ns0_counters 2 # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # ERROR: ns0out6 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at check_ns0_counters3 # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns1in # ^^^^^^ # ERROR: ns1in counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_ns0_counters 4 # Error: No such file or directory # list counter inet filter ns1in # ^^^^^^ # Error: No such file or directory # list counter inet filter ns1in6 # ^^^^^^ # ERROR: ns1 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_ns0_counters 5 # Error: No such file or directory # list counter inet filter ns1 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns1out # ^^^^^^ # ERROR: ns1out counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_ns0_counters 4 # Error: No such file or directory # list counter inet filter ns1out # ^^^^^^ # Error: No such file or directory # list counter inet filter ns1out6 # ^^^^^^ # ERROR: ns1 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_ns0_counters 5 # Error: No such file or directory # list counter inet filter ns1 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # ERROR: ns0in counter in ns2-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_counters 1 # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # ERROR: ns0out counter in ns2-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_counters 2 # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # ERROR: ns0in6 counter in ns2-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_counters 3 # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # ERROR: ns0out6 counter in ns2-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_counters 4 # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # ERROR: ns0in counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at check_ns0_counters 1 # Error: No such file or directory # list counter inet filter ns0in # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # ERROR: ns0in6 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at # Error: No such file or directory # list counter inet filter ns0in6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # ERROR: ns0out counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at check_ns0_counters 2 # Error: No such file or directory # list counter inet filter ns0out # ^^^^^^ # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # ERROR: ns0out6 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 0 bytes 0) at check_ns0_counters3 # Error: No such file or directory # list counter inet filter ns0out6 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns2in # ^^^^^^ # ERROR: ns2in counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_ns0_counters 4 # Error: No such file or directory # list counter inet filter ns2in # ^^^^^^ # Error: No such file or directory # list counter inet filter ns2in6 # ^^^^^^ # ERROR: ns2 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_ns0_counters 5 # Error: No such file or directory # list counter inet filter ns2 # ^^^^^^ # Error: No such file or directory # list counter inet filter ns2out # ^^^^^^ # ERROR: ns2out counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 84) at check_ns0_counters 4 # Error: No such file or directory # list counter inet filter ns2out # ^^^^^^ # Error: No such file or directory # list counter inet filter ns2out6 # ^^^^^^ # ERROR: ns2 counter in ns0-0Hc1Kf82 has unexpected value (expected packets 1 bytes 104) at check_ns0_counters 5 # Error: No such file or directory # list counter inet filter ns2 # ^^^^^^ [ 92.417219] unwind: Unknown symbol address bf02e1c8 [ 92.417611] BUG: spinlock recursion on CPU#0, modprobe/762 [ 92.417622] lock: unwind_lock+0x0/0x24, .magic: dead4ead, .owner: modprobe/762, .owner_cpu: 0 [ 92.417649] CPU: 0 PID: 762 Comm: modprobe Not tainted 6.1.4-rc1 #1 [ 92.417657] Hardware name: Generic DT based system [ 92.417662] unwind_backtrace from show_stack+0x18/0x1c [ 92.417682] show_stack from dump_stack_lvl+0x58/0x70 [ 92.417703] dump_stack_lvl from do_raw_spin_lock+0xcc/0xf0 [ 92.417719] do_raw_spin_lock from _raw_spin_lock_irqsave+0x60/0x74 [ 92.417740] _raw_spin_lock_irqsave from unwind_frame+0x470/0x840 [ 92.417760] unwind_frame from __save_stack_trace+0xa4/0xe0 [ 92.417775] __save_stack_trace from stack_trace_save+0x40/0x60 [ 92.417792] stack_trace_save from save_trace+0x50/0x410 [ 92.417805] save_trace from __lock_acquire+0x16dc/0x2a8c [ 92.417815] __lock_acquire from lock_acquire+0x110/0x364 [ 92.417826] lock_acquire from _raw_spin_lock_irqsave+0x58/0x74 [ 92.417847] _raw_spin_lock_irqsave from down_trylock+0x14/0x34 [ 92.417872] down_trylock from __down_trylock_console_sem+0x30/0x98 [ 92.417894] __down_trylock_console_sem from vprintk_emit+0x98/0x35c [ 92.417914] vprintk_emit from vprintk_default+0x28/0x30 [ 92.417933] vprintk_default from _printk+0x30/0x54 [ 92.417954] _printk from search_index+0xcc/0xd8 [ 92.417974] search_index from unwind_frame+0x630/0x840 [ 92.417989] unwind_frame from __save_stack_trace+0xa4/0xe0 [ 92.417999] __save_stack_trace from stack_trace_save+0x40/0x60 [ 92.418021] stack_trace_save from set_track_prepare+0x2c/0x58 [ 92.418044] set_track_prepare from free_debug_processing+0x380/0x61c [ 92.418063] free_debug_processing from kmem_cache_free+0x270/0x45c [ 92.418077] kmem_cache_free from rcu_core+0x3c8/0x1140 [ 92.418093] rcu_core from __do_softirq+0x130/0x538 [ 92.418109] __do_softirq from __irq_exit_rcu+0x14c/0x170 [ 92.418122] __irq_exit_rcu from irq_exit+0x10/0x30 [ 92.418132] irq_exit from call_with_stack+0x18/0x20 [ 92.418146] call_with_stack from __irq_svc+0x9c/0xb8 [ 92.418160] Exception stack(0xf8f59cc0 to 0xf8f59d08) [ 92.418171] 9cc0: c634b108 f8f9e940 0000021c 00034068 00000028 c634b100 00000d01 f8fa7040 [ 92.418180] 9ce0: c634b108 c634b100 c25e54d0 ffffffbf bf02e020 f8f59d10 bf02e304 bf02e1c8 [ 92.418187] 9d00: 200d0113 ffffffff [ 92.418191] __irq_svc from sha1_ce_transform+0x188/0x1bc [sha1_arm_ce] [ 118.427094] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 118.430231] (detected by 1, t=2602 jiffies, g=13749, q=213 ncpus=2) [ 118.433459] rcu: All QSes seen, last rcu_sched kthread activity 2602 (-18164--20766), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 118.438830] rcu: rcu_sched kthread timer wakeup didn't happen for 2601 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 [ 118.444321] rcu: Possible timer handling issue on cpu=0 timer-softirq=3501 [ 118.447958] rcu: rcu_sched kthread starved for 2602 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0 [ 118.453202] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior. [ 118.457584] rcu: RCU grace-period kthread stack dump: [ 118.460282] task:rcu_sched state:R stack:0 pid:14 ppid:2 flags:0x00000000 [ 118.464277] __schedule from schedule+0x60/0x100 [ 118.466571] schedule from schedule_timeout+0xbc/0x20c [ 118.469192] schedule_timeout from rcu_gp_fqs_loop+0x180/0x8d0 [ 118.472165] rcu_gp_fqs_loop from rcu_gp_kthread+0x268/0x3c0 [ 118.475096] rcu_gp_kthread from kthread+0xfc/0x11c [ 118.477675] kthread from ret_from_fork+0x14/0x2c [ 118.479938] Exception stack(0xf0871fb0 to 0xf0871ff8) [ 118.482620] 1fa0: 00000000 00000000 00000000 00000000 [ 118.486777] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 118.490778] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 118.494227] rcu: Stack dump where RCU GP kthread last ran: [ 118.496920] Sending NMI from CPU 1 to CPUs 0: [ 196.487089] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 196.490069] (detected by 1, t=10408 jiffies, g=13749, q=291 ncpus=2) [ 196.493125] rcu: All QSes seen, last rcu_sched kthread activity 10408 (-10358--20766), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 196.498543] rcu: rcu_sched kthread timer wakeup didn't happen for 10407 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 [ 196.503820] rcu: Possible timer handling issue on cpu=0 timer-softirq=3501 [ 196.507068] rcu: rcu_sched kthread starved for 10408 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0 [ 196.511845] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior. [ 196.515998] rcu: RCU grace-period kthread stack dump: [ 196.518341] task:rcu_sched state:R stack:0 pid:14 ppid:2 flags:0x00000000 [ 196.522212] __schedule from schedule+0x60/0x100 [ 196.524392] schedule from schedule_timeout+0xbc/0x20c [ 196.526793] schedule_timeout from rcu_gp_fqs_loop+0x180/0x8d0 [ 196.529554] rcu_gp_fqs_loop from rcu_gp_kthread+0x268/0x3c0 [ 196.532231] rcu_gp_kthread from kthread+0xfc/0x11c [ 196.534515] kthread from ret_from_fork+0x14/0x2c [ 196.536814] Exception stack(0xf0871fb0 to 0xf0871ff8) [ 196.539163] 1fa0: 00000000 00000000 00000000 00000000 [ 196.542933] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 196.546718] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 196.549759] rcu: Stack dump where RCU GP kthread last ran: [ 196.552305] Sending NMI from CPU 1 to CPUs 0: [ 274.537090] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 274.539913] (detected by 1, t=18213 jiffies, g=13749, q=294 ncpus=2) [ 274.542844] rcu: All QSes seen, last rcu_sched kthread activity 18213 (-2553--20766), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 274.548052] rcu: rcu_sched kthread timer wakeup didn't happen for 18212 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 [ 274.553130] rcu: Possible timer handling issue on cpu=0 timer-softirq=3501 [ 274.556276] rcu: rcu_sched kthread starved for 18213 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0 [ 274.560932] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior. [ 274.564906] rcu: RCU grace-period kthread stack dump: [ 274.567183] task:rcu_sched state:R stack:0 pid:14 ppid:2 flags:0x00000000 [ 274.570945] __schedule from schedule+0x60/0x100 [ 274.573114] schedule from schedule_timeout+0xbc/0x20c [ 274.575482] schedule_timeout from rcu_gp_fqs_loop+0x180/0x8d0 [ 274.578110] rcu_gp_fqs_loop from rcu_gp_kthread+0x268/0x3c0 [ 274.580685] rcu_gp_kthread from kthread+0xfc/0x11c [ 274.582907] kthread from ret_from_fork+0x14/0x2c [ 274.585072] Exception stack(0xf0871fb0 to 0xf0871ff8) [ 274.587375] 1fa0: 00000000 00000000 00000000 00000000 [ 274.591035] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 274.594733] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 274.597716] rcu: Stack dump where RCU GP kthread last ran: [ 274.600211] Sending NMI from CPU 1 to CPUs 0: [ 352.587095] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 352.589951] (detected by 1, t=26018 jiffies, g=13749, q=302 ncpus=2) [ 352.592812] rcu: All QSes seen, last rcu_sched kthread activity 26018 (5252--20766), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 352.597854] rcu: rcu_sched kthread timer wakeup didn't happen for 26017 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 [ 352.603086] rcu: Possible timer handling issue on cpu=0 timer-softirq=3501 [ 352.606120] rcu: rcu_sched kthread starved for 26018 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0 [ 352.610625] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior. [ 352.614522] rcu: RCU grace-period kthread stack dump: [ 352.616787] task:rcu_sched state:R stack:0 pid:14 ppid:2 flags:0x00000000 [ 352.620470] __schedule from schedule+0x60/0x100 [ 352.622642] schedule from schedule_timeout+0xbc/0x20c [ 352.625133] schedule_timeout from rcu_gp_fqs_loop+0x180/0x8d0 [ 352.627944] rcu_gp_fqs_loop from rcu_gp_kthread+0x268/0x3c0 [ 352.630522] rcu_gp_kthread from kthread+0xfc/0x11c [ 352.632711] kthread from ret_from_fork+0x14/0x2c [ 352.634870] Exception stack(0xf0871fb0 to 0xf0871ff8) [ 352.637127] 1fa0: 00000000 00000000 00000000 00000000 [ 352.640687] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 352.644262] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 352.647148] rcu: Stack dump where RCU GP kthread last ran: [ 352.649559] Sending NMI from CPU 1 to CPUs 0: [ 430.637222] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 430.640203] (detected by 1, t=33823 jiffies, g=13749, q=314 ncpus=2) [ 430.643245] rcu: All QSes seen, last rcu_sched kthread activity 33823 (13057--20766), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 430.648624] rcu: rcu_sched kthread timer wakeup didn't happen for 33822 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 [ 430.653861] rcu: Possible timer handling issue on cpu=0 timer-softirq=3501 [ 430.657085] rcu: rcu_sched kthread starved for 33823 jiffies! g13749 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0 [ 430.661780] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior. [ 430.665876] rcu: RCU grace-period kthread stack dump: [ 430.668225] task:rcu_sched state:R stack:0 pid:14 ppid:2 flags:0x00000000 [ 430.672089] __schedule from schedule+0x60/0x100 [ 430.674294] schedule from schedule_timeout+0xbc/0x20c [ 430.676805] schedule_timeout from rcu_gp_fqs_loop+0x180/0x8d0 [ 430.679569] rcu_gp_fqs_loop from rcu_gp_kthread+0x268/0x3c0 [ 430.682281] rcu_gp_kthread from kthread+0xfc/0x11c [ 430.684608] kthread from ret_from_fork+0x14/0x2c [ 430.686809] Exception stack(0xf0871fb0 to 0xf0871ff8) [ 430.689211] 1fa0: 00000000 00000000 00000000 00000000 [ 430.692951] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 430.696735] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 430.699829] rcu: Stack dump where RCU GP kthread last ran: [ 430.702415] Sending NMI from CPU 1 to CPUs 0: [1] https://lkft.validation.linaro.org/scheduler/job/6022385#L1224 https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-6.1.y/build/v6.1.3… https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-6.1.y/build/v6.1.3… 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/2JrzrHzfFQKu8CwO4A3H… build-url: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc/-/pipelines/7… artifact-location: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3H… toolchain: gcc-10 vmlinux.xz: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3H… System.map: https://storage.tuxsuite.com/public/linaro/lkft/builds/2JrzrHzfFQKu8CwO4A3H… -- Linaro LKFT https://lkft.linaro.org

2 years, 10 months

1
0
0 0

Re: [PATCH v4 1/9] KVM: s390: Extend MEM_OP ioctl by storage key checked cmpxchg

by Janis Schoetterl-Glausch

On Wed, 2022-12-14 at 10:23 +0800, kernel test robot wrote: > Hi Janis, > > Thank you for the patch! Yet something to improve: > > [auto build test ERROR on 739ad2e4e15b585a0eaf98b7bdee62b2dd9588c9] > > url: https://github.com/intel-lab-lkp/linux/commits/Janis-Schoetterl-Glausch/KVM… > base: 739ad2e4e15b585a0eaf98b7bdee62b2dd9588c9 > patch link: https://lore.kernel.org/r/20221213165405.2953539-2-scgl%40linux.ibm.com > patch subject: [PATCH v4 1/9] KVM: s390: Extend MEM_OP ioctl by storage key checked cmpxchg > config: s390-randconfig-r004-20221213 > compiler: s390-linux-gcc (GCC) 12.1.0 > reproduce (this is a W=1 build): > wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross > chmod +x ~/bin/make.cross > # https://github.com/intel-lab-lkp/linux/commit/4e0991bd47ba30c7588e042da7a84… > git remote add linux-review https://github.com/intel-lab-lkp/linux > git fetch --no-tags linux-review Janis-Schoetterl-Glausch/KVM-s390-Extend-MEM_OP-ioctl-by-storage-key-checked-cmpxchg/20221214-005540 > git checkout 4e0991bd47ba30c7588e042da7a84d84b9f84056 > # save the config file > mkdir build_dir && cp config build_dir/.config > COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-12.1.0 make.cross W=1 O=build_dir ARCH=s390 SHELL=/bin/bash > > If you fix the issue, kindly add following tag where applicable > > Reported-by: kernel test robot <lkp(a)intel.com> > > All errors (new ones prefixed by >>): > > s390-linux-ld: arch/s390/kvm/gaccess.o: in function `__cmpxchg_user_key': > > > arch/s390/include/asm/uaccess.h:410: undefined reference to `__ashlti3' > > > s390-linux-ld: arch/s390/include/asm/uaccess.h:411: undefined reference to `__ashlti3' > s390-linux-ld: arch/s390/include/asm/uaccess.h:458: undefined reference to `__ashlti3' > s390-linux-ld: arch/s390/include/asm/uaccess.h:459: undefined reference to `__ashlti3' > > > vim +410 arch/s390/include/asm/uaccess.h > > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 396 > 4148575abe1e14 Heiko Carstens 2022-11-02 397 static __always_inline int __cmpxchg_user_key(unsigned long address, void *uval, > 4148575abe1e14 Heiko Carstens 2022-11-02 398 __uint128_t old, __uint128_t new, > 4148575abe1e14 Heiko Carstens 2022-11-02 399 unsigned long key, int size) > 4148575abe1e14 Heiko Carstens 2022-11-02 400 { > 4148575abe1e14 Heiko Carstens 2022-11-02 401 int rc = 0; > 4148575abe1e14 Heiko Carstens 2022-11-02 402 > 4148575abe1e14 Heiko Carstens 2022-11-02 403 switch (size) { > 4148575abe1e14 Heiko Carstens 2022-11-02 404 case 1: { > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 405 unsigned int prev, shift, mask, _old, _new; > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 406 unsigned long count; > 4148575abe1e14 Heiko Carstens 2022-11-02 407 > 4148575abe1e14 Heiko Carstens 2022-11-02 408 shift = (3 ^ (address & 3)) << 3; > 4148575abe1e14 Heiko Carstens 2022-11-02 409 address ^= address & 3; > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 @410 _old = (old & 0xff) << shift; > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 @411 _new = (new & 0xff) << shift; Not sure what it is in this config that causes gcc to emit this symbol instead of a shift instruction, but casting old/new to 32 bit fixes the error. > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 412 mask = ~(0xff << shift); > 4148575abe1e14 Heiko Carstens 2022-11-02 413 asm volatile( > 4148575abe1e14 Heiko Carstens 2022-11-02 414 " spka 0(%[key])\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 415 " sacf 256\n" > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 416 " llill %[count],%[max_loops]\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 417 "0: l %[prev],%[address]\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 418 "1: nr %[prev],%[mask]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 419 " xilf %[mask],0xffffffff\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 420 " or %[new],%[prev]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 421 " or %[prev],%[tmp]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 422 "2: lr %[tmp],%[prev]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 423 "3: cs %[prev],%[new],%[address]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 424 "4: jnl 5f\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 425 " xr %[tmp],%[prev]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 426 " xr %[new],%[tmp]\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 427 " nr %[tmp],%[mask]\n" > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 428 " jnz 5f\n" > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 429 " brct %[count],2b\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 430 "5: sacf 768\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 431 " spka %[default_key]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 432 EX_TABLE_UA_LOAD_REG(0b, 5b, %[rc], %[prev]) > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 433 EX_TABLE_UA_LOAD_REG(1b, 5b, %[rc], %[prev]) > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 434 EX_TABLE_UA_LOAD_REG(3b, 5b, %[rc], %[prev]) > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 435 EX_TABLE_UA_LOAD_REG(4b, 5b, %[rc], %[prev]) > 4148575abe1e14 Heiko Carstens 2022-11-02 436 : [rc] "+&d" (rc), > 4148575abe1e14 Heiko Carstens 2022-11-02 437 [prev] "=&d" (prev), > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 438 [address] "+Q" (*(int *)address), > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 439 [tmp] "+&d" (_old), > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 440 [new] "+&d" (_new), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 441 [mask] "+&d" (mask), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 442 [count] "=a" (count) > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 443 : [key] "%[count]" (key << 4), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 444 [default_key] "J" (PAGE_DEFAULT_KEY), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 445 [max_loops] "J" (CMPXCHG_USER_KEY_MAX_LOOPS) > 4148575abe1e14 Heiko Carstens 2022-11-02 446 : "memory", "cc"); > 4148575abe1e14 Heiko Carstens 2022-11-02 447 *(unsigned char *)uval = prev >> shift; > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 448 if (!count) > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 449 rc = -EAGAIN; > 4148575abe1e14 Heiko Carstens 2022-11-02 450 return rc; > 4148575abe1e14 Heiko Carstens 2022-11-02 451 } > 4148575abe1e14 Heiko Carstens 2022-11-02 452 case 2: { > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 453 unsigned int prev, shift, mask, _old, _new; > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 454 unsigned long count; > 4148575abe1e14 Heiko Carstens 2022-11-02 455 > 4148575abe1e14 Heiko Carstens 2022-11-02 456 shift = (2 ^ (address & 2)) << 3; > 4148575abe1e14 Heiko Carstens 2022-11-02 457 address ^= address & 2; > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 458 _old = (old & 0xffff) << shift; > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 459 _new = (new & 0xffff) << shift; Same here. > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 460 mask = ~(0xffff << shift); > 4148575abe1e14 Heiko Carstens 2022-11-02 461 asm volatile( > 4148575abe1e14 Heiko Carstens 2022-11-02 462 " spka 0(%[key])\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 463 " sacf 256\n" > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 464 " llill %[count],%[max_loops]\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 465 "0: l %[prev],%[address]\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 466 "1: nr %[prev],%[mask]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 467 " xilf %[mask],0xffffffff\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 468 " or %[new],%[prev]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 469 " or %[prev],%[tmp]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 470 "2: lr %[tmp],%[prev]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 471 "3: cs %[prev],%[new],%[address]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 472 "4: jnl 5f\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 473 " xr %[tmp],%[prev]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 474 " xr %[new],%[tmp]\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 475 " nr %[tmp],%[mask]\n" > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 476 " jnz 5f\n" > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 477 " brct %[count],2b\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 478 "5: sacf 768\n" > 4148575abe1e14 Heiko Carstens 2022-11-02 479 " spka %[default_key]\n" > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 480 EX_TABLE_UA_LOAD_REG(0b, 5b, %[rc], %[prev]) > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 481 EX_TABLE_UA_LOAD_REG(1b, 5b, %[rc], %[prev]) > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 482 EX_TABLE_UA_LOAD_REG(3b, 5b, %[rc], %[prev]) > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 483 EX_TABLE_UA_LOAD_REG(4b, 5b, %[rc], %[prev]) > 4148575abe1e14 Heiko Carstens 2022-11-02 484 : [rc] "+&d" (rc), > 4148575abe1e14 Heiko Carstens 2022-11-02 485 [prev] "=&d" (prev), > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 486 [address] "+Q" (*(int *)address), > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 487 [tmp] "+&d" (_old), > 51098f0eb22e2f Janis Schoetterl-Glausch 2022-11-16 488 [new] "+&d" (_new), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 489 [mask] "+&d" (mask), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 490 [count] "=a" (count) > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 491 : [key] "%[count]" (key << 4), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 492 [default_key] "J" (PAGE_DEFAULT_KEY), > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 493 [max_loops] "J" (CMPXCHG_USER_KEY_MAX_LOOPS) > 4148575abe1e14 Heiko Carstens 2022-11-02 494 : "memory", "cc"); > 4148575abe1e14 Heiko Carstens 2022-11-02 495 *(unsigned short *)uval = prev >> shift; > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 496 if (!count) > 739ad2e4e15b58 Janis Schoetterl-Glausch 2022-11-17 497 rc = -EAGAIN; > 4148575abe1e14 Heiko Carstens 2022-11-02 498 return rc; [...]

2 years, 10 months

2
1
0 0

Re: PROBLEM: Hang in selftests/netfilter/nft_trans_stress.sh

by Florian Westphal

Mirsad Goran Todorovac <mirsad.todorovac(a)alu.unizg.hr> wrote: > Hi all, > > The `make kselftest` hangs in netfilter/nft_trans_stress.sh test when testing 6.2.0-rc2 > (attempted 2 times, waiting half an hour at least): This script completes in 49 seconds for me. > # selftests: netfilter: nft_trans_stress.sh > # PASS: nft add/delete test returned 0 > # PASS: nft reload test returned 0 > > The test script seems to be stuck in ping flood: No, it gets stuck in the sub-test after 'PASS: nft reload test returned 0' Can you send me the output of 'bash -x nft_trans_stress.sh'? It should tell which command/program isn't making progress.

2 years, 10 months

2
3
0 0

2025

2024

2023

2022

2021

2020

2019

2018

2017

Linux-kselftest-mirror January 2023