ubuntu_kernel_selftests / ftrace:ftracetest do_softirq failure on Jammy realtime

Bug #1959610 reported by Joseph Salisbury
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
ubuntu-kernel-tests
Fix Released
Undecided
Unassigned
linux (Ubuntu)
Fix Released
Low
Krzysztof Kozlowski
Jammy
Fix Released
Low
Krzysztof Kozlowski

Bug Description

[Impact]

* ubuntu_kernel_selftests / ftrace:ftracetest fails on realtime kernel.

* ftrace:ftracetest which reports: "echo: I/O error". This is caused by using "do_softirq" in test which does not exist on preempt RT kernel.

[Fix]

* Use other function.
* Upstream commit 6fec1ab67f8d ("selftests/ftrace: Do not trace do_softirq because of PREEMPT_RT")

[Test Plan]

* Run the test on regular (base) and realtime kernel.

[Where problems could occur]

* Only ftracetest tests.

[Other info]

Failure is reported for step 32 in Jenkins job:

23:48:45 DEBUG| [stdout] # selftests: ftrace: ftracetest
23:48:45 DEBUG| [stdout] # === Ftrace unit tests ===
23:48:45 DEBUG| [stdout] # [1] Basic trace file check [PASS]
23:48:49 DEBUG| [stdout] # [2] Basic test for tracers [PASS]
23:48:49 DEBUG| [stdout] # [3] Basic trace clock test [PASS]
23:48:49 DEBUG| [stdout] # [4] Basic event tracing check [PASS]
23:48:50 DEBUG| [stdout] # [5] Change the ringbuffer size [PASS]
23:48:50 DEBUG| [stdout] # [6] Snapshot and tracing setting [PASS]
23:48:50 DEBUG| [stdout] # [7] trace_pipe and trace_marker [PASS]
23:49:38 DEBUG| [stdout] # [8] Test ftrace direct functions against tracers [PASS]
23:49:57 DEBUG| [stdout] # [9] Test ftrace direct functions against kprobes [PASS]
23:49:57 DEBUG| [stdout] # [10] Generic dynamic event - add/remove eprobe events [PASS]
23:49:57 DEBUG| [stdout] # [11] Generic dynamic event - add/remove kprobe events [PASS]
23:49:57 DEBUG| [stdout] # [12] Generic dynamic event - add/remove synthetic events [PASS]
23:49:57 DEBUG| [stdout] # [13] Generic dynamic event - selective clear (compatibility) [PASS]
23:49:58 DEBUG| [stdout] # [14] Generic dynamic event - generic clear event [PASS]
23:49:58 DEBUG| [stdout] # [15] Generic dynamic event - check if duplicate events are caught [PASS]
23:49:58 DEBUG| [stdout] # [16] event tracing - enable/disable with event level files [PASS]
23:49:58 DEBUG| [stdout] # [17] event tracing - restricts events based on pid notrace filtering [PASS]
23:49:59 DEBUG| [stdout] # [18] event tracing - restricts events based on pid [PASS]
23:49:59 DEBUG| [stdout] # [19] event tracing - enable/disable with subsystem level files [PASS]
23:50:00 DEBUG| [stdout] # [20] event tracing - enable/disable with top level files [PASS]
23:50:01 DEBUG| [stdout] # [21] Test trace_printk from module [PASS]
23:50:04 DEBUG| [stdout] # [22] ftrace - function graph filters with stack tracer [PASS]
23:50:05 DEBUG| [stdout] # [23] ftrace - function graph filters [PASS]
23:50:06 DEBUG| [stdout] # [24] ftrace - function pid notrace filters [PASS]
23:50:06 DEBUG| [stdout] # [25] ftrace - function pid filters [PASS]
23:50:08 DEBUG| [stdout] # [26] ftrace - stacktrace filter command [PASS]
23:50:08 DEBUG| [stdout] # [27] ftrace - function trace with cpumask [PASS]
23:50:12 DEBUG| [stdout] # [28] ftrace - test for function event triggers [PASS]
23:50:13 DEBUG| [stdout] # [29] ftrace - function trace on module [PASS]
23:50:16 DEBUG| [stdout] # [30] ftrace - function profiling [PASS]
23:50:21 DEBUG| [stdout] # [31] ftrace - function profiler with function tracing [PASS]
23:50:22 DEBUG| [stdout] # [32] ftrace - test reading of set_ftrace_filter [FAIL]
23:50:24 DEBUG| [stdout] # [33] ftrace - test for function traceon/off triggers [PASS]
23:50:24 DEBUG| [stdout] # [34] ftrace - test tracing error log support [PASS]
23:50:28 DEBUG| [stdout] # [35] Test creation and deletion of trace instances while setting an event [PASS]
23:50:29 DEBUG| [stdout] # [36] Test creation and deletion of trace instances [PASS]
23:50:30 DEBUG| [stdout] # [37] Kprobe dynamic event - adding and removing [PASS]
23:50:30 DEBUG| [stdout] # [38] Kprobe dynamic event - busy event check [PASS]
23:50:30 DEBUG| [stdout] # [39] Kprobe dynamic event with arguments [PASS]
23:50:30 DEBUG| [stdout] # [40] Kprobe event with comm arguments [PASS]
23:50:30 DEBUG| [stdout] # [41] Kprobe event string type argument [PASS]
23:50:31 DEBUG| [stdout] # [42] Kprobe event symbol argument [PASS]
23:50:32 DEBUG| [stdout] # [43] Kprobe event argument syntax [PASS]
23:50:32 DEBUG| [stdout] # [44] Kprobes event arguments with types [PASS]
23:50:32 DEBUG| [stdout] # [45] Kprobe event user-memory access [PASS]
23:50:33 DEBUG| [stdout] # [46] Kprobe event auto/manual naming [PASS]
23:50:33 DEBUG| [stdout] # [47] Kprobe dynamic event with function tracer [PASS]
23:50:34 DEBUG| [stdout] # [48] Create/delete multiprobe on kprobe event [PASS]
23:50:34 DEBUG| [stdout] # [49] Kprobe event parser error log check [PASS]
23:50:35 DEBUG| [stdout] # [50] Kretprobe dynamic event with arguments [PASS]
23:50:35 DEBUG| [stdout] # [51] Kretprobe dynamic event with maxactive [PASS]
23:50:35 DEBUG| [stdout] # [52] Kretprobe %return suffix test [PASS]
23:51:00 DEBUG| [stdout] # [53] Register/unregister many kprobe events [PASS]
23:51:00 DEBUG| [stdout] # [54] Kprobe dynamic event - adding and removing [PASS]
23:51:01 DEBUG| [stdout] # [55] Uprobe event parser error log check [PASS]
23:51:01 DEBUG| [stdout] # [56] test for the preemptirqsoff tracer [UNSUPPORTED]
23:51:32 DEBUG| [stdout] # [57] Meta-selftest: Checkbashisms [PASS]
23:51:33 DEBUG| [stdout] # [58] Test wakeup tracer [PASS]
23:51:35 DEBUG| [stdout] # [59] Test wakeup RT tracer [PASS]
23:51:35 DEBUG| [stdout] # [60] event trigger - test inter-event histogram trigger expected fail actions [XFAIL]
23:51:37 DEBUG| [stdout] # [61] event trigger - test field variable support [PASS]
23:51:38 DEBUG| [stdout] # [62] event trigger - test multiple actions on hist trigger [PASS]
23:51:42 DEBUG| [stdout] # [63] event trigger - test inter-event histogram trigger onchange action [PASS]
23:51:46 DEBUG| [stdout] # [64] event trigger - test inter-event histogram trigger onmatch action [PASS]
23:51:51 DEBUG| [stdout] # [65] event trigger - test inter-event histogram trigger onmatch-onmax action [PASS]
23:51:53 DEBUG| [stdout] # [66] event trigger - test inter-event histogram trigger onmax action [PASS]
23:51:58 DEBUG| [stdout] # [67] event trigger - test inter-event histogram trigger snapshot action [PASS]
23:51:58 DEBUG| [stdout] # [68] event trigger - test inter-event histogram trigger eprobe on synthetic event [PASS]
23:52:02 DEBUG| [stdout] # [69] event trigger - test inter-event histogram trigger trace action with dynamic string param [PASS]
23:52:03 DEBUG| [stdout] # [70] event trigger - test synthetic_events syntax parser [PASS]
23:52:03 DEBUG| [stdout] # [71] event trigger - test synthetic_events syntax parser errors [PASS]
23:52:07 DEBUG| [stdout] # [72] event trigger - test inter-event histogram trigger trace action [PASS]
23:52:08 DEBUG| [stdout] # [73] event trigger - test event enable/disable trigger [PASS]
23:52:08 DEBUG| [stdout] # [74] event trigger - test trigger filter [PASS]
23:52:09 DEBUG| [stdout] # [75] event trigger - test histogram modifiers [PASS]
23:52:09 DEBUG| [stdout] # [76] event trigger - test histogram parser errors [PASS]
23:52:09 DEBUG| [stdout] # [77] event trigger - test multiple histogram triggers [PASS]
23:52:09 DEBUG| [stdout] # [78] event trigger - test snapshot-trigger [PASS]
23:52:10 DEBUG| [stdout] # [79] event trigger - test stacktrace-trigger [PASS]
23:52:10 DEBUG| [stdout] # [80] trace_marker trigger - test snapshot trigger [PASS]
23:52:11 DEBUG| [stdout] # [81] trace_marker trigger - test histogram with synthetic event against kernel event [PASS]
23:52:12 DEBUG| [stdout] # [82] trace_marker trigger - test histogram with synthetic event [PASS]
23:52:12 DEBUG| [stdout] # [83] event trigger - test traceon/off trigger [PASS]
23:52:15 DEBUG| [stdout] # [84] (instance) Basic test for tracers [PASS]
23:52:15 DEBUG| [stdout] # [85] (instance) Basic trace clock test [PASS]
23:52:15 DEBUG| [stdout] # [86] (instance) Change the ringbuffer size [PASS]
23:52:16 DEBUG| [stdout] # [87] (instance) Snapshot and tracing setting [PASS]
23:52:16 DEBUG| [stdout] # [88] (instance) trace_pipe and trace_marker [PASS]
23:52:16 DEBUG| [stdout] # [89] (instance) event tracing - enable/disable with event level files [PASS]
23:52:17 DEBUG| [stdout] # [90] (instance) event tracing - restricts events based on pid notrace filtering [PASS]
23:52:17 DEBUG| [stdout] # [91] (instance) event tracing - restricts events based on pid [PASS]
23:52:18 DEBUG| [stdout] # [92] (instance) event tracing - enable/disable with subsystem level files [PASS]
23:52:18 DEBUG| [stdout] # [93] (instance) ftrace - function pid notrace filters [PASS]
23:52:19 DEBUG| [stdout] # [94] (instance) ftrace - function pid filters [PASS]
23:52:21 DEBUG| [stdout] # [95] (instance) ftrace - stacktrace filter command [PASS]
23:52:24 DEBUG| [stdout] # [96] (instance) ftrace - test for function event triggers [PASS]
23:52:26 DEBUG| [stdout] # [97] (instance) ftrace - test for function traceon/off triggers [PASS]
23:52:26 DEBUG| [stdout] # [98] (instance) event trigger - test event enable/disable trigger [PASS]
23:52:27 DEBUG| [stdout] # [99] (instance) event trigger - test trigger filter [PASS]
23:52:27 DEBUG| [stdout] # [100] (instance) event trigger - test histogram modifiers [PASS]
23:52:28 DEBUG| [stdout] # [101] (instance) event trigger - test multiple histogram triggers [PASS]
23:52:28 DEBUG| [stdout] # [102] (instance) trace_marker trigger - test snapshot trigger [PASS]
23:52:28 DEBUG| [stdout] #
23:52:28 DEBUG| [stdout] #
23:52:28 DEBUG| [stdout] # # of passed: 99
23:52:28 DEBUG| [stdout] # # of failed: 1
23:52:28 DEBUG| [stdout] # # of unresolved: 0
23:52:28 DEBUG| [stdout] # # of untested: 0
23:52:28 DEBUG| [stdout] # # of unsupported: 1
23:52:28 DEBUG| [stdout] # # of xfailed: 1
23:52:28 DEBUG| [stdout] # # of undefined(test bug): 0

Output from running test manually:

+ echo do_softirq
./ftracetest: 81: echo: echo: I/O error

# of passed: 0
# of failed: 1
# of unresolved: 0
# of untested: 0
# of unsupported: 0
# of xfailed: 0
# of undefined(test bug): 0

Revision history for this message
Ubuntu Kernel Bot (ubuntu-kernel-bot) wrote : Missing required logs.

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1959610

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

Changed in linux (Ubuntu):
status: New → Incomplete
Revision history for this message
Krzysztof Kozlowski (krzk) wrote :

Sent fix upstream:
https://lore.kernel<email address hidden>/T/#u
Discussions on-going.

Changed in linux (Ubuntu):
assignee: nobody → Krzysztof Kozlowski (krzk)
status: Incomplete → In Progress
importance: Undecided → Medium
description: updated
tags: added: amd64 ubuntu-kernel-selftests
Revision history for this message
Krzysztof Kozlowski (krzk) wrote :

Sent SRU

Changed in linux (Ubuntu Jammy):
importance: Medium → Low
Changed in linux (Ubuntu Jammy):
status: In Progress → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :
Download full text (67.6 KiB)

This bug was fixed in the package linux - 5.15.0-23.23

---------------
linux (5.15.0-23.23) jammy; urgency=medium

  * jammy/linux: 5.15.0-23.23 -proposed tracker (LP: #1964573)

  * Packaging resync (LP: #1786013)
    - [Packaging] resync dkms-build{,--nvidia-N} from LRMv5
    - debian/dkms-versions -- update from kernel-versions (main/master)

  * [22.04 FEAT] KVM: Enable GISA support for Secure Execution guests
    (LP: #1959977)
    - KVM: s390: pv: make use of ultravisor AIV support

  * intel_iommu breaks Intel IPU6 camera: isys port open ready failed -16
    (LP: #1958004)
    - SAUCE: iommu: intel-ipu: use IOMMU passthrough mode for Intel IPUs

  * CVE-2022-23960
    - ARM: report Spectre v2 status through sysfs
    - ARM: early traps initialisation
    - ARM: use LOADADDR() to get load address of sections
    - ARM: Spectre-BHB workaround
    - ARM: include unprivileged BPF status in Spectre V2 reporting
    - arm64: Add Neoverse-N2, Cortex-A710 CPU part definition
    - arm64: Add HWCAP for self-synchronising virtual counter
    - arm64: Add Cortex-X2 CPU part definition
    - arm64: add ID_AA64ISAR2_EL1 sys register
    - arm64: cpufeature: add HWCAP for FEAT_AFP
    - arm64: cpufeature: add HWCAP for FEAT_RPRES
    - arm64: entry.S: Add ventry overflow sanity checks
    - arm64: spectre: Rename spectre_v4_patch_fw_mitigation_conduit
    - KVM: arm64: Allow indirect vectors to be used without SPECTRE_V3A
    - arm64: entry: Make the trampoline cleanup optional
    - arm64: entry: Free up another register on kpti's tramp_exit path
    - arm64: entry: Move the trampoline data page before the text page
    - arm64: entry: Allow tramp_alias to access symbols after the 4K boundary
    - arm64: entry: Don't assume tramp_vectors is the start of the vectors
    - arm64: entry: Move trampoline macros out of ifdef'd section
    - arm64: entry: Make the kpti trampoline's kpti sequence optional
    - arm64: entry: Allow the trampoline text to occupy multiple pages
    - arm64: entry: Add non-kpti __bp_harden_el1_vectors for mitigations
    - arm64: entry: Add vectors that have the bhb mitigation sequences
    - arm64: entry: Add macro for reading symbol addresses from the trampoline
    - arm64: Add percpu vectors for EL1
    - arm64: proton-pack: Report Spectre-BHB vulnerabilities as part of Spectre-v2
    - arm64: Mitigate spectre style branch history side channels
    - KVM: arm64: Allow SMCCC_ARCH_WORKAROUND_3 to be discovered and migrated
    - arm64: Use the clearbhb instruction in mitigations
    - arm64: proton-pack: Include unprivileged eBPF status in Spectre v2
      mitigation reporting
    - ARM: fix build error when BPF_SYSCALL is disabled

  * CVE-2021-26401
    - x86/speculation: Use generic retpoline by default on AMD
    - x86/speculation: Update link to AMD speculation whitepaper
    - x86/speculation: Warn about Spectre v2 LFENCE mitigation
    - x86/speculation: Warn about eIBRS + LFENCE + Unprivileged eBPF + SMT

  * CVE-2022-0001
    - x86,bugs: Unconditionally allow spectre_v2=retpoline,amd
    - x86/speculation: Rename RETPOLINE_AMD to RETPOLINE_LFENCE
    - x86/speculation: Add eIBRS + Retpoline options
    - Document...

Changed in linux (Ubuntu Jammy):
status: Fix Committed → Fix Released
Revision history for this message
Ubuntu Kernel Bot (ubuntu-kernel-bot) wrote :

This bug is awaiting verification that the linux-oracle-5.15/5.15.0-1006.8~20.04.1 kernel in -proposed solves the problem. Please test the kernel and update this bug with the results. If the problem is solved, change the tag 'verification-needed-focal' to 'verification-done-focal'. If the problem still exists, change the tag 'verification-needed-focal' to 'verification-failed-focal'.

If verification is not done by 5 working days from today, this fix will be dropped from the source code, and this bug will be closed.

See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you!

tags: added: verification-needed-focal
Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

ftracetest is green with F-oracle 5.15.0-1007.9~20.04.1

tags: added: verification-done-focal
removed: verification-needed-focal
Changed in ubuntu-kernel-tests:
status: New → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.