ftrace test failed with Register/unregister many kprobe events in ubuntu_kernel_selftests

Bug #1866972 reported by Po-Hsu Lin
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
ubuntu-kernel-tests
Fix Released
Undecided
Unassigned
linux (Ubuntu)
Fix Released
Undecided
Unassigned
Eoan
Won't Fix
Undecided
Thadeu Lima de Souza Cascardo

Bug Description

[Impact]
kernel selftest ftrace will fail with:
[42] Register/unregister many kprobe events [FAIL]

[Test case]
Run that selftest with:
cd tools/testing/selftests/ftrace/
sudo make run_tests

[Regression potential]
The suggested fix only change the test, not the ftrace code. From the nature of the test, the change would hardly prevent us from detecting other hard failures besides that we do not return EEXIST currently for duplicate probes.

=============================================

Issue found on c4.large with 5.0.0-1027.30-aws

Test failed with:
[42] Register/unregister many kprobe events [FAIL]

 selftests: ftrace: ftracetest
 ========================================
 === Ftrace unit tests ===
 [1] Basic trace file check [PASS]
 [2] Basic test for tracers [PASS]
 [3] Basic trace clock test [PASS]
 [4] Basic event tracing check [PASS]
 [5] Change the ringbuffer size [PASS]
 [6] Snapshot and tracing setting [PASS]
 [7] trace_pipe and trace_marker [PASS]
 [8] Generic dynamic event - add/remove kprobe events [PASS]
 [9] Generic dynamic event - add/remove synthetic events [PASS]
 [10] Generic dynamic event - selective clear (compatibility) [PASS]
 [11] Generic dynamic event - generic clear event [PASS]
 [12] event tracing - enable/disable with event level files [PASS]
 [13] event tracing - restricts events based on pid [PASS]
 [14] event tracing - enable/disable with subsystem level files [PASS]
 [15] event tracing - enable/disable with top level files [PASS]
 [16] Test trace_printk from module [UNRESOLVED]
 [17] ftrace - function graph filters with stack tracer [PASS]
 [18] ftrace - function graph filters [PASS]
 [19] ftrace - function pid filters [PASS]
 [20] ftrace - stacktrace filter command [PASS]
 [21] ftrace - function trace with cpumask [PASS]
 [22] ftrace - test for function event triggers [PASS]
 [23] ftrace - function trace on module [UNRESOLVED]
 [24] ftrace - function profiling [PASS]
 [25] ftrace - function profiler with function tracing [PASS]
 [26] ftrace - test reading of set_ftrace_filter [PASS]
 [27] ftrace - test for function traceon/off triggers [PASS]
 [28] Test creation and deletion of trace instances while setting an event [PASS]
 [29] Test creation and deletion of trace instances [PASS]
 [30] Kprobe dynamic event - adding and removing [PASS]
 [31] Kprobe dynamic event - busy event check [PASS]
 [32] Kprobe dynamic event with arguments [PASS]
 [33] Kprobe event with comm arguments [PASS]
 [34] Kprobe event string type argument [PASS]
 [35] Kprobe event symbol argument [PASS]
 [36] Kprobe event argument syntax [PASS]
 [37] Kprobes event arguments with types [PASS]
 [38] Kprobe event auto/manual naming [PASS]
 [39] Kprobe dynamic event with function tracer [PASS]
 [40] Kretprobe dynamic event with arguments [PASS]
 [41] Kretprobe dynamic event with maxactive [PASS]
 [42] Register/unregister many kprobe events [FAIL]
 [43] Kprobe dynamic event - adding and removing [PASS]
 [44] test for the preemptirqsoff tracer [UNSUPPORTED]
 [45] Test wakeup tracer [PASS]
 [46] Test wakeup RT tracer [PASS]
 [47] event trigger - test extended error support [PASS]
 [48] event trigger - test field variable support [PASS]
 [49] event trigger - test multiple actions on hist trigger [PASS]
 [50] event trigger - test inter-event histogram trigger onmatch action [PASS]
 [51] event trigger - test inter-event histogram trigger onmatch-onmax action [PASS]
 [52] event trigger - test inter-event histogram trigger onmax action [PASS]
 [53] event trigger - test synthetic_events syntax parser [PASS]
 [54] event trigger - test event enable/disable trigger [PASS]
 [55] event trigger - test trigger filter [PASS]
 [56] event trigger - test histogram modifiers [PASS]
 [57] event trigger - test multiple histogram triggers [PASS]
 [58] event trigger - test snapshot-trigger [PASS]
 [59] event trigger - test stacktrace-trigger [PASS]
 [60] trace_marker trigger - test snapshot trigger [PASS]
 [61] trace_marker trigger - test histogram with synthetic event against kernel event [PASS]
 [62] trace_marker trigger - test histogram with synthetic event [PASS]
 [63] event trigger - test traceon/off trigger [PASS]
 [64] (instance) Basic test for tracers [PASS]
 [65] (instance) Basic trace clock test [PASS]
 [66] (instance) Change the ringbuffer size [PASS]
 [67] (instance) Snapshot and tracing setting [PASS]
 [68] (instance) trace_pipe and trace_marker [PASS]
 [69] (instance) event tracing - enable/disable with event level files [PASS]
 [70] (instance) event tracing - restricts events based on pid [PASS]
 [71] (instance) event tracing - enable/disable with subsystem level files [PASS]
 [72] (instance) ftrace - stacktrace filter command [PASS]
 [73] (instance) ftrace - test for function event triggers [PASS]
 [74] (instance) ftrace - test for function traceon/off triggers [PASS]
 [75] (instance) event trigger - test event enable/disable trigger [PASS]
 [76] (instance) event trigger - test trigger filter [PASS]
 [77] (instance) event trigger - test histogram modifiers [PASS]
 [78] (instance) event trigger - test multiple histogram triggers [PASS]
 [79] (instance) trace_marker trigger - test snapshot trigger [PASS]

 # of passed: 75
 # of failed: 1
 # of unresolved: 2
 # of untested: 0
 # of unsupported: 1
 # of xfailed: 0
 # of undefined(test bug): 0
 not ok 1..1 selftests: ftrace: ftracetest [FAIL]

Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

