ubuntu_kernel_selftests ftrace fails

Bug #1830084 reported by Sean Feole on 2019-05-22
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
ubuntu-kernel-tests
Undecided
Unassigned
linux-aws (Ubuntu)
Undecided
Unassigned
Disco
Undecided
Unassigned
linux-azure (Ubuntu)
Undecided
Unassigned
Disco
Undecided
Unassigned
linux-gcp (Ubuntu)
Undecided
Unassigned
Disco
Undecided
Unassigned

Bug Description

Cloud: Azure
Series: Disco
Kernel: 5.0.0-1007.7 linux-azure
Instance: Standard_D2_v3 and others.

05/20 14:24:27 DEBUG| utils:0116| Running 'sudo sh -c 'echo 1 > /proc/sys/net/ipv4/conf/all/accept_local''
05/20 14:24:27 DEBUG| utils:0116| Running 'sudo make -C linux/tools/testing/selftests TARGETS=ftrace run_tests'
05/20 14:24:27 DEBUG| utils:0153| [stdout] make: Entering directory '/home/azure/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests'
05/20 14:24:27 DEBUG| utils:0153| [stdout] make[1]: Entering directory '/home/azure/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
05/20 14:24:27 DEBUG| utils:0153| [stdout] make[1]: Nothing to be done for 'all'.
05/20 14:24:27 DEBUG| utils:0153| [stdout] make[1]: Leaving directory '/home/azure/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
05/20 14:24:27 DEBUG| utils:0153| [stdout] make[1]: Entering directory '/home/azure/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
05/20 14:24:27 DEBUG| utils:0153| [stdout] TAP version 13
05/20 14:24:27 DEBUG| utils:0153| [stdout] selftests: ftrace: ftracetest
05/20 14:24:27 DEBUG| utils:0153| [stdout] ========================================
05/20 14:24:27 ERROR| utils:0153| [stderr] ./ftracetest: 163: [: Illegal number:
05/20 14:24:27 DEBUG| utils:0153| [stdout] -e === Ftrace unit tests ===
05/20 14:24:27 DEBUG| utils:0153| [stdout] -e -n [1] Basic trace file check
05/20 14:24:27 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:27 DEBUG| utils:0153| [stdout] -e -n [2] Basic test for tracers
05/20 14:24:31 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:31 DEBUG| utils:0153| [stdout] -e -n [3] Basic trace clock test
05/20 14:24:32 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:32 DEBUG| utils:0153| [stdout] -e -n [4] Basic event tracing check
05/20 14:24:32 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:32 DEBUG| utils:0153| [stdout] -e -n [5] Change the ringbuffer size
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e -n [6] Snapshot and tracing setting
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e -n [7] trace_pipe and trace_marker
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e -n [8] Generic dynamic event - add/remove kprobe events
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e -n [9] Generic dynamic event - add/remove synthetic events
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:33 DEBUG| utils:0153| [stdout] -e -n [10] Generic dynamic event - selective clear (compatibility)
05/20 14:24:34 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:34 DEBUG| utils:0153| [stdout] -e -n [11] Generic dynamic event - generic clear event
05/20 14:24:34 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:34 DEBUG| utils:0153| [stdout] -e -n [12] event tracing - enable/disable with event level files
05/20 14:24:34 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:34 DEBUG| utils:0153| [stdout] -e -n [13] event tracing - restricts events based on pid
05/20 14:24:35 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:35 DEBUG| utils:0153| [stdout] -e -n [14] event tracing - enable/disable with subsystem level files
05/20 14:24:35 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:35 DEBUG| utils:0153| [stdout] -e -n [15] event tracing - enable/disable with top level files
05/20 14:24:35 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:35 DEBUG| utils:0153| [stdout] -e -n [16] Test trace_printk from module
05/20 14:24:36 DEBUG| utils:0153| [stdout] -e [UNRESOLVED]
05/20 14:24:36 DEBUG| utils:0153| [stdout] -e -n [17] ftrace - function graph filters with stack tracer
05/20 14:24:38 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:38 DEBUG| utils:0153| [stdout] -e -n [18] ftrace - function graph filters
05/20 14:24:40 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:40 DEBUG| utils:0153| [stdout] -e -n [19] ftrace - function pid filters
05/20 14:24:41 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:41 DEBUG| utils:0153| [stdout] -e -n [20] ftrace - stacktrace filter command
05/20 14:24:42 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:42 DEBUG| utils:0153| [stdout] -e -n [21] ftrace - function trace with cpumask
05/20 14:24:42 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:42 DEBUG| utils:0153| [stdout] -e -n [22] ftrace - test for function event triggers
05/20 14:24:46 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:46 DEBUG| utils:0153| [stdout] -e -n [23] ftrace - function trace on module
05/20 14:24:46 DEBUG| utils:0153| [stdout] -e [UNRESOLVED]
05/20 14:24:46 DEBUG| utils:0153| [stdout] -e -n [24] ftrace - function profiling
05/20 14:24:49 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:49 DEBUG| utils:0153| [stdout] -e -n [25] ftrace - function profiler with function tracing
05/20 14:24:53 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:53 DEBUG| utils:0153| [stdout] -e -n [26] ftrace - test reading of set_ftrace_filter
05/20 14:24:54 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:54 DEBUG| utils:0153| [stdout] -e -n [27] ftrace - test for function traceon/off triggers
05/20 14:24:56 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:56 DEBUG| utils:0153| [stdout] -e -n [28] Test creation and deletion of trace instances while setting an event
05/20 14:24:59 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:24:59 DEBUG| utils:0153| [stdout] -e -n [29] Test creation and deletion of trace instances
05/20 14:25:00 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:00 DEBUG| utils:0153| [stdout] -e -n [30] Kprobe dynamic event - adding and removing
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e -n [31] Kprobe dynamic event - busy event check
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e -n [32] Kprobe dynamic event with arguments
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e -n [33] Kprobe event with comm arguments
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:01 DEBUG| utils:0153| [stdout] -e -n [34] Kprobe event string type argument
05/20 14:25:02 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:02 DEBUG| utils:0153| [stdout] -e -n [35] Kprobe event symbol argument
05/20 14:25:02 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:02 DEBUG| utils:0153| [stdout] -e -n [36] Kprobe event argument syntax
05/20 14:25:03 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:03 DEBUG| utils:0153| [stdout] -e -n [37] Kprobes event arguments with types
05/20 14:25:03 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:03 DEBUG| utils:0153| [stdout] -e -n [38] Kprobe event auto/manual naming
05/20 14:25:04 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:04 DEBUG| utils:0153| [stdout] -e -n [39] Kprobe dynamic event with function tracer
05/20 14:25:04 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:04 DEBUG| utils:0153| [stdout] -e -n [40] Kretprobe dynamic event with arguments
05/20 14:25:05 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:05 DEBUG| utils:0153| [stdout] -e -n [41] Kretprobe dynamic event with maxactive
05/20 14:25:05 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:05 DEBUG| utils:0153| [stdout] -e -n [42] Register/unregister many kprobe events
05/20 14:25:30 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:30 DEBUG| utils:0153| [stdout] -e -n [43] Kprobe dynamic event - adding and removing
05/20 14:25:30 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:30 DEBUG| utils:0153| [stdout] -e -n [44] test for the preemptirqsoff tracer
05/20 14:25:31 DEBUG| utils:0153| [stdout] -e [UNSUPPORTED]
05/20 14:25:31 DEBUG| utils:0153| [stdout] -e -n [45] Test wakeup tracer
05/20 14:25:32 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:32 DEBUG| utils:0153| [stdout] -e -n [46] Test wakeup RT tracer
05/20 14:25:34 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:34 DEBUG| utils:0153| [stdout] -e -n [47] event trigger - test extended error support
05/20 14:25:34 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:34 DEBUG| utils:0153| [stdout] -e -n [48] event trigger - test field variable support
05/20 14:25:37 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:37 DEBUG| utils:0153| [stdout] -e -n [49] event trigger - test multiple actions on hist trigger
05/20 14:25:37 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:37 DEBUG| utils:0153| [stdout] -e -n [50] event trigger - test inter-event histogram trigger onmatch action
05/20 14:25:42 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:42 DEBUG| utils:0153| [stdout] -e -n [51] event trigger - test inter-event histogram trigger onmatch-onmax action
05/20 14:25:47 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:47 DEBUG| utils:0153| [stdout] -e -n [52] event trigger - test inter-event histogram trigger onmax action
05/20 14:25:49 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:49 DEBUG| utils:0153| [stdout] -e -n [53] event trigger - test synthetic_events syntax parser
05/20 14:25:50 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:50 DEBUG| utils:0153| [stdout] -e -n [54] event trigger - test event enable/disable trigger
05/20 14:25:50 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:50 DEBUG| utils:0153| [stdout] -e -n [55] event trigger - test trigger filter
05/20 14:25:51 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:51 DEBUG| utils:0153| [stdout] -e -n [56] event trigger - test histogram modifiers
05/20 14:25:51 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:51 DEBUG| utils:0153| [stdout] -e -n [57] event trigger - test multiple histogram triggers
05/20 14:25:51 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:51 DEBUG| utils:0153| [stdout] -e -n [58] event trigger - test snapshot-trigger
05/20 14:25:52 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:52 DEBUG| utils:0153| [stdout] -e -n [59] event trigger - test stacktrace-trigger
05/20 14:25:52 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:52 DEBUG| utils:0153| [stdout] -e -n [60] trace_marker trigger - test snapshot trigger
05/20 14:25:52 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:52 DEBUG| utils:0153| [stdout] -e -n [61] trace_marker trigger - test histogram with synthetic event against kernel event
05/20 14:25:54 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:54 DEBUG| utils:0153| [stdout] -e -n [62] trace_marker trigger - test histogram with synthetic event
05/20 14:25:54 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:54 DEBUG| utils:0153| [stdout] -e -n [63] event trigger - test traceon/off trigger
05/20 14:25:55 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:55 DEBUG| utils:0153| [stdout] -e -n [64] (instance) Basic test for tracers
05/20 14:25:57 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:57 DEBUG| utils:0153| [stdout] -e -n [65] (instance) Basic trace clock test
05/20 14:25:58 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:58 DEBUG| utils:0153| [stdout] -e -n [66] (instance) Change the ringbuffer size
05/20 14:25:58 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:58 DEBUG| utils:0153| [stdout] -e -n [67] (instance) Snapshot and tracing setting
05/20 14:25:58 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:59 DEBUG| utils:0153| [stdout] -e -n [68] (instance) trace_pipe and trace_marker
05/20 14:25:59 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:59 DEBUG| utils:0153| [stdout] -e -n [69] (instance) event tracing - enable/disable with event level files
05/20 14:25:59 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:25:59 DEBUG| utils:0153| [stdout] -e -n [70] (instance) event tracing - restricts events based on pid
05/20 14:25:59 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:00 DEBUG| utils:0153| [stdout] -e -n [71] (instance) event tracing - enable/disable with subsystem level files
05/20 14:26:00 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:00 DEBUG| utils:0153| [stdout] -e -n [72] (instance) ftrace - stacktrace filter command
05/20 14:26:01 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:01 DEBUG| utils:0153| [stdout] -e -n [73] (instance) ftrace - test for function event triggers
05/20 14:26:04 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:04 DEBUG| utils:0153| [stdout] -e -n [74] (instance) ftrace - test for function traceon/off triggers
05/20 14:26:06 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:06 DEBUG| utils:0153| [stdout] -e -n [75] (instance) event trigger - test event enable/disable trigger
05/20 14:26:06 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:06 DEBUG| utils:0153| [stdout] -e -n [76] (instance) event trigger - test trigger filter
05/20 14:26:07 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:07 DEBUG| utils:0153| [stdout] -e -n [77] (instance) event trigger - test histogram modifiers
05/20 14:26:07 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:07 DEBUG| utils:0153| [stdout] -e -n [78] (instance) event trigger - test multiple histogram triggers163: [: Illegal number:
05/20 14:26:07 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:07 DEBUG| utils:0153| [stdout] -e -n [79] (instance) trace_marker trigger - test snapshot trigger
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e [PASS]
05/20 14:26:08 DEBUG| utils:0153| [stdout]
05/20 14:26:08 DEBUG| utils:0153| [stdout]
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of passed: 76
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of failed: 0
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of unresolved: 2
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of untested: 0
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of unsupported: 1
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of xfailed: 0
05/20 14:26:08 DEBUG| utils:0153| [stdout] -e # of undefined(test bug): 0
05/20 14:26:08 DEBUG| utils:0153| [stdout] not ok 1..1 selftests: ftrace: ftracetest [FAIL]
05/20 14:26:08 DEBUG| utils:0153| [stdout] make[1]: Leaving directory '/home/azure/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
05/20 14:26:08 DEBUG| utils:0153| [stdout] make: Leaving directory '/home/azure/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests'
05/20 14:26:08 ERROR| test:0414| Exception escaping from test:
Traceback (most recent call last):
  File "/home/azure/autotest/client/shared/test.py", line 411, in _exec
    _call_test_function(self.execute, *p_args, **p_dargs)
  File "/home/azure/autotest/client/shared/test.py", line 823, in _call_test_function
    return func(*args, **dargs)
  File "/home/azure/autotest/client/shared/test.py", line 291, in execute
    postprocess_profiled_run, args, dargs)
  File "/home/azure/autotest/client/shared/test.py", line 212, in _call_run_once
    self.run_once(*args, **dargs)
  File "/home/azure/autotest/client/tests/ubuntu_kernel_selftests/ubuntu_kernel_selftests.py", line 149, in run_once
    raise error.TestError('Test failed for ' + test_name)
TestError: Test failed for ftrace

Sean Feole (sfeole) on 2019-05-22
summary: - ubuntu_kernel_tests ftrace fails on disco, linux-auzre
+ ubuntu_kernel_tests ftrace fails on disco, linux-azure
Changed in linux-azure (Ubuntu):
status: New → Confirmed
Changed in linux-azure (Ubuntu Disco):
status: New → Confirmed
Sean Feole (sfeole) on 2019-07-17
summary: - ubuntu_kernel_tests ftrace fails on disco, linux-azure
+ ubuntu_kernel_tests ftrace fails

On Google, GCP this appears to fail across all of our tested instances.

Looks like that the cause is from the following due to the following

07/16 06:52:00 DEBUG| utils:0153| [stdout] [16] Test trace_printk from module [UNRESOLVED]
07/16 06:52:05 DEBUG| utils:0153| [stdout] [21] ftrace - function trace with cpumask [UNRESOLVED]
07/16 06:52:08 DEBUG| utils:0153| [stdout] [23] ftrace - function trace on module [UNRESOLVED]

Sean Feole (sfeole) wrote :

On GCP trace_printk module can't be found which triggers exit_unresolved

/home/jenkins/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace/test.d/event/trace_printk.tc
+ rmmod trace-printk
rmmod: ERROR: Module trace_printk is not currently loaded
+ :
+ modprobe trace-printk
modprobe: FATAL: Module trace-printk not found in directory /lib/modules/5.0.0-1011-gcp
+ echo No trace-printk sample module - please make CONFIG_SAMPLE_TRACE_PRINTK=m

tags: added: aws gcp sru-20190701
tags: removed: aws
Po-Hsu Lin (cypressyew) wrote :

Issue found on GKE 5.0

summary: - ubuntu_kernel_tests ftrace fails
+ ubuntu_kernel_selftests ftrace fails
tags: added: gke ubuntu-kernel-selftests
Sean Feole (sfeole) on 2019-08-09
tags: added: sru-20190722
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers