Re: [Bug Report] Multiple S390x KUNIT clk failures

[msalter@redhat.com]

On Tue, 2024-05-28 at 16:49 -0400, Audra Mitchell wrote:
> On Tue, May 28, 2024 at 02:49:56PM -0400, Donald Zickus wrote:
> > (trying again without the html part that gmail likes to add.  Apologies)
> > 
> > On Tue, May 28, 2024 at 2:45 PM Donald Zickus <dzickus@redhat.com> wrote:
> > > 
> > > Hi Stephen,
> > > 
> > > On Tue, May 14, 2024 at 6:04 PM Stephen Boyd <sboyd@kernel.org> wrote:
> > > > 
> > > > Quoting Nico Pache (2024-05-14 00:14:24)
> > > > > Hi Stephen,
> > > > > 
> > > > > Yes, we have that commit. This is failing on fedora-ark, so it's
> > > > > constantly updated to match upstream, and the earliest recorded
> > > > > instance of it failing in our environment is v6.1.
> > > > > 
> > > > 
> > > > Please don't top post. I'm unable to run s390 kunit tests in qemu. They
> > > > seem to crash before finishing.
> > > 
> > > 
> > > I am working with Nico on moving this forward.  What can we do to help resolve this?
> 
> Hello all,
> 
> I spent some time last week or so working on debugging these failures and I 
> believe I have found the problem. I reached out to Malk Salter for advice on 
> the best way to move forward with a fix on Friday the 17th, but he was on 
> PTO for the last week. I was waiting for his reply before I replied to this 
> thread. 
> 
> Also as a side note, I also ran into the same issue as Stephen with running
> the kunit tests on s390 QEMU. I did not pursue resolving that issue and
> instead just compiled the test as a module. 
> 
> For clarity, this is what I sent to Mark and were I believe the failure is
> occurring:
> 
> The tests create a pretend clk-gate and use a "fake_reg" to emulate
> the expected behavior of the clk_gate->reg. I added some debug
> statements to the driver and noticed that the reg changes after
> initialization to -1. I also noticed that we call this to read the
> data in the clk-gate->reg:
> 
> static inline u32 clk_gate_readl(struct clk_gate *gate)
> {
>         if (gate->flags & CLK_GATE_BIG_ENDIAN)
>                 return ioread32be(gate->reg);
> 
>         return readl(gate->reg);
> }
> 
> However, it does not look like ioread32be is defined for s390, so

It is defined. arch/s390/include/asm/io.h defines:

   #define __raw_readl	zpci_read_u32

and then includes include/asm-generic/io.h which has:

static inline u32 readl(const volatile void __iomem *addr)
{
	u32 val;

	log_read_mmio(32, addr, _THIS_IP_, _RET_IP_);
	__io_br();
	val = __le32_to_cpu((__le32 __force)__raw_readl(addr));
	__io_ar(val);
	log_post_read_mmio(val, 32, addr, _THIS_IP_, _RET_IP_);
	return val;
}
...
static inline u32 ioread32be(const volatile void __iomem *addr)
{
	return swab32(readl(addr));
}

which should do the right thing (s390 being BE and readl() is for 32-bit LE reads).

But I don't know the s390 compiler or ISA, so I'm not sure where the zpci_load
is coming from.

   
> instead the compiler uses read1 (which becomes zpci_load). I checked
> this by dumping the assembler of the compiled kunit clk-gate_test:
> 
> /root/linux/drivers/clk/clk-gate.c: 29
> 0x13214c9c6 <clk_gate_is_enabled+38>:   tm      33(%r2),4
> 0x13214c9ca <clk_gate_is_enabled+42>:   jne     0x13214ca82
> <clk_gate_is_enabled+226>
> /root/linux/./arch/s390/include/asm/pci_io.h: 64
> 0x13214c9ce <clk_gate_is_enabled+46>:   lghi    %r4,4
> 0x13214c9d2 <clk_gate_is_enabled+50>:   la      %r2,160(%r15)
> 0x13214c9d6 <clk_gate_is_enabled+54>:   brasl   %r14,0x131bbc3f0 <zpci_load>
> 0x13214c9dc <clk_gate_is_enabled+60>:   cije    %r2,0,0x13214ca78
> <clk_gate_is_enabled+216>
> 
> Following up on this, I noticed that if the zpci_load is not
> successful, we will return a -1:
> 
> static inline RETTYPE zpci_read_##RETTYPE(const volatile void __iomem
> *addr)    \
> {
>          \
>         u64 data;
>          \
>         int rc;
>          \
> 
>          \
>         rc = zpci_load(&data, addr, LENGTH);
>          \
>         if (rc)
>          \
>                 data = -1ULL;
>          \
>         return (RETTYPE) data;
>          \
> }
> 
> 
> All this to say, I'm not sure the best way to resolve this problem. We
> need to patch clk_gate_readl() but I am not sure the best way to go
> about doing this for big_endian systems.
> 
> Any recommedations on the best way to resolve this problem is welcomed!
> 
> Thanks in advance!
> 
> -- Audra Mitchell
> 
> 
> > > 
> > > Cheers,
> > > Don
> > > 
> > > > 
> > > > 
> > > >  ./tools/testing/kunit/kunit.py run --kunitconfig=lib/kunit --arch=s390 --cross_compile=/path/to/s390-linux-
> > > > 
> > > > [14:55:10] Starting KUnit Kernel (1/1)...
> > > > [14:55:10] ============================================================
> > > > Running tests with:
> > > > $ qemu-system-s390x -nodefaults -m 1024 -kernel .kunit/arch/s390/boot/bzImage -append 'kunit.enable=1 console=ttyS0 kunit_shutdown=reboot' -no-reboot
> > > > -nographic -serial stdio -machine s390-ccw-virtio -cpu qemu
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ================= example_init (1 subtest) =================
> > > > [14:55:11] [PASSED] example_init_test
> > > > [14:55:11] ================== [PASSED] example_init ===================
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ============= kunit_executor_test (8 subtests) =============
> > > > [14:55:11] [PASSED] parse_filter_test
> > > > [14:55:11] [PASSED] filter_suites_test
> > > > [14:55:11] [PASSED] filter_suites_test_glob_test
> > > > [14:55:11] [PASSED] filter_suites_to_empty_test
> > > > [14:55:11] [PASSED] parse_filter_attr_test
> > > > [14:55:11] [PASSED] filter_attr_test
> > > > [14:55:11] [PASSED] filter_attr_empty_test
> > > > [14:55:11] [PASSED] filter_attr_skip_test
> > > > [14:55:11] [ERROR] Test: kunit_executor_test: Expected test number 1 but found 2
> > > > [14:55:11] =============== [PASSED] kunit_executor_test ===============
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ============ kunit-try-catch-test (2 subtests) =============
> > > > [14:55:11] [PASSED] kunit_test_try_catch_successful_try_no_catch
> > > > [14:55:11] [PASSED] kunit_test_try_catch_unsuccessful_try_does_catch
> > > > [14:55:11] [ERROR] Test: kunit-try-catch-test: Expected test number 1 but found 3
> > > > [14:55:11] ============== [PASSED] kunit-try-catch-test ===============
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ============ kunit-resource-test (12 subtests) =============
> > > > [14:55:11] [PASSED] kunit_resource_test_init_resources
> > > > [14:55:11] [PASSED] kunit_resource_test_alloc_resource
> > > > [14:55:11] [PASSED] kunit_resource_test_destroy_resource
> > > > [14:55:11] [PASSED] kunit_resource_test_remove_resource
> > > > [14:55:11] [PASSED] kunit_resource_test_cleanup_resources
> > > > [14:55:11] [PASSED] kunit_resource_test_proper_free_ordering
> > > > [14:55:11] [PASSED] kunit_resource_test_static
> > > > [14:55:11] [PASSED] kunit_resource_test_named
> > > > [14:55:11] [PASSED] kunit_resource_test_action
> > > > [14:55:11] [PASSED] kunit_resource_test_remove_action
> > > > [14:55:11] [PASSED] kunit_resource_test_release_action
> > > > [14:55:11] [PASSED] kunit_resource_test_action_ordering
> > > > [14:55:11] [ERROR] Test: kunit-resource-test: Expected test number 1 but found 4
> > > > [14:55:11] =============== [PASSED] kunit-resource-test ===============
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] =============== kunit-log-test (2 subtests) ================
> > > > [14:55:11] [PASSED] kunit_log_test
> > > > [14:55:11] [SKIPPED] kunit_log_newline_test
> > > > [14:55:11] [ERROR] Test: kunit-log-test: Expected test number 1 but found 5
> > > > [14:55:11] ================= [PASSED] kunit-log-test ==================
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ================ kunit_status (2 subtests) =================
> > > > [14:55:11] [PASSED] kunit_status_set_failure_test
> > > > [14:55:11] [PASSED] kunit_status_mark_skipped_test
> > > > [14:55:11] [ERROR] Test: kunit_status: Expected test number 1 but found 6
> > > > [14:55:11] ================== [PASSED] kunit_status ===================
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ================ kunit_current (2 subtests) ================
> > > > [14:55:11] [PASSED] kunit_current_test
> > > > [14:55:11] [PASSED] kunit_current_fail_test
> > > > [14:55:11] [ERROR] Test: kunit_current: Expected test number 1 but found 7
> > > > [14:55:11] ================== [PASSED] kunit_current ==================
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ================ kunit_device (3 subtests) =================
> > > > [14:55:11] [PASSED] kunit_device_test
> > > > [14:55:11] [PASSED] kunit_device_cleanup_test
> > > > [14:55:11] [PASSED] kunit_device_driver_test
> > > > [14:55:11] [ERROR] Test: kunit_device: Expected test number 1 but found 8
> > > > [14:55:11] ================== [PASSED] kunit_device ===================
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] ============= string-stream-test (12 subtests) =============
> > > > [14:55:11] [PASSED] string_stream_managed_init_test
> > > > [14:55:11] [PASSED] string_stream_unmanaged_init_test
> > > > [14:55:11] [PASSED] string_stream_managed_free_test
> > > > [14:55:11] [PASSED] string_stream_resource_free_test
> > > > [14:55:11] [PASSED] string_stream_line_add_test
> > > > [14:55:11] [PASSED] string_stream_variable_length_line_test
> > > > [14:55:11] [PASSED] string_stream_append_test
> > > > [14:55:11] [PASSED] string_stream_append_auto_newline_test
> > > > [14:55:11] [PASSED] string_stream_append_empty_string_test
> > > > [14:55:11] [PASSED] string_stream_no_auto_newline_test
> > > > [14:55:11] [PASSED] string_stream_auto_newline_test
> > > > [14:55:11] [PASSED] string_stream_performance_test
> > > > [14:55:11] [ERROR] Test: string-stream-test: Expected test number 1 but found 9
> > > > [14:55:11] =============== [PASSED] string-stream-test ================
> > > > [14:55:11] =============================  =============================
> > > > [14:55:11] =================== example (9 subtests) ===================
> > > > [14:55:11] [PASSED] example_simple_test
> > > > [14:55:11] [SKIPPED] example_skip_test
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11]
> > > > [14:55:11] # example_mark_skipped_test: initializing
> > > > [14:55:11]
> > > > [14:55:11] # example_mark_skipped_test: You should see a line below.
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: example: missing subtest result line!
> > > > [14:55:11]
> > > > [14:55:11] # module: kunit_example_test
> > > > [14:55:11] ==================== [CRASHED] example =====================
> > > > [14:55:11]
> > > > [14:55:11] # example: initializing suite
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11]
> > > > [14:55:11] ======================== [CRASHED]  ========================
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] [ERROR] Test: main: missing expected subtest!
> > > > [14:55:11] [CRASHED]
> > > > [14:55:11] ============================================================
> > > > [14:55:11] Testing complete. Ran 62 tests: passed: 44, crashed: 16, skipped: 2, errors: 25
> > > > The kernel seems to have crashed; you can decode the stack traces with:
> > > > $ scripts/decode_stacktrace.sh .kunit/vmlinux .kunit < .kunit/test.log | tee .kunit/decoded.log | ./tools/testing/kunit/kunit.py parse
> > > > [14:55:11] Elapsed time: 16.240s total, 1.476s configuring, 14.294s building, 0.469s running
> > > > 
> > > > I wonder if something with my local environment is causing troubles.
> > > > 
>