ubuntu_kernel_selftests.ftrace timeout on H/riscv

[Kleber Sacilotto de Souza]

ubuntu_kernel_selftests.ftrace times out always after the same step when running on hirsute/linux-riscv on the regression tests infrastructure (QEMU VM).

Log from the tests running with hirsute/linux-riscv 5.11.0-1018.19:

18:02:56 INFO | START ubuntu_kernel_selftests.ftrace ubuntu_kernel_selftests.ftrace timestamp=1629568976 timeout=1800 localtime=Aug 21 18:02:56
18:02:56 DEBUG| Persistent state client._record_indent now set to 2
18:02:56 DEBUG| Persistent state client.unexpected_reboot now set to ('ubuntu_kernel_selftests.ftrace', 'ubuntu_kernel_selftests.ftrace')
18:02:56 DEBUG| Waiting for pid 29328 for 1800 seconds
18:02:56 WARNI| System python is too old, crash handling disabled
18:02:56 DEBUG| Running 'sudo sh -c 'echo 1 > /proc/sys/net/ipv4/conf/all/accept_local''
18:02:56 DEBUG| Running 'sudo make -C linux/tools/testing/selftests TARGETS=ftrace run_tests'
18:02:57 DEBUG| [stdout] make: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests'
18:02:57 DEBUG| [stdout] make --no-builtin-rules ARCH=riscv -C ../../.. headers_install
18:02:57 DEBUG| [stdout] make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux'
18:03:13 DEBUG| [stdout] INSTALL ./usr/include
18:03:14 DEBUG| [stdout] make[1]: Leaving directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux'
18:03:14 DEBUG| [stdout] make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
18:03:14 DEBUG| [stdout] make[1]: Nothing to be done for 'all'.
18:03:14 DEBUG| [stdout] make[1]: Leaving directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
18:03:15 DEBUG| [stdout] make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
18:03:15 DEBUG| [stdout] TAP version 13
18:03:15 DEBUG| [stdout] 1..1
18:03:15 DEBUG| [stdout] # selftests: ftrace: ftracetest
18:03:15 ERROR| [stderr] perl: warning: Setting locale failed.
18:03:15 ERROR| [stderr] perl: warning: Please check that your locale settings:
18:03:15 ERROR| [stderr] LANGUAGE = (unset),
18:03:15 ERROR| [stderr] LC_ALL = (unset),
18:03:15 ERROR| [stderr] LC_CTYPE = "C.UTF-8",
18:03:15 ERROR| [stderr] LANG = "en_US.UTF-8"
18:03:15 ERROR| [stderr] are supported and installed on your system.
18:03:15 ERROR| [stderr] perl: warning: Falling back to the standard locale ("C").
18:03:16 DEBUG| [stdout] # === Ftrace unit tests ===
18:03:21 DEBUG| [stdout] # [1] Basic trace file check [PASS]
18:03:58 DEBUG| [stdout] # [2] Basic test for tracers [PASS]
18:04:04 DEBUG| [stdout] # [3] Basic trace clock test [PASS]
18:04:10 DEBUG| [stdout] # [4] Basic event tracing check [PASS]
18:04:16 DEBUG| [stdout] # [5] Change the ringbuffer size [PASS]
18:04:21 DEBUG| [stdout] # [6] Snapshot and tracing setting [PASS]
18:04:27 DEBUG| [stdout] # [7] trace_pipe and trace_marker [PASS]
18:04:32 DEBUG| [stdout] # [8] Test ftrace direct functions against tracers [UNRESOLVED]
18:04:33 DEBUG| [stdout] # [9] Test ftrace direct functions against kprobes [UNSUPPORTED]
18:04:38 DEBUG| [stdout] # [10] Generic dynamic event - add/remove kprobe events [FAIL]
18:04:39 DEBUG| [stdout] # [11] Generic dynamic event - add/remove synthetic events [UNSUPPORTED]
18:04:39 DEBUG| [stdout] # [12] Generic dynamic event - selective clear (compatibility) [UNSUPPORTED]
18:04:40 DEBUG| [stdout] # [13] Generic dynamic event - generic clear event [UNSUPPORTED]
18:04:46 DEBUG| [stdout] # [14] event tracing - enable/disable with event level files [PASS]
18:04:54 DEBUG| [stdout] # [15] event tracing - restricts events based on pid notrace filtering [PASS]
18:05:00 DEBUG| [stdout] # [16] event tracing - restricts events based on pid [PASS]
18:05:07 DEBUG| [stdout] # [17] event tracing - enable/disable with subsystem level files [PASS]
18:05:14 DEBUG| [stdout] # [18] event tracing - enable/disable with top level files [PASS]
18:05:21 DEBUG| [stdout] # [19] Test trace_printk from module [PASS]
18:05:39 DEBUG| [stdout] # [20] ftrace - function graph filters with stack tracer [PASS]
18:05:50 DEBUG| [stdout] # [21] ftrace - function graph filters [PASS]
18:06:04 DEBUG| [stdout] # [22] ftrace - function pid notrace filters [PASS]
18:06:18 DEBUG| [stdout] # [23] ftrace - function pid filters [PASS]
18:06:28 DEBUG| [stdout] # [24] ftrace - stacktrace filter command [PASS]
18:06:38 DEBUG| [stdout] # [25] ftrace - function trace with cpumask [PASS]
18:07:09 DEBUG| [stdout] # [26] ftrace - test for function event triggers [FAIL]
18:07:28 DEBUG| [stdout] # [27] ftrace - function trace on module [PASS]
18:07:37 INFO | Timer expired (1800 sec.), nuking pid 29328
18:07:37 INFO | ERROR ubuntu_kernel_selftests.ftrace ubuntu_kernel_selftests.ftrace timestamp=1629569257 localtime=Aug 21 18:07:37 Unhandled AutoservRunError: Could not kill 29328
  None
  Traceback (most recent call last):
    File "/home/ubuntu/autotest/client/job.py", line 510, in _runtest
      parallel.fork_waitfor_timed(self.resultdir, pid, timeout)
    File "/home/ubuntu/autotest/client/parallel.py", line 112, in fork_waitfor_timed
      utils.nuke_pid(pid)
    File "/home/ubuntu/autotest/client/shared/utils.py", line 1214, in nuke_pid
      raise error.AutoservRunError('Could not kill %d' % pid, None)
  AutoservRunError: Could not kill 29328
  None

18:07:37 INFO | END ERROR ubuntu_kernel_selftests.ftrace ubuntu_kernel_selftests.ftrace timestamp=1629569257 localtime=Aug 21 18:07:37

For reference, the two failures are reported on bug 1923682 and bug 1923683.

[Brian Murray (brian-murray)]

The Hirsute Hippo has reached End of Life, so this bug will not be fixed for that release.

[Po-Hsu Lin (cypressyew)]

This is because of bug 1940971, autotest timeout is not working as expected on RISCV kernel.

Workaround is to disable the timeout for this test on RISCV:
https://git.launchpad.net/~canonical-kernel-team/+git/autotest-client-tests/commit/?id=0170e2de7083e6e1d8ca4b3ad92c3f059889b69c