← Back to team overview

canonical-ubuntu-qa team mailing list archive

  1. canonical-ubuntu-qa team
  2. Mailing list archive
  3. Message #01960

[Bug 2029405] Re: Change in trace file leads to test timeout in ftrace tests on 5.15 ARM64

  Thread Previous • Date Previous • • Thread Next 
https://lists.ubuntu.com/archives/kernel-team/2023-November/147192.html

** Description changed:

- First time seen this since ftrace refactor out from
- ubuntu_kernel_selftests to ubuntu-kselftests-ftrace
+ 
+ [Impact]
+ On ARM64 systems, tests like event-enable.tc, event-pid.tc in
+ linux/tools/testing/selftests/ftrace will take too much time to run
+ and consequently leading to test timeout.
+ 
+ The culprit is the `cat` command on the changing trace file.
+ 
+ [Fix]
+ * 25b9513872 selftests/ftrace: Stop tracing while reading the trace
+   file by default
+ 
+ This patch can be cherry-picked into Jammy. I didn't see this issue in
+ our 5.4 kernels. And it's already landed in newer kernels.
+ 
+ [Test]
+ On an ARM64 testing node, apply this patch to the kernel tree and run
+ event-pid.tc test in linux/tools/testing/selftests/ftrace with:
+ 
+   sudo ./ftracetest -vvv test.d/event/event-pid.tc
+ 
+ The test should finish within a few minutes.
+ 
+ [Regression Potential]
+ Change limited to testing tools, it should not have any actual impact
+ to kernel functions.
+ 
+ == Original Bug Report ==
+ First time seen this since ftrace refactor out from ubuntu_kernel_selftests to ubuntu-kselftests-ftrace
  
  Issue found on ARM64 nodes with both generic / generic-64k kernel.
  
  Partial test log:
-  Running './ftracetest -vvv test.d/event/subsystem-enable.tc'
-  === Ftrace unit tests ===
-  ....
-  [1] event tracing - enable/disable with event level files
-  + [ 2 -eq 1 ]
-  + [ -f set_event_pid ]
-  + echo
-  + [ -f set_ftrace_pid ]
-  + echo
-  + [ -f set_ftrace_notrace ]
-  + echo
-  + [ -f set_graph_function ]
-  + echo
-  + tee set_graph_function set_graph_notrace 
-  + [ -f stack_trace_filter ]
-  + echo
-  + [ -f kprobe_events ]
-  + echo
-  + [ -f uprobe_events ]
-  + echo
-  + [ -f synthetic_events ]
-  + echo
-  + [ -f snapshot ]
-  + echo 0
-  + clear_trace
-  + echo
-  + enable_tracing
-  + echo 1
-  + . /home/ubuntu/autotest/client/tmp/ubuntu_kselftests_ftrace/src/linux/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
-  + echo sched:sched_switch
-  + yield
-  + ping 127.0.0.1 -c 1
-  PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
-  64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.096 ms
-  
-  --- 127.0.0.1 ping statistics ---
-  1 packets transmitted, 1 received, 0% packet loss, time 0ms
-  rtt min/avg/max/mdev = 0.096/0.096/0.096/0.000 ms
-  + cat trace
-  + grep sched_switch
-  + wc -l
-  Timer expired (600 sec.), nuking pid 20982
+  Running './ftracetest -vvv test.d/event/subsystem-enable.tc'
+  === Ftrace unit tests ===
+  ....
+  [1] event tracing - enable/disable with event level files
+  + [ 2 -eq 1 ]
+  + [ -f set_event_pid ]
+  + echo
+  + [ -f set_ftrace_pid ]
+  + echo
+  + [ -f set_ftrace_notrace ]
+  + echo
+  + [ -f set_graph_function ]
+  + echo
+  + tee set_graph_function set_graph_notrace
+  + [ -f stack_trace_filter ]
+  + echo
+  + [ -f kprobe_events ]
+  + echo
+  + [ -f uprobe_events ]
+  + echo
+  + [ -f synthetic_events ]
+  + echo
+  + [ -f snapshot ]
+  + echo 0
+  + clear_trace
+  + echo
+  + enable_tracing
+  + echo 1
+  + . /home/ubuntu/autotest/client/tmp/ubuntu_kselftests_ftrace/src/linux/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
+  + echo sched:sched_switch
+  + yield
+  + ping 127.0.0.1 -c 1
+  PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
+  64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.096 ms
+ 
+  --- 127.0.0.1 ping statistics ---
+  1 packets transmitted, 1 received, 0% packet loss, time 0ms
+  rtt min/avg/max/mdev = 0.096/0.096/0.096/0.000 ms
+  + cat trace
+  + grep sched_switch
+  + wc -l
+  Timer expired (600 sec.), nuking pid 20982
  
  From the code (tools/testing/selftests/ftrace/test.d/event/event-
  enable.tc) this test is trying to run:
  
-     count=`cat trace | grep sched_switch | wc -l`
+     count=`cat trace | grep sched_switch | wc -l`
  
  This command caused the timeout as `cat trace` seems to be never ending.

** Description changed:

- 
  [Impact]
- On ARM64 systems, tests like event-enable.tc, event-pid.tc in
- linux/tools/testing/selftests/ftrace will take too much time to run
- and consequently leading to test timeout.
+ On ARM64 systems, tests like subsystem-enable.tc, event-enable.tc,
+ event-pid.tc in linux/tools/testing/selftests/ftrace will take too
+ much time to run and consequently leads to test timeout.
  
  The culprit is the `cat` command on the changing trace file.
  
  [Fix]
  * 25b9513872 selftests/ftrace: Stop tracing while reading the trace
-   file by default
+   file by default
  
  This patch can be cherry-picked into Jammy. I didn't see this issue in
  our 5.4 kernels. And it's already landed in newer kernels.
  
  [Test]
  On an ARM64 testing node, apply this patch to the kernel tree and run
  event-pid.tc test in linux/tools/testing/selftests/ftrace with:
  
-   sudo ./ftracetest -vvv test.d/event/event-pid.tc
+   sudo ./ftracetest -vvv test.d/event/event-pid.tc
  
  The test should finish within a few minutes.
  
  [Regression Potential]
  Change limited to testing tools, it should not have any actual impact
  to kernel functions.
  
  == Original Bug Report ==
  First time seen this since ftrace refactor out from ubuntu_kernel_selftests to ubuntu-kselftests-ftrace
  
  Issue found on ARM64 nodes with both generic / generic-64k kernel.
  
  Partial test log:
   Running './ftracetest -vvv test.d/event/subsystem-enable.tc'
   === Ftrace unit tests ===
   ....
   [1] event tracing - enable/disable with event level files
   + [ 2 -eq 1 ]
   + [ -f set_event_pid ]
   + echo
   + [ -f set_ftrace_pid ]
   + echo
   + [ -f set_ftrace_notrace ]
   + echo
   + [ -f set_graph_function ]
   + echo
   + tee set_graph_function set_graph_notrace
   + [ -f stack_trace_filter ]
   + echo
   + [ -f kprobe_events ]
   + echo
   + [ -f uprobe_events ]
   + echo
   + [ -f synthetic_events ]
   + echo
   + [ -f snapshot ]
   + echo 0
   + clear_trace
   + echo
   + enable_tracing
   + echo 1
   + . /home/ubuntu/autotest/client/tmp/ubuntu_kselftests_ftrace/src/linux/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
   + echo sched:sched_switch
   + yield
   + ping 127.0.0.1 -c 1
   PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
   64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.096 ms
  
   --- 127.0.0.1 ping statistics ---
   1 packets transmitted, 1 received, 0% packet loss, time 0ms
   rtt min/avg/max/mdev = 0.096/0.096/0.096/0.000 ms
   + cat trace
   + grep sched_switch
   + wc -l
   Timer expired (600 sec.), nuking pid 20982
  
  From the code (tools/testing/selftests/ftrace/test.d/event/event-
  enable.tc) this test is trying to run:
  
      count=`cat trace | grep sched_switch | wc -l`
  
  This command caused the timeout as `cat trace` seems to be never ending.

** Tags added: sru-20231030

-- 
You received this bug notification because you are a member of Canonical
Platform QA Team, which is subscribed to ubuntu-kernel-tests.
https://bugs.launchpad.net/bugs/2029405

Title:
  Change in trace file leads to test timeout in ftrace tests on 5.15
  ARM64

Status in ubuntu-kernel-tests:
  In Progress
Status in linux package in Ubuntu:
  Fix Released
Status in linux source package in Jammy:
  In Progress

Bug description:
  [Impact]
  On ARM64 systems, tests like subsystem-enable.tc, event-enable.tc,
  event-pid.tc in linux/tools/testing/selftests/ftrace will take too
  much time to run and consequently leads to test timeout.

  The culprit is the `cat` command on the changing trace file.

  [Fix]
  * 25b9513872 selftests/ftrace: Stop tracing while reading the trace
    file by default

  This patch can be cherry-picked into Jammy. I didn't see this issue in
  our 5.4 kernels. And it's already landed in newer kernels.

  [Test]
  On an ARM64 testing node, apply this patch to the kernel tree and run
  event-pid.tc test in linux/tools/testing/selftests/ftrace with:

    sudo ./ftracetest -vvv test.d/event/event-pid.tc

  The test should finish within a few minutes.

  [Regression Potential]
  Change limited to testing tools, it should not have any actual impact
  to kernel functions.

  == Original Bug Report ==
  First time seen this since ftrace refactor out from ubuntu_kernel_selftests to ubuntu-kselftests-ftrace

  Issue found on ARM64 nodes with both generic / generic-64k kernel.

  Partial test log:
   Running './ftracetest -vvv test.d/event/subsystem-enable.tc'
   === Ftrace unit tests ===
   ....
   [1] event tracing - enable/disable with event level files
   + [ 2 -eq 1 ]
   + [ -f set_event_pid ]
   + echo
   + [ -f set_ftrace_pid ]
   + echo
   + [ -f set_ftrace_notrace ]
   + echo
   + [ -f set_graph_function ]
   + echo
   + tee set_graph_function set_graph_notrace
   + [ -f stack_trace_filter ]
   + echo
   + [ -f kprobe_events ]
   + echo
   + [ -f uprobe_events ]
   + echo
   + [ -f synthetic_events ]
   + echo
   + [ -f snapshot ]
   + echo 0
   + clear_trace
   + echo
   + enable_tracing
   + echo 1
   + . /home/ubuntu/autotest/client/tmp/ubuntu_kselftests_ftrace/src/linux/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
   + echo sched:sched_switch
   + yield
   + ping 127.0.0.1 -c 1
   PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
   64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.096 ms

   --- 127.0.0.1 ping statistics ---
   1 packets transmitted, 1 received, 0% packet loss, time 0ms
   rtt min/avg/max/mdev = 0.096/0.096/0.096/0.000 ms
   + cat trace
   + grep sched_switch
   + wc -l
   Timer expired (600 sec.), nuking pid 20982

  From the code (tools/testing/selftests/ftrace/test.d/event/event-
  enable.tc) this test is trying to run:

      count=`cat trace | grep sched_switch | wc -l`

  This command caused the timeout as `cat trace` seems to be never
  ending.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-kernel-tests/+bug/2029405/+subscriptions
  Thread Previous • Date Previous • • Thread Next