For reference, there was once an issue for this particular test on 5.0 kernel, bug 1840750

tags: added: amd64 aws sru-20200217 ubuntu-kernel-selftests
tags: added: 5.0 bionic
Revision history for this message
Po-Hsu Lin (cypressyew) wrote :
Download full text (4.7 KiB)

Test passed on c4.large with 5.0.0-1025-aws

 selftests: ftrace: ftracetest
 ========================================
 === Ftrace unit tests ===
 [1] Basic trace file check [PASS]
 [2] Basic test for tracers [PASS]
 [3] Basic trace clock test [PASS]
 [4] Basic event tracing check [PASS]
 [5] Change the ringbuffer size [PASS]
 [6] Snapshot and tracing setting [PASS]
 [7] trace_pipe and trace_marker [PASS]
 [8] Generic dynamic event - add/remove kprobe events [PASS]
 [9] Generic dynamic event - add/remove synthetic events [PASS]
 [10] Generic dynamic event - selective clear (compatibility) [PASS]
 [11] Generic dynamic event - generic clear event [PASS]
 [12] event tracing - enable/disable with event level files [PASS]
 [13] event tracing - restricts events based on pid [PASS]
 [14] event tracing - enable/disable with subsystem level files [PASS]
 [15] event tracing - enable/disable with top level files [PASS]
 [16] Test trace_printk from module [UNRESOLVED]
 [17] ftrace - function graph filters with stack tracer [PASS]
 [18] ftrace - function graph filters [PASS]
 [19] ftrace - function pid filters [PASS]
 [20] ftrace - stacktrace filter command [PASS]
 [21] ftrace - function trace with cpumask [PASS]
 [22] ftrace - test for function event triggers [PASS]
 [23] ftrace - function trace on module [UNRESOLVED]
 [24] ftrace - function profiling [PASS]
 [25] ftrace - function profiler with function tracing [PASS]
 [26] ftrace - test reading of set_ftrace_filter [PASS]
 [27] ftrace - test for function traceon/off triggers [PASS]
 [28] Test creation and deletion of trace instances while setting an event [PASS]
 [29] Test creation and deletion of trace instances [PASS]
 [30] Kprobe dynamic event - adding and removing [PASS]
 [31] Kprobe dynamic event - busy event check [PASS]
 [32] Kprobe dynamic event with arguments [PASS]
 [33] Kprobe event with comm arguments [PASS]
 [34] Kprobe event string type argument [PASS]
 [35] Kprobe event symbol argument [PASS]
 [36] Kprobe event argument syntax [PASS]
 [37] Kprobes event arguments with types [PASS]
 [38] Kprobe event auto/manual naming [PASS]
 [39] Kprobe dynamic event with function tracer [PASS]
 [40] Kretprobe dynamic event with arguments [PASS]
 [41] Kretprobe dynamic event with maxactive [PASS]
 [42] Register/unregister many kprobe events [PASS]
 [43] Kprobe dynamic event - adding and removing [PASS]
 [44] test for the preemptirqsoff tracer [UNSUPPORTED]
 [45] Test wakeup tracer [PASS]
 [46] Test wakeup RT tracer [PASS]
 [47] event trigger - test extended error support [PASS]
 [48] event trigger - test field variable support [PASS]
 [49] event trigger - test multiple actions on hist trigger [PASS]
 [50] event trigger - test inter-event histogram trigger onmatch action [PASS]
 [51] event trigger - test inter-event histogram trigger onmatch-onmax action [PASS]
 [52] event trigger - test inter-event histogram trigger onmax action [PASS]
 [53] event trigger - test synthetic_events syntax parser [PASS]
 [54] event trigger - test event enable/disable trigger [PASS]
 [55] event trigger - test trigger filter [PASS]
 [56] event trigger - test histogram modifiers [PASS]
 [57] event trigger - test multiple histog...

Read more...

tags: added: kqa-blocker
Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

I have the proposed kernel tested with the tool in 5.0.0-1025-aws kernel, and it will pass.

But with the tool in 5.0.0-1027-aws kernel it will fail, it looks like a testing tool issue to me.

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 1866972

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
Changed in linux (Ubuntu Disco):
status: New → Incomplete
Revision history for this message
Po-Hsu Lin (cypressyew) wrote : Re: ftrace test failed with Register/unregister many kprobe events in ubuntu_kernel_selftests on B-AWS-5.0

I have 5.0.0-1027-aws tested against with the latest upstream code (f35111a9 https://github.com/torvalds/linux.git)

And this is still failing:
# [51] Register/unregister many kprobe events [FAIL]

Revision history for this message
Thadeu Lima de Souza Cascardo (cascardo) wrote :

Does it fail if you change /bin/sh to point to bash instead of dash?

I know some ftrace tests failed because of how 'echo' would behave differently between those two shells, and that using printf would be better, and that Seth has already sent a patch for that upstream.

I recall this test being the one that failed, but may be misremembering.

Cascardo.

Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

With /bin/sh in ftrace/test.d/kprobe/multiple_kprobes.tc changed to /bin/bash this is still failing with the upstream repo.

Run this test with the following command to see more debug info:
./ftracetest test.d/kprobe/multiple_kprobes.tc -v

Test failed because the wc -l result for kprobe_events does not met expectations.
The number of kprobes events (248) is not 256

Please find attachment for the test log.

Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

This can be found on Eoan 5.3.0-43.36 as well.

tags: added: 5.3 eoan sru-20200316
Po-Hsu Lin (cypressyew)
summary: ftrace test failed with Register/unregister many kprobe events in
- ubuntu_kernel_selftests on B-AWS-5.0
+ ubuntu_kernel_selftests on B-AWS-5.0 / E
Revision history for this message
Sean Feole (sfeole) wrote : Re: ftrace test failed with Register/unregister many kprobe events in ubuntu_kernel_selftests on B-AWS-5.0 / E

No longer see a failure with KProbe events on AWS for SRU cycle 2020.04.06 : 5.3.0-1017.18

[41] Kprobe dynamic event with function tracer [PASS]
[42] Kprobe event parser error log check [PASS]
[43] Kretprobe dynamic event with arguments [PASS]

Changed in ubuntu-kernel-tests:
status: New → Invalid
Changed in linux (Ubuntu):
status: Incomplete → Invalid
Changed in linux (Ubuntu Disco):
status: Incomplete → Invalid
Revision history for this message
Sean Feole (sfeole) wrote :

Please note disco has been EOL, if the failures are still exhibited with another release, lets open a new bug as this has been stale for quite some time

Sean Feole (sfeole)
Changed in ubuntu-kernel-tests:
status: Invalid → Triaged
summary: ftrace test failed with Register/unregister many kprobe events in
- ubuntu_kernel_selftests on B-AWS-5.0 / E
+ ubuntu_kernel_selftests on Metal / E
summary: ftrace test failed with Register/unregister many kprobe events in
- ubuntu_kernel_selftests on Metal / E
+ ubuntu_kernel_selftests
tags: added: sru-20200406
removed: 5.0 aws
Changed in linux (Ubuntu):
status: Invalid → Triaged
no longer affects: linux (Ubuntu Disco)
Revision history for this message
Sean Feole (sfeole) wrote :

Was observed on the linux-gcp 5.3 kernel:
04/14 09:54:08 DEBUG| utils:0153| [stdout] # [45] Register/unregister many kprobe events [FAIL]

5.3.0-1018.19~18.04.1 linux-gcp-5.3

tags: added: gcp
description: updated
Changed in linux (Ubuntu Eoan):
status: New → In Progress
Changed in linux (Ubuntu):
status: Triaged → Fix Released
Changed in linux (Ubuntu Eoan):
assignee: nobody → Thadeu Lima de Souza Cascardo (cascardo)
Revision history for this message
Thadeu Lima de Souza Cascardo (cascardo) wrote :

For what matters, the alternative would probably to pick fe60b0ce8e7335269722ec080173a9411a9d58a5. More exactly, all the following commits:

41af3cf587f476f9a879b08219324c8b456e6a4c tracing/uprobe: Add multi-probe per uprobe event support
60d53e2c3b75e79c83970fe73db79123d9462c7c tracing/probe: Split trace_event related data from trace_probe
ca89bc071d5e4e981dcc52e0ca90f4500d332e42 tracing/kprobe: Add multi-probe per event support
fe60b0ce8e7335269722ec080173a9411a9d58a5 tracing/probe: Reject exactly same probe event
f8d7ab2bded897607bff6324d5c6ea6b4aecca0c tracing/probe: Fix same probe event argument matching

Not tested.

Changed in linux (Ubuntu Eoan):
status: In Progress → Fix Committed
Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

For the record this is still affecting 5.0 kernel 5.0.0-53.57~18.04.1-generic

tags: added: 5.0 sru-20200608
Revision history for this message
Sean Feole (sfeole) wrote :

Looks like fixed in 5.3.0-1026.28~18.04.1 - aws

Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

Although Disco has already reached EOL, but we still need to support 5.0 kernel.
This issue still exist in 5.0:
 * 5.0.0-1067.72 (OEM-OSP1)
 * 5.0.0-60.64~18.04.1

Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

Still affecting 5.0.0-1046.47 GKE

tags: added: sru-20200720
Revision history for this message
Brian Murray (brian-murray) wrote :

The Eoan Ermine has reached end of life, so this bug will not be fixed for that release

Changed in linux (Ubuntu Eoan):
status: Fix Committed → Won't Fix
tags: added: 5.8 focal sru-20210510
tags: removed: 5.8 focal sru-20210510
Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

Since this issue has been fixed in new kernels and the 5.0, 5.3 kernel mentioned are all out-dated. Plus this bug was not being referenced in any of our hints, I am going to close this report. Thanks.

Changed in ubuntu-kernel-tests:
status: Triaged → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Bug attachments

Remote bug watches

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