January 2023 - Linux-kselftest-mirror

[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;

1 year, 11 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

1 year, 11 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.

1 year, 11 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" ?

1 year, 11 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

1 year, 11 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

1 year, 11 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

1 year, 11 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; [...]

1 year, 11 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.

1 year, 11 months

2
3
0 0

[PATCH AUTOSEL 6.1 08/10] kunit: alloc_string_stream_fragment error handling bug fix

by Sasha Levin

From: "YoungJun.park" <her0gyugyu(a)gmail.com> [ Upstream commit 93ef83050e597634d2c7dc838a28caf5137b9404 ] When it fails to allocate fragment, it does not free and return error. And check the pointer inappropriately. Fixed merge conflicts with commit 618887768bb7 ("kunit: update NULL vs IS_ERR() tests") Shuah Khan <skhan(a)linuxfoundation.org> Signed-off-by: YoungJun.park <her0gyugyu(a)gmail.com> Reviewed-by: David Gow <davidgow(a)google.com> Signed-off-by: Shuah Khan <skhan(a)linuxfoundation.org> Signed-off-by: Sasha Levin <sashal(a)kernel.org> --- lib/kunit/string-stream.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/lib/kunit/string-stream.c b/lib/kunit/string-stream.c index a608746020a9..7aeabe1a3dc5 100644 --- a/lib/kunit/string-stream.c +++ b/lib/kunit/string-stream.c @@ -23,8 +23,10 @@ static struct string_stream_fragment *alloc_string_stream_fragment( return ERR_PTR(-ENOMEM); frag->fragment = kunit_kmalloc(test, len, gfp); - if (!frag->fragment) + if (!frag->fragment) { + kunit_kfree(test, frag); return ERR_PTR(-ENOMEM); + } return frag; } -- 2.35.1

1 year, 11 months

1
0
0 0

2024

2023

2022

2021

2020

2019

2018

2017

Linux-kselftest-mirror January 2023