2017-06-07 22:43:00

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 05/23/2017 12:02 AM, Masami Hiramatsu wrote:
> Hi,
>
> This series improves ftracetest mainly to run on 4.9 stable
> tree kernel. There still some issues remains (it seems some
> fixes are not merged), but a half of issues are fixed.
>
> NOTE: One patch will modify ftrace README to check the
> availability of the maxactive option, which should have
> been implemented with the function-added patch.
>
> With this series, only 1 test actually failed on 4.9.29.
> (and 3 unsupported, since it is too old to support it)
>
> Tue May 23 05:56:24 UTC 2017
> === 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] event tracing - enable/disable with event level files [PASS]
> [6] event tracing - restricts events based on pid [PASS]
> [7] event tracing - enable/disable with subsystem level files [PASS]
> [8] event tracing - enable/disable with top level files [PASS]
> [9] ftrace - function graph filters with stack tracer [PASS]
> [10] ftrace - function graph filters [PASS]
> [11] ftrace - function glob filters [PASS]
> [12] ftrace - function pid filters [PASS]
> [13] ftrace - test for function event triggers [PASS]
> [14] ftrace - function profiler with function tracing [PASS]
> [15] ftrace - test reading of set_ftrace_filter [FAIL]
> [16] ftrace - test for function traceon/off triggers [PASS]
> [17] Test creation and deletion of trace instances while setting an event [PASS]
> [18] Test creation and deletion of trace instances [PASS]
> [19] Kprobe dynamic event - adding and removing [PASS]
> [20] Kprobe dynamic event - busy event check [PASS]
> [21] Kprobe dynamic event with arguments [PASS]
> [22] Kprobes event arguments with types [PASS]
> [23] Kprobe dynamic event with function tracer [PASS]
> [24] Kretprobe dynamic event with arguments [PASS]
> [25] Kretprobe dynamic event with maxactive [UNSUPPORTED]
> [26] event trigger - test event enable/disable trigger [PASS]
> [27] event trigger - test trigger filter [PASS]
> [28] event trigger - test histogram modifiers [PASS]
> [29] event trigger - test histogram trigger [PASS]
> [30] event trigger - test multiple histogram triggers [PASS]
> [31] event trigger - test snapshot-trigger [PASS]
> [32] event trigger - test stacktrace-trigger [PASS]
> [33] event trigger - test traceon/off trigger [PASS]
> [34] (instance) Basic test for tracers [PASS]
> [35] (instance) Basic trace clock test [PASS]
> [36] (instance) event tracing - enable/disable with event level files [PASS]
> [37] (instance) event tracing - restricts events based on pid [PASS]
> [38] (instance) event tracing - enable/disable with subsystem level files [PASS]
> [39] (instance) ftrace - test for function event triggers [UNSUPPORTED]
> [40] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
> [41] (instance) event trigger - test event enable/disable trigger [PASS]
> [42] (instance) event trigger - test trigger filter [PASS]
> [43] (instance) event trigger - test histogram modifiers [PASS]
> [44] (instance) event trigger - test histogram trigger [PASS]
> [45] (instance) event trigger - test multiple histogram triggers [PASS]
>
> # of passed: 41
> # of failed: 1
> # of unresolved: 0
> # of untested: 0
> # of unsupported: 3
> # of xfailed: 0
> # of undefined(test bug): 0
>
>
>> [15] ftrace - test reading of set_ftrace_filter [FAIL]
> was caused by the difference of the result of
> "dd bs=1 if=set_ftrace_filter" and "cat set_ftrace_filter",
> which has been fixed on upstream by commit fcdc71257923
> ("ftrace: Fix indexing of t_hash_start() from t_next()")
> but backporting it onto 4.9.y stable tree didn't fix that.
>
>
> Thank you,
>
> ---
>
> Masami Hiramatsu (7):
> selftests/ftrace: Skip full-glob-matching filter test on older kernel
> selftests/ftrace: Reduce trace buffer checking overhead
> ftrace/kprobes: selftests: Check kretprobe maxactive is supported
> selftests/ftrace: Reset ftrace filter on older kernel
> selftests/ftrace: Add instance indication in test log
> selftests/ftrace: Use top-level available_filter_function
> selftests/ftrace: Return unsupported if it detects older kernel
>
>
> kernel/trace/trace.c | 3 +-
> tools/testing/selftests/ftrace/ftracetest | 2 +
> .../ftrace/test.d/event/toplevel-enable.tc | 8 ++++--
> .../ftrace/test.d/ftrace/func-filter-glob.tc | 28 ++++++++++++--------
> .../ftrace/test.d/ftrace/func_event_triggers.tc | 9 ++++++
> .../test.d/ftrace/func_traceonoff_triggers.tc | 13 +++++++++
> .../ftrace/test.d/instances/instance-event.tc | 5 +++-
> .../ftrace/test.d/kprobe/kretprobe_maxactive.tc | 1 +
> 8 files changed, 53 insertions(+), 16 deletions(-)
>
> --
> Masami Hiramatsu (Linaro) <[email protected]>
>
>

Hi Masami/Steve,

I applied this series to linux-kselftest next. I am seeing these
errors when ftracetest runs.

Is this a known problem? Has this been fixed? I am guessing this
problem is in the tracing sub-system. I ran the test on linux-kselftest
next which is based on 4.12-rc4

Am I missing a trace sub-system fix.

[ 5507.393998] ------------[ cut here ]------------
[ 5507.394010] WARNING: CPU: 2 PID: 30258 at kernel/trace/ring_buffer.c:4215 ring_buffer_reset_cpu+0x798/0xd00
[ 5507.394013] Modules linked in: binfmt_misc x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd cryptd glue_helper snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_timer lpc_ich mac_hid tpm_tis tpm_tis_core parport_pc ppdev lp parport ip_tables x_tables autofs4 btrfs xor hid_generic usbhid hid raid6_pq dm_mirror dm_region_hash dm_log usb_storage i915 iosf_mbi i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops r8169 drm mii wmi video
[ 5507.394194] CPU: 2 PID: 30258 Comm: ftracetest Tainted: G W 4.12.0-rc4 #16
[ 5507.394198] Hardware name: System76, Inc. Wild Dog Performance/H87-PLUS, BIOS 0705 12/05/2013
[ 5507.394202] task: ffff88033c7e0000 task.stack: ffff880378798000
[ 5507.394207] RIP: 0010:ring_buffer_reset_cpu+0x798/0xd00
[ 5507.394211] RSP: 0018:ffff88037879f9c8 EFLAGS: 00010006
[ 5507.394218] RAX: ffff88038f410a00 RBX: ffff88038f418480 RCX: 0000000000000282
[ 5507.394222] RDX: 1ffff10071e83091 RSI: 00000000e018b669 RDI: ffff88038f418488
[ 5507.394226] RBP: ffff88037879fa08 R08: ffff88038f418550 R09: ffffffff83a8ef00
[ 5507.394230] R10: ffff88037879f928 R11: ffffffff834940e0 R12: 0000000000000007
[ 5507.394234] R13: ffff88038f418490 R14: ffff88038f410a00 R15: ffff88037d18ac00
[ 5507.394239] FS: 00007f0787844700(0000) GS:ffff88038f880000(0000) knlGS:0000000000000000
[ 5507.394242] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 5507.394246] CR2: 0000561f7a0e5bb8 CR3: 00000003637eb000 CR4: 00000000001406e0
[ 5507.394250] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 5507.394253] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 5507.394257] Call Trace:
[ 5507.394272] tracing_reset_online_cpus+0xd2/0x160
[ 5507.394283] tracing_open+0x18b/0x200
[ 5507.394295] do_dentry_open+0x630/0xba0
[ 5507.394301] ? generic_permission+0x4f/0x320
[ 5507.394310] ? tracing_snapshot_open+0x2e0/0x2e0
[ 5507.394323] vfs_open+0xf1/0x270
[ 5507.394329] ? may_open+0xc7/0x2e0
[ 5507.394339] path_openat+0xccc/0x2610
[ 5507.394360] ? path_lookupat+0x880/0x880
[ 5507.394366] ? entry_SYSCALL_64_fastpath+0x18/0xad
[ 5507.394386] ? debug_check_no_locks_freed+0x280/0x280
[ 5507.394413] do_filp_open+0x17c/0x260
[ 5507.394421] ? may_open_dev+0xc0/0xc0
[ 5507.394444] ? _raw_spin_unlock+0x27/0x30
[ 5507.394452] ? __alloc_fd+0x191/0x4b0
[ 5507.394475] do_sys_open+0x175/0x350
[ 5507.394479] ? do_sys_open+0x175/0x350
[ 5507.394488] ? filp_open+0x60/0x60
[ 5507.394498] ? trace_hardirqs_on_thunk+0x1a/0x1c
[ 5507.394510] SyS_open+0x1e/0x20
[ 5507.394516] entry_SYSCALL_64_fastpath+0x18/0xad
[ 5507.394521] RIP: 0033:0x7f0787373a70
[ 5507.394524] RSP: 002b:00007fffab7a9f68 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
[ 5507.394532] RAX: ffffffffffffffda RBX: 0000561f7a0e60f0 RCX: 00007f0787373a70
[ 5507.394535] RDX: 00000000000001b6 RSI: 0000000000000241 RDI: 0000561f7a0ef058
[ 5507.394539] RBP: 0000000000000046 R08: 0000561f7a0e6158 R09: 0000561f7a0ef001
[ 5507.394543] R10: 0000561f7a0e8260 R11: 0000000000000246 R12: 0000000000000020
[ 5507.394547] R13: 0000561f7a0ef010 R14: 0000561f7a0e5b90 R15: 00007fffab7aa1a0
[ 5507.394571] Code: 41 5f 5d c3 48 8d 7b 08 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 51 05 00 00 48 8b 43 08 f0 ff 40 08 <0f> ff eb b2 48 89 d7 89 c6 4c 89 45 c0 48 89 4d c8 48 89 55 d0
[ 5507.394761] ---[ end trace ea9d726487ff6f82 ]---

thanks,
-- Shuah


2017-06-07 22:56:33

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Wed, 7 Jun 2017 16:42:55 -0600
Shuah Khan <[email protected]> wrote:

> On 05/23/2017 12:02 AM, Masami Hiramatsu wrote:
> > Hi,
> >
> > This series improves ftracetest mainly to run on 4.9 stable
> > tree kernel. There still some issues remains (it seems some
> > fixes are not merged), but a half of issues are fixed.
> >
> > NOTE: One patch will modify ftrace README to check the
> > availability of the maxactive option, which should have
> > been implemented with the function-added patch.
> >
> > With this series, only 1 test actually failed on 4.9.29.
> > (and 3 unsupported, since it is too old to support it)
> >
> > Tue May 23 05:56:24 UTC 2017
> > === 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] event tracing - enable/disable with event level files [PASS]
> > [6] event tracing - restricts events based on pid [PASS]
> > [7] event tracing - enable/disable with subsystem level files [PASS]
> > [8] event tracing - enable/disable with top level files [PASS]
> > [9] ftrace - function graph filters with stack tracer [PASS]
> > [10] ftrace - function graph filters [PASS]
> > [11] ftrace - function glob filters [PASS]
> > [12] ftrace - function pid filters [PASS]
> > [13] ftrace - test for function event triggers [PASS]
> > [14] ftrace - function profiler with function tracing [PASS]
> > [15] ftrace - test reading of set_ftrace_filter [FAIL]
> > [16] ftrace - test for function traceon/off triggers [PASS]
> > [17] Test creation and deletion of trace instances while setting an event [PASS]
> > [18] Test creation and deletion of trace instances [PASS]
> > [19] Kprobe dynamic event - adding and removing [PASS]
> > [20] Kprobe dynamic event - busy event check [PASS]
> > [21] Kprobe dynamic event with arguments [PASS]
> > [22] Kprobes event arguments with types [PASS]
> > [23] Kprobe dynamic event with function tracer [PASS]
> > [24] Kretprobe dynamic event with arguments [PASS]
> > [25] Kretprobe dynamic event with maxactive [UNSUPPORTED]
> > [26] event trigger - test event enable/disable trigger [PASS]
> > [27] event trigger - test trigger filter [PASS]
> > [28] event trigger - test histogram modifiers [PASS]
> > [29] event trigger - test histogram trigger [PASS]
> > [30] event trigger - test multiple histogram triggers [PASS]
> > [31] event trigger - test snapshot-trigger [PASS]
> > [32] event trigger - test stacktrace-trigger [PASS]
> > [33] event trigger - test traceon/off trigger [PASS]
> > [34] (instance) Basic test for tracers [PASS]
> > [35] (instance) Basic trace clock test [PASS]
> > [36] (instance) event tracing - enable/disable with event level files [PASS]
> > [37] (instance) event tracing - restricts events based on pid [PASS]
> > [38] (instance) event tracing - enable/disable with subsystem level files [PASS]
> > [39] (instance) ftrace - test for function event triggers [UNSUPPORTED]
> > [40] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
> > [41] (instance) event trigger - test event enable/disable trigger [PASS]
> > [42] (instance) event trigger - test trigger filter [PASS]
> > [43] (instance) event trigger - test histogram modifiers [PASS]
> > [44] (instance) event trigger - test histogram trigger [PASS]
> > [45] (instance) event trigger - test multiple histogram triggers [PASS]
> >
> > # of passed: 41
> > # of failed: 1
> > # of unresolved: 0
> > # of untested: 0
> > # of unsupported: 3
> > # of xfailed: 0
> > # of undefined(test bug): 0
> >
> >
> >> [15] ftrace - test reading of set_ftrace_filter [FAIL]
> > was caused by the difference of the result of
> > "dd bs=1 if=set_ftrace_filter" and "cat set_ftrace_filter",
> > which has been fixed on upstream by commit fcdc71257923
> > ("ftrace: Fix indexing of t_hash_start() from t_next()")
> > but backporting it onto 4.9.y stable tree didn't fix that.
> >
> >
> > Thank you,
> >
> > ---
> >
> > Masami Hiramatsu (7):
> > selftests/ftrace: Skip full-glob-matching filter test on older kernel
> > selftests/ftrace: Reduce trace buffer checking overhead
> > ftrace/kprobes: selftests: Check kretprobe maxactive is supported
> > selftests/ftrace: Reset ftrace filter on older kernel
> > selftests/ftrace: Add instance indication in test log
> > selftests/ftrace: Use top-level available_filter_function
> > selftests/ftrace: Return unsupported if it detects older kernel
> >
> >
> > kernel/trace/trace.c | 3 +-
> > tools/testing/selftests/ftrace/ftracetest | 2 +
> > .../ftrace/test.d/event/toplevel-enable.tc | 8 ++++--
> > .../ftrace/test.d/ftrace/func-filter-glob.tc | 28 ++++++++++++--------
> > .../ftrace/test.d/ftrace/func_event_triggers.tc | 9 ++++++
> > .../test.d/ftrace/func_traceonoff_triggers.tc | 13 +++++++++
> > .../ftrace/test.d/instances/instance-event.tc | 5 +++-
> > .../ftrace/test.d/kprobe/kretprobe_maxactive.tc | 1 +
> > 8 files changed, 53 insertions(+), 16 deletions(-)
> >
> > --
> > Masami Hiramatsu (Linaro) <[email protected]>
> >
> >
>
> Hi Masami/Steve,
>
> I applied this series to linux-kselftest next. I am seeing these
> errors when ftracetest runs.
>
> Is this a known problem? Has this been fixed? I am guessing this
> problem is in the tracing sub-system. I ran the test on linux-kselftest
> next which is based on 4.12-rc4
>
> Am I missing a trace sub-system fix.

No this is new to me. Just to confirm, you see this on 4.12-rc4 right?
Can you send me your config.

Thanks!

-- Steve

>
> [ 5507.393998] ------------[ cut here ]------------
> [ 5507.394010] WARNING: CPU: 2 PID: 30258 at kernel/trace/ring_buffer.c:4215 ring_buffer_reset_cpu+0x798/0xd00
> [ 5507.394013] Modules linked in: binfmt_misc x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd cryptd glue_helper snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_timer lpc_ich mac_hid tpm_tis tpm_tis_core parport_pc ppdev lp parport ip_tables x_tables autofs4 btrfs xor hid_generic usbhid hid raid6_pq dm_mirror dm_region_hash dm_log usb_storage i915 iosf_mbi i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops r8169 drm mii wmi video
> [ 5507.394194] CPU: 2 PID: 30258 Comm: ftracetest Tainted: G W 4.12.0-rc4 #16
> [ 5507.394198] Hardware name: System76, Inc. Wild Dog Performance/H87-PLUS, BIOS 0705 12/05/2013
> [ 5507.394202] task: ffff88033c7e0000 task.stack: ffff880378798000
> [ 5507.394207] RIP: 0010:ring_buffer_reset_cpu+0x798/0xd00
> [ 5507.394211] RSP: 0018:ffff88037879f9c8 EFLAGS: 00010006
> [ 5507.394218] RAX: ffff88038f410a00 RBX: ffff88038f418480 RCX: 0000000000000282
> [ 5507.394222] RDX: 1ffff10071e83091 RSI: 00000000e018b669 RDI: ffff88038f418488
> [ 5507.394226] RBP: ffff88037879fa08 R08: ffff88038f418550 R09: ffffffff83a8ef00
> [ 5507.394230] R10: ffff88037879f928 R11: ffffffff834940e0 R12: 0000000000000007
> [ 5507.394234] R13: ffff88038f418490 R14: ffff88038f410a00 R15: ffff88037d18ac00
> [ 5507.394239] FS: 00007f0787844700(0000) GS:ffff88038f880000(0000) knlGS:0000000000000000
> [ 5507.394242] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 5507.394246] CR2: 0000561f7a0e5bb8 CR3: 00000003637eb000 CR4: 00000000001406e0
> [ 5507.394250] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 5507.394253] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 5507.394257] Call Trace:
> [ 5507.394272] tracing_reset_online_cpus+0xd2/0x160
> [ 5507.394283] tracing_open+0x18b/0x200
> [ 5507.394295] do_dentry_open+0x630/0xba0
> [ 5507.394301] ? generic_permission+0x4f/0x320
> [ 5507.394310] ? tracing_snapshot_open+0x2e0/0x2e0
> [ 5507.394323] vfs_open+0xf1/0x270
> [ 5507.394329] ? may_open+0xc7/0x2e0
> [ 5507.394339] path_openat+0xccc/0x2610
> [ 5507.394360] ? path_lookupat+0x880/0x880
> [ 5507.394366] ? entry_SYSCALL_64_fastpath+0x18/0xad
> [ 5507.394386] ? debug_check_no_locks_freed+0x280/0x280
> [ 5507.394413] do_filp_open+0x17c/0x260
> [ 5507.394421] ? may_open_dev+0xc0/0xc0
> [ 5507.394444] ? _raw_spin_unlock+0x27/0x30
> [ 5507.394452] ? __alloc_fd+0x191/0x4b0
> [ 5507.394475] do_sys_open+0x175/0x350
> [ 5507.394479] ? do_sys_open+0x175/0x350
> [ 5507.394488] ? filp_open+0x60/0x60
> [ 5507.394498] ? trace_hardirqs_on_thunk+0x1a/0x1c
> [ 5507.394510] SyS_open+0x1e/0x20
> [ 5507.394516] entry_SYSCALL_64_fastpath+0x18/0xad
> [ 5507.394521] RIP: 0033:0x7f0787373a70
> [ 5507.394524] RSP: 002b:00007fffab7a9f68 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
> [ 5507.394532] RAX: ffffffffffffffda RBX: 0000561f7a0e60f0 RCX: 00007f0787373a70
> [ 5507.394535] RDX: 00000000000001b6 RSI: 0000000000000241 RDI: 0000561f7a0ef058
> [ 5507.394539] RBP: 0000000000000046 R08: 0000561f7a0e6158 R09: 0000561f7a0ef001
> [ 5507.394543] R10: 0000561f7a0e8260 R11: 0000000000000246 R12: 0000000000000020
> [ 5507.394547] R13: 0000561f7a0ef010 R14: 0000561f7a0e5b90 R15: 00007fffab7aa1a0
> [ 5507.394571] Code: 41 5f 5d c3 48 8d 7b 08 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 51 05 00 00 48 8b 43 08 f0 ff 40 08 <0f> ff eb b2 48 89 d7 89 c6 4c 89 45 c0 48 89 4d c8 48 89 55 d0
> [ 5507.394761] ---[ end trace ea9d726487ff6f82 ]---
>
> thanks,
> -- Shuah

2017-06-07 23:01:21

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 06/07/2017 04:56 PM, Steven Rostedt wrote:
> On Wed, 7 Jun 2017 16:42:55 -0600
> Shuah Khan <[email protected]> wrote:
>
>> On 05/23/2017 12:02 AM, Masami Hiramatsu wrote:
>>> Hi,
>>>
>>> This series improves ftracetest mainly to run on 4.9 stable
>>> tree kernel. There still some issues remains (it seems some
>>> fixes are not merged), but a half of issues are fixed.
>>>
>>> NOTE: One patch will modify ftrace README to check the
>>> availability of the maxactive option, which should have
>>> been implemented with the function-added patch.
>>>
>>> With this series, only 1 test actually failed on 4.9.29.
>>> (and 3 unsupported, since it is too old to support it)
>>>
>>> Tue May 23 05:56:24 UTC 2017
>>> === 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] event tracing - enable/disable with event level files [PASS]
>>> [6] event tracing - restricts events based on pid [PASS]
>>> [7] event tracing - enable/disable with subsystem level files [PASS]
>>> [8] event tracing - enable/disable with top level files [PASS]
>>> [9] ftrace - function graph filters with stack tracer [PASS]
>>> [10] ftrace - function graph filters [PASS]
>>> [11] ftrace - function glob filters [PASS]
>>> [12] ftrace - function pid filters [PASS]
>>> [13] ftrace - test for function event triggers [PASS]
>>> [14] ftrace - function profiler with function tracing [PASS]
>>> [15] ftrace - test reading of set_ftrace_filter [FAIL]
>>> [16] ftrace - test for function traceon/off triggers [PASS]
>>> [17] Test creation and deletion of trace instances while setting an event [PASS]
>>> [18] Test creation and deletion of trace instances [PASS]
>>> [19] Kprobe dynamic event - adding and removing [PASS]
>>> [20] Kprobe dynamic event - busy event check [PASS]
>>> [21] Kprobe dynamic event with arguments [PASS]
>>> [22] Kprobes event arguments with types [PASS]
>>> [23] Kprobe dynamic event with function tracer [PASS]
>>> [24] Kretprobe dynamic event with arguments [PASS]
>>> [25] Kretprobe dynamic event with maxactive [UNSUPPORTED]
>>> [26] event trigger - test event enable/disable trigger [PASS]
>>> [27] event trigger - test trigger filter [PASS]
>>> [28] event trigger - test histogram modifiers [PASS]
>>> [29] event trigger - test histogram trigger [PASS]
>>> [30] event trigger - test multiple histogram triggers [PASS]
>>> [31] event trigger - test snapshot-trigger [PASS]
>>> [32] event trigger - test stacktrace-trigger [PASS]
>>> [33] event trigger - test traceon/off trigger [PASS]
>>> [34] (instance) Basic test for tracers [PASS]
>>> [35] (instance) Basic trace clock test [PASS]
>>> [36] (instance) event tracing - enable/disable with event level files [PASS]
>>> [37] (instance) event tracing - restricts events based on pid [PASS]
>>> [38] (instance) event tracing - enable/disable with subsystem level files [PASS]
>>> [39] (instance) ftrace - test for function event triggers [UNSUPPORTED]
>>> [40] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
>>> [41] (instance) event trigger - test event enable/disable trigger [PASS]
>>> [42] (instance) event trigger - test trigger filter [PASS]
>>> [43] (instance) event trigger - test histogram modifiers [PASS]
>>> [44] (instance) event trigger - test histogram trigger [PASS]
>>> [45] (instance) event trigger - test multiple histogram triggers [PASS]
>>>
>>> # of passed: 41
>>> # of failed: 1
>>> # of unresolved: 0
>>> # of untested: 0
>>> # of unsupported: 3
>>> # of xfailed: 0
>>> # of undefined(test bug): 0
>>>
>>>
>>>> [15] ftrace - test reading of set_ftrace_filter [FAIL]
>>> was caused by the difference of the result of
>>> "dd bs=1 if=set_ftrace_filter" and "cat set_ftrace_filter",
>>> which has been fixed on upstream by commit fcdc71257923
>>> ("ftrace: Fix indexing of t_hash_start() from t_next()")
>>> but backporting it onto 4.9.y stable tree didn't fix that.
>>>
>>>
>>> Thank you,
>>>
>>> ---
>>>
>>> Masami Hiramatsu (7):
>>> selftests/ftrace: Skip full-glob-matching filter test on older kernel
>>> selftests/ftrace: Reduce trace buffer checking overhead
>>> ftrace/kprobes: selftests: Check kretprobe maxactive is supported
>>> selftests/ftrace: Reset ftrace filter on older kernel
>>> selftests/ftrace: Add instance indication in test log
>>> selftests/ftrace: Use top-level available_filter_function
>>> selftests/ftrace: Return unsupported if it detects older kernel
>>>
>>>
>>> kernel/trace/trace.c | 3 +-
>>> tools/testing/selftests/ftrace/ftracetest | 2 +
>>> .../ftrace/test.d/event/toplevel-enable.tc | 8 ++++--
>>> .../ftrace/test.d/ftrace/func-filter-glob.tc | 28 ++++++++++++--------
>>> .../ftrace/test.d/ftrace/func_event_triggers.tc | 9 ++++++
>>> .../test.d/ftrace/func_traceonoff_triggers.tc | 13 +++++++++
>>> .../ftrace/test.d/instances/instance-event.tc | 5 +++-
>>> .../ftrace/test.d/kprobe/kretprobe_maxactive.tc | 1 +
>>> 8 files changed, 53 insertions(+), 16 deletions(-)
>>>
>>> --
>>> Masami Hiramatsu (Linaro) <[email protected]>
>>>
>>>
>>
>> Hi Masami/Steve,
>>
>> I applied this series to linux-kselftest next. I am seeing these
>> errors when ftracetest runs.
>>
>> Is this a known problem? Has this been fixed? I am guessing this
>> problem is in the tracing sub-system. I ran the test on linux-kselftest
>> next which is based on 4.12-rc4
>>
>> Am I missing a trace sub-system fix.
>
> No this is new to me. Just to confirm, you see this on 4.12-rc4 right?
> Can you send me your config.
>

Here is the config - please see attached.

-- Shuah



Attachments:
config (181.30 kB)

2017-06-08 17:37:52

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Wed, 7 Jun 2017 17:01:08 -0600
Shuah Khan <[email protected]> wrote:

> On 06/07/2017 04:56 PM, Steven Rostedt wrote:
> > On Wed, 7 Jun 2017 16:42:55 -0600
> > Shuah Khan <[email protected]> wrote:
> >
> >> On 05/23/2017 12:02 AM, Masami Hiramatsu wrote:
> >>> Hi,
> >>>
> >>> This series improves ftracetest mainly to run on 4.9 stable
> >>> tree kernel. There still some issues remains (it seems some
> >>> fixes are not merged), but a half of issues are fixed.
> >>>
> >>> NOTE: One patch will modify ftrace README to check the
> >>> availability of the maxactive option, which should have
> >>> been implemented with the function-added patch.
> >>>
> >>> With this series, only 1 test actually failed on 4.9.29.
> >>> (and 3 unsupported, since it is too old to support it)
> >>>
> >>> Tue May 23 05:56:24 UTC 2017
> >>> === 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] event tracing - enable/disable with event level files [PASS]
> >>> [6] event tracing - restricts events based on pid [PASS]
> >>> [7] event tracing - enable/disable with subsystem level files [PASS]
> >>> [8] event tracing - enable/disable with top level files [PASS]
> >>> [9] ftrace - function graph filters with stack tracer [PASS]
> >>> [10] ftrace - function graph filters [PASS]
> >>> [11] ftrace - function glob filters [PASS]
> >>> [12] ftrace - function pid filters [PASS]
> >>> [13] ftrace - test for function event triggers [PASS]
> >>> [14] ftrace - function profiler with function tracing [PASS]
> >>> [15] ftrace - test reading of set_ftrace_filter [FAIL]
> >>> [16] ftrace - test for function traceon/off triggers [PASS]
> >>> [17] Test creation and deletion of trace instances while setting an event [PASS]
> >>> [18] Test creation and deletion of trace instances [PASS]
> >>> [19] Kprobe dynamic event - adding and removing [PASS]
> >>> [20] Kprobe dynamic event - busy event check [PASS]
> >>> [21] Kprobe dynamic event with arguments [PASS]
> >>> [22] Kprobes event arguments with types [PASS]
> >>> [23] Kprobe dynamic event with function tracer [PASS]
> >>> [24] Kretprobe dynamic event with arguments [PASS]
> >>> [25] Kretprobe dynamic event with maxactive [UNSUPPORTED]
> >>> [26] event trigger - test event enable/disable trigger [PASS]
> >>> [27] event trigger - test trigger filter [PASS]
> >>> [28] event trigger - test histogram modifiers [PASS]
> >>> [29] event trigger - test histogram trigger [PASS]
> >>> [30] event trigger - test multiple histogram triggers [PASS]
> >>> [31] event trigger - test snapshot-trigger [PASS]
> >>> [32] event trigger - test stacktrace-trigger [PASS]
> >>> [33] event trigger - test traceon/off trigger [PASS]
> >>> [34] (instance) Basic test for tracers [PASS]
> >>> [35] (instance) Basic trace clock test [PASS]
> >>> [36] (instance) event tracing - enable/disable with event level files [PASS]
> >>> [37] (instance) event tracing - restricts events based on pid [PASS]
> >>> [38] (instance) event tracing - enable/disable with subsystem level files [PASS]
> >>> [39] (instance) ftrace - test for function event triggers [UNSUPPORTED]
> >>> [40] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
> >>> [41] (instance) event trigger - test event enable/disable trigger [PASS]
> >>> [42] (instance) event trigger - test trigger filter [PASS]
> >>> [43] (instance) event trigger - test histogram modifiers [PASS]
> >>> [44] (instance) event trigger - test histogram trigger [PASS]
> >>> [45] (instance) event trigger - test multiple histogram triggers [PASS]
> >>>
> >>> # of passed: 41
> >>> # of failed: 1
> >>> # of unresolved: 0
> >>> # of untested: 0
> >>> # of unsupported: 3
> >>> # of xfailed: 0
> >>> # of undefined(test bug): 0

I booted v4.12-rc4 with your config (didn't even have to change
anything for my box), and checkout the v4.12-rc4 kernel on the test box
and ran ftracetest. Here's my result:

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

The unsupported were:

[29] event trigger - test histogram modifiers [UNSUPPORTED]
[30] event trigger - test histogram trigger [UNSUPPORTED]
[31] event trigger - test multiple histogram triggers [UNSUPPORTED]

[44] (instance) event trigger - test histogram modifiers [UNSUPPORTED]
[45] (instance) event trigger - test histogram trigger [UNSUPPORTED]
[46] (instance) event trigger - test multiple histogram triggers [UNSUPPORTED]

Now why is this different? What compiler are you using to build your
kernel?

Thanks!

-- Steve



> >>>
> >>>
> >>>> [15] ftrace - test reading of set_ftrace_filter [FAIL]
> >>> was caused by the difference of the result of
> >>> "dd bs=1 if=set_ftrace_filter" and "cat set_ftrace_filter",
> >>> which has been fixed on upstream by commit fcdc71257923
> >>> ("ftrace: Fix indexing of t_hash_start() from t_next()")
> >>> but backporting it onto 4.9.y stable tree didn't fix that.
> >>>
> >>>
> >>> Thank you,
> >>>
> >>> ---
> >>>
> >>> Masami Hiramatsu (7):
> >>> selftests/ftrace: Skip full-glob-matching filter test on older kernel
> >>> selftests/ftrace: Reduce trace buffer checking overhead
> >>> ftrace/kprobes: selftests: Check kretprobe maxactive is supported
> >>> selftests/ftrace: Reset ftrace filter on older kernel
> >>> selftests/ftrace: Add instance indication in test log
> >>> selftests/ftrace: Use top-level available_filter_function
> >>> selftests/ftrace: Return unsupported if it detects older kernel
> >>>
> >>>
> >>> kernel/trace/trace.c | 3 +-
> >>> tools/testing/selftests/ftrace/ftracetest | 2 +
> >>> .../ftrace/test.d/event/toplevel-enable.tc | 8 ++++--
> >>> .../ftrace/test.d/ftrace/func-filter-glob.tc | 28 ++++++++++++--------
> >>> .../ftrace/test.d/ftrace/func_event_triggers.tc | 9 ++++++
> >>> .../test.d/ftrace/func_traceonoff_triggers.tc | 13 +++++++++
> >>> .../ftrace/test.d/instances/instance-event.tc | 5 +++-
> >>> .../ftrace/test.d/kprobe/kretprobe_maxactive.tc | 1 +
> >>> 8 files changed, 53 insertions(+), 16 deletions(-)
> >>>
> >>> --
> >>> Masami Hiramatsu (Linaro) <[email protected]>
> >>>
> >>>
> >>
> >> Hi Masami/Steve,
> >>
> >> I applied this series to linux-kselftest next. I am seeing these
> >> errors when ftracetest runs.
> >>
> >> Is this a known problem? Has this been fixed? I am guessing this
> >> problem is in the tracing sub-system. I ran the test on linux-kselftest
> >> next which is based on 4.12-rc4
> >>
> >> Am I missing a trace sub-system fix.
> >
> > No this is new to me. Just to confirm, you see this on 4.12-rc4 right?
> > Can you send me your config.
> >
>
> Here is the config - please see attached.
>
> -- Shuah
>
>

2017-06-08 20:06:34

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 06/08/2017 11:37 AM, Steven Rostedt wrote:
> On Wed, 7 Jun 2017 17:01:08 -0600
> Shuah Khan <[email protected]> wrote:
>
>> On 06/07/2017 04:56 PM, Steven Rostedt wrote:
>>> On Wed, 7 Jun 2017 16:42:55 -0600
>>> Shuah Khan <[email protected]> wrote:
>>>
>>>> On 05/23/2017 12:02 AM, Masami Hiramatsu wrote:
>>>>> Hi,
>>>>>
>>>>> This series improves ftracetest mainly to run on 4.9 stable
>>>>> tree kernel. There still some issues remains (it seems some
>>>>> fixes are not merged), but a half of issues are fixed.
>>>>>
>>>>> NOTE: One patch will modify ftrace README to check the
>>>>> availability of the maxactive option, which should have
>>>>> been implemented with the function-added patch.
>>>>>
>>>>> With this series, only 1 test actually failed on 4.9.29.
>>>>> (and 3 unsupported, since it is too old to support it)
>>>>>
>>>>> Tue May 23 05:56:24 UTC 2017
>>>>> === 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] event tracing - enable/disable with event level files [PASS]
>>>>> [6] event tracing - restricts events based on pid [PASS]
>>>>> [7] event tracing - enable/disable with subsystem level files [PASS]
>>>>> [8] event tracing - enable/disable with top level files [PASS]
>>>>> [9] ftrace - function graph filters with stack tracer [PASS]
>>>>> [10] ftrace - function graph filters [PASS]
>>>>> [11] ftrace - function glob filters [PASS]
>>>>> [12] ftrace - function pid filters [PASS]
>>>>> [13] ftrace - test for function event triggers [PASS]
>>>>> [14] ftrace - function profiler with function tracing [PASS]
>>>>> [15] ftrace - test reading of set_ftrace_filter [FAIL]
>>>>> [16] ftrace - test for function traceon/off triggers [PASS]
>>>>> [17] Test creation and deletion of trace instances while setting an event [PASS]
>>>>> [18] Test creation and deletion of trace instances [PASS]
>>>>> [19] Kprobe dynamic event - adding and removing [PASS]
>>>>> [20] Kprobe dynamic event - busy event check [PASS]
>>>>> [21] Kprobe dynamic event with arguments [PASS]
>>>>> [22] Kprobes event arguments with types [PASS]
>>>>> [23] Kprobe dynamic event with function tracer [PASS]
>>>>> [24] Kretprobe dynamic event with arguments [PASS]
>>>>> [25] Kretprobe dynamic event with maxactive [UNSUPPORTED]
>>>>> [26] event trigger - test event enable/disable trigger [PASS]
>>>>> [27] event trigger - test trigger filter [PASS]
>>>>> [28] event trigger - test histogram modifiers [PASS]
>>>>> [29] event trigger - test histogram trigger [PASS]
>>>>> [30] event trigger - test multiple histogram triggers [PASS]
>>>>> [31] event trigger - test snapshot-trigger [PASS]
>>>>> [32] event trigger - test stacktrace-trigger [PASS]
>>>>> [33] event trigger - test traceon/off trigger [PASS]
>>>>> [34] (instance) Basic test for tracers [PASS]
>>>>> [35] (instance) Basic trace clock test [PASS]
>>>>> [36] (instance) event tracing - enable/disable with event level files [PASS]
>>>>> [37] (instance) event tracing - restricts events based on pid [PASS]
>>>>> [38] (instance) event tracing - enable/disable with subsystem level files [PASS]
>>>>> [39] (instance) ftrace - test for function event triggers [UNSUPPORTED]
>>>>> [40] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
>>>>> [41] (instance) event trigger - test event enable/disable trigger [PASS]
>>>>> [42] (instance) event trigger - test trigger filter [PASS]
>>>>> [43] (instance) event trigger - test histogram modifiers [PASS]
>>>>> [44] (instance) event trigger - test histogram trigger [PASS]
>>>>> [45] (instance) event trigger - test multiple histogram triggers [PASS]
>>>>>
>>>>> # of passed: 41
>>>>> # of failed: 1
>>>>> # of unresolved: 0
>>>>> # of untested: 0
>>>>> # of unsupported: 3
>>>>> # of xfailed: 0
>>>>> # of undefined(test bug): 0
>
> I booted v4.12-rc4 with your config (didn't even have to change
> anything for my box), and checkout the v4.12-rc4 kernel on the test box
> and ran ftracetest. Here's my result:
>
> # of passed: 40
> # of failed: 0
> # of unresolved: 0
> # of untested: 0
> # of unsupported: 6
> # of xfailed: 0
> # of undefined(test bug): 0
>
> The unsupported were:
>
> [29] event trigger - test histogram modifiers [UNSUPPORTED]
> [30] event trigger - test histogram trigger [UNSUPPORTED]
> [31] event trigger - test multiple histogram triggers [UNSUPPORTED]
>
> [44] (instance) event trigger - test histogram modifiers [UNSUPPORTED]
> [45] (instance) event trigger - test histogram trigger [UNSUPPORTED]
> [46] (instance) event trigger - test multiple histogram triggers [UNSUPPORTED]
>
> Now why is this different? What compiler are you using to build your
> kernel?
>
gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)


I don't see any regressions. I use this system for stable release testing
and haven't seen any issues. Does ftrace have a dependency on a specific
gcc revision?


Full details:
gcc -v
Using built-in specs.
COLLECT_GCC=gcc
COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/6/lto-wrapper
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Ubuntu 6.3.0-12ubuntu2' --with-bugurl=file:///usr/share/doc/gcc-6/README.Bugs --enable-languages=c,ada,c++,java,go,d,fortran,objc,obj-c++ --prefix=/usr --program-suffix=-6 --program-prefix=x86_64-linux-gnu- --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --libdir=/usr/lib --enable-nls --with-sysroot=/ --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --with-default-libstdcxx-abi=new --enable-gnu-unique-object --disable-vtable-verify --enable-libmpx --enable-plugin --enable-default-pie --with-system-zlib --disable-browser-plugin --enable-java-awt=gtk --enable-gtk-cairo --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-6-amd64/jre --enable-java-home --with-jvm-root-dir=/usr/lib/jvm/java-1.5.0-gcj-6-amd64 --with-jvm-jar-dir=/usr/lib/jvm-exports/java-1.5.0-gcj-6-amd64 --with-arch-directory=amd64 --with-ecj-jar=/usr/share/java/eclipse-ecj.jar --with-target-system-zlib --enable-objc-gc=auto --enable-multiarch --disable-werror --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --enable-multilib --with-tune=generic --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)

gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)

thanks,
-- Shuah

2017-06-08 21:08:49

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Thu, 8 Jun 2017 14:06:23 -0600
Shuah Khan <[email protected]> wrote:

> >>>>> # of passed: 41
> >>>>> # of failed: 1
> >>>>> # of unresolved: 0
> >>>>> # of untested: 0
> >>>>> # of unsupported: 3
> >>>>> # of xfailed: 0
> >>>>> # of undefined(test bug): 0
> >
> > I booted v4.12-rc4 with your config (didn't even have to change
> > anything for my box), and checkout the v4.12-rc4 kernel on the test box
> > and ran ftracetest. Here's my result:
> >
> > # of passed: 40
> > # of failed: 0
> > # of unresolved: 0
> > # of untested: 0
> > # of unsupported: 6
> > # of xfailed: 0
> > # of undefined(test bug): 0
> >
> > The unsupported were:
> >
> > [29] event trigger - test histogram modifiers [UNSUPPORTED]
> > [30] event trigger - test histogram trigger [UNSUPPORTED]
> > [31] event trigger - test multiple histogram triggers [UNSUPPORTED]
> >
> > [44] (instance) event trigger - test histogram modifiers [UNSUPPORTED]
> > [45] (instance) event trigger - test histogram trigger [UNSUPPORTED]
> > [46] (instance) event trigger - test multiple histogram triggers [UNSUPPORTED]
> >
> > Now why is this different? What compiler are you using to build your
> > kernel?
> >
> gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)
>
>
> I don't see any regressions. I use this system for stable release testing
> and haven't seen any issues. Does ftrace have a dependency on a specific
> gcc revision?

It behaves differently with different gcc, as some support mfentry,
while others only use mcount. gcc 6.3.0 should be using mfentry. I'm
testing with 6.2, a build I made myself.

Just to confirm, you are running the 4.12-rc4 ftracetests on a 4.12-rc4
kernel and getting this error? Or are you running a different version
of ftracetest or a different version of the kernel?

-- Steve



>
>
> Full details:
> gcc -v
> Using built-in specs.
> COLLECT_GCC=gcc
> COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/6/lto-wrapper
> Target: x86_64-linux-gnu
> Configured with: ../src/configure -v --with-pkgversion='Ubuntu
> 6.3.0-12ubuntu2'
> --with-bugurl=file:///usr/share/doc/gcc-6/README.Bugs
> --enable-languages=c,ada,c++,java,go,d,fortran,objc,obj-c++
> --prefix=/usr --program-suffix=-6 --program-prefix=x86_64-linux-gnu-
> --enable-shared --enable-linker-build-id --libexecdir=/usr/lib
> --without-included-gettext --enable-threads=posix --libdir=/usr/lib
> --enable-nls --with-sysroot=/ --enable-clocale=gnu
> --enable-libstdcxx-debug --enable-libstdcxx-time=yes
> --with-default-libstdcxx-abi=new --enable-gnu-unique-object
> --disable-vtable-verify --enable-libmpx --enable-plugin
> --enable-default-pie --with-system-zlib --disable-browser-plugin
> --enable-java-awt=gtk --enable-gtk-cairo
> --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-6-amd64/jre
> --enable-java-home
> --with-jvm-root-dir=/usr/lib/jvm/java-1.5.0-gcj-6-amd64
> --with-jvm-jar-dir=/usr/lib/jvm-exports/java-1.5.0-gcj-6-amd64
> --with-arch-directory=amd64
> --with-ecj-jar=/usr/share/java/eclipse-ecj.jar
> --with-target-system-zlib --enable-objc-gc=auto --enable-multiarch
> --disable-werror --with-arch-32=i686 --with-abi=m64
> --with-multilib-list=m32,m64,mx32 --enable-multilib
> --with-tune=generic --enable-checking=release
> --build=x86_64-linux-gnu --host=x86_64-linux-gnu
> --target=x86_64-linux-gnu Thread model: posix gcc version 6.3.0
> 20170406 (Ubuntu 6.3.0-12ubuntu2)
>
> gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)
>
> thanks,
> -- Shuah

2017-06-08 21:12:01

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Wed, 7 Jun 2017 17:01:08 -0600
Shuah Khan <[email protected]> wrote:

> >>> [29] event trigger - test histogram trigger [PASS]
> >>> [30] event trigger - test multiple histogram triggers [PASS]
> >>> [31] event trigger - test snapshot-trigger [PASS]
> >>> [32] event trigger - test stacktrace-trigger [PASS]
> >>> [33] event trigger - test traceon/off trigger [PASS]
> >>> [34] (instance) Basic test for tracers [PASS]
> >>> [35] (instance) Basic trace clock test [PASS]
> >>> [36] (instance) event tracing - enable/disable with event level files [PASS]
> >>> [37] (instance) event tracing - restricts events based on pid [PASS]
> >>> [38] (instance) event tracing - enable/disable with subsystem level files [PASS]
> >>> [39] (instance) ftrace - test for function event triggers [UNSUPPORTED]
> >>> [40] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
> >>> [41] (instance) event trigger - test event enable/disable trigger [PASS]
> >>> [42] (instance) event trigger - test trigger filter [PASS]
> >>> [43] (instance) event trigger - test histogram modifiers [PASS]
> >>> [44] (instance) event trigger - test histogram trigger [PASS]
> >>> [45] (instance) event trigger - test multiple histogram triggers [PASS]

Are you sure you sent me the right config?

CONFIG_DYNAMIC_FTRACE_WITH_REGS=y
CONFIG_FUNCTION_PROFILER=y
CONFIG_FTRACE_MCOUNT_RECORD=y
# CONFIG_FTRACE_STARTUP_TEST is not set
CONFIG_MMIOTRACE=y
# CONFIG_HIST_TRIGGERS is not set

HIST_TRIGGERS is not set in your config, which should have made the
histogram trigger tests return UNSUPPORTED.

-- Steve

2017-06-08 21:14:23

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 06/08/2017 03:08 PM, Steven Rostedt wrote:
> On Thu, 8 Jun 2017 14:06:23 -0600
> Shuah Khan <[email protected]> wrote:
>
>>>>>>> # of passed: 41
>>>>>>> # of failed: 1
>>>>>>> # of unresolved: 0
>>>>>>> # of untested: 0
>>>>>>> # of unsupported: 3
>>>>>>> # of xfailed: 0
>>>>>>> # of undefined(test bug): 0
>>>
>>> I booted v4.12-rc4 with your config (didn't even have to change
>>> anything for my box), and checkout the v4.12-rc4 kernel on the test box
>>> and ran ftracetest. Here's my result:
>>>
>>> # of passed: 40
>>> # of failed: 0
>>> # of unresolved: 0
>>> # of untested: 0
>>> # of unsupported: 6
>>> # of xfailed: 0
>>> # of undefined(test bug): 0
>>>
>>> The unsupported were:
>>>
>>> [29] event trigger - test histogram modifiers [UNSUPPORTED]
>>> [30] event trigger - test histogram trigger [UNSUPPORTED]
>>> [31] event trigger - test multiple histogram triggers [UNSUPPORTED]
>>>
>>> [44] (instance) event trigger - test histogram modifiers [UNSUPPORTED]
>>> [45] (instance) event trigger - test histogram trigger [UNSUPPORTED]
>>> [46] (instance) event trigger - test multiple histogram triggers [UNSUPPORTED]
>>>
>>> Now why is this different? What compiler are you using to build your
>>> kernel?
>>>
>> gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)
>>
>>
>> I don't see any regressions. I use this system for stable release testing
>> and haven't seen any issues. Does ftrace have a dependency on a specific
>> gcc revision?
>
> It behaves differently with different gcc, as some support mfentry,
> while others only use mcount. gcc 6.3.0 should be using mfentry. I'm
> testing with 6.2, a build I made myself.
>
> Just to confirm, you are running the 4.12-rc4 ftracetests on a 4.12-rc4
> kernel and getting this error? Or are you running a different version
> of ftracetest or a different version of the kernel?
>

I am running 4.12-rc4 ftracetests on a 4.12-rc4 kernel. I did a headers
install before I built and ran kselftest.

btw tests should run on older kernels failing gracefully when feature isn't
supported and/or enabled.

So the expectation is for ftracetest to run cleanly skipping tests on older
kernels.

Would getting results for ftracetest on 4.11 with 4.11 ftracetest help you
with debug?

thanks,
-- Shuah

2017-06-08 21:26:32

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Thu, 8 Jun 2017 15:14:19 -0600
Shuah Khan <[email protected]> wrote:

> On 06/08/2017 03:08 PM, Steven Rostedt wrote:
> > On Thu, 8 Jun 2017 14:06:23 -0600
> > Shuah Khan <[email protected]> wrote:
> >
> >>>>>>> # of passed: 41
> >>>>>>> # of failed: 1
> >>>>>>> # of unresolved: 0
> >>>>>>> # of untested: 0
> >>>>>>> # of unsupported: 3
> >>>>>>> # of xfailed: 0
> >>>>>>> # of undefined(test bug): 0
> >>>
> >>> I booted v4.12-rc4 with your config (didn't even have to change
> >>> anything for my box), and checkout the v4.12-rc4 kernel on the test box
> >>> and ran ftracetest. Here's my result:
> >>>
> >>> # of passed: 40
> >>> # of failed: 0
> >>> # of unresolved: 0
> >>> # of untested: 0
> >>> # of unsupported: 6
> >>> # of xfailed: 0
> >>> # of undefined(test bug): 0
> >>>
> >>> The unsupported were:
> >>>
> >>> [29] event trigger - test histogram modifiers [UNSUPPORTED]
> >>> [30] event trigger - test histogram trigger [UNSUPPORTED]
> >>> [31] event trigger - test multiple histogram triggers [UNSUPPORTED]
> >>>
> >>> [44] (instance) event trigger - test histogram modifiers [UNSUPPORTED]
> >>> [45] (instance) event trigger - test histogram trigger [UNSUPPORTED]
> >>> [46] (instance) event trigger - test multiple histogram triggers [UNSUPPORTED]
> >>>
> >>> Now why is this different? What compiler are you using to build your
> >>> kernel?
> >>>
> >> gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)
> >>
> >>
> >> I don't see any regressions. I use this system for stable release testing
> >> and haven't seen any issues. Does ftrace have a dependency on a specific
> >> gcc revision?
> >
> > It behaves differently with different gcc, as some support mfentry,
> > while others only use mcount. gcc 6.3.0 should be using mfentry. I'm
> > testing with 6.2, a build I made myself.
> >
> > Just to confirm, you are running the 4.12-rc4 ftracetests on a 4.12-rc4
> > kernel and getting this error? Or are you running a different version
> > of ftracetest or a different version of the kernel?
> >
>
> I am running 4.12-rc4 ftracetests on a 4.12-rc4 kernel. I did a headers
> install before I built and ran kselftest.

Well, ftracetest is mainly bash scripts. So it shouldn't be affected by
any C libraries or headers.

>
> btw tests should run on older kernels failing gracefully when feature isn't
> supported and/or enabled.

Correct, it should do that.

>
> So the expectation is for ftracetest to run cleanly skipping tests on older
> kernels.

Note, when a bug is found, we do add the reproducer to ftracetest. So
depending on whether you have the latest stable, or the stable has a
fix, ftracetest can cause the machine to crash on older releases.

>
> Would getting results for ftracetest on 4.11 with 4.11 ftracetest help you
> with debug?
>

No, I'm trying to see why I get a completely different result from what
you have running the same version of the kernel, config and tests.

-- Steve

2017-06-08 21:33:44

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 06/08/2017 03:26 PM, Steven Rostedt wrote:
> On Thu, 8 Jun 2017 15:14:19 -0600
> Shuah Khan <[email protected]> wrote:
>
>> On 06/08/2017 03:08 PM, Steven Rostedt wrote:
>>> On Thu, 8 Jun 2017 14:06:23 -0600
>>> Shuah Khan <[email protected]> wrote:
>>>
>>>>>>>>> # of passed: 41
>>>>>>>>> # of failed: 1
>>>>>>>>> # of unresolved: 0
>>>>>>>>> # of untested: 0
>>>>>>>>> # of unsupported: 3
>>>>>>>>> # of xfailed: 0
>>>>>>>>> # of undefined(test bug): 0
>>>>>
>>>>> I booted v4.12-rc4 with your config (didn't even have to change
>>>>> anything for my box), and checkout the v4.12-rc4 kernel on the test box
>>>>> and ran ftracetest. Here's my result:
>>>>>
>>>>> # of passed: 40
>>>>> # of failed: 0
>>>>> # of unresolved: 0
>>>>> # of untested: 0
>>>>> # of unsupported: 6
>>>>> # of xfailed: 0
>>>>> # of undefined(test bug): 0
>>>>>
>>>>> The unsupported were:
>>>>>
>>>>> [29] event trigger - test histogram modifiers [UNSUPPORTED]
>>>>> [30] event trigger - test histogram trigger [UNSUPPORTED]
>>>>> [31] event trigger - test multiple histogram triggers [UNSUPPORTED]
>>>>>
>>>>> [44] (instance) event trigger - test histogram modifiers [UNSUPPORTED]
>>>>> [45] (instance) event trigger - test histogram trigger [UNSUPPORTED]
>>>>> [46] (instance) event trigger - test multiple histogram triggers [UNSUPPORTED]
>>>>>
>>>>> Now why is this different? What compiler are you using to build your
>>>>> kernel?
>>>>>
>>>> gcc version 6.3.0 20170406 (Ubuntu 6.3.0-12ubuntu2)
>>>>
>>>>
>>>> I don't see any regressions. I use this system for stable release testing
>>>> and haven't seen any issues. Does ftrace have a dependency on a specific
>>>> gcc revision?
>>>
>>> It behaves differently with different gcc, as some support mfentry,
>>> while others only use mcount. gcc 6.3.0 should be using mfentry. I'm
>>> testing with 6.2, a build I made myself.
>>>
>>> Just to confirm, you are running the 4.12-rc4 ftracetests on a 4.12-rc4
>>> kernel and getting this error? Or are you running a different version
>>> of ftracetest or a different version of the kernel?
>>>
>>
>> I am running 4.12-rc4 ftracetests on a 4.12-rc4 kernel. I did a headers
>> install before I built and ran kselftest.
>
> Well, ftracetest is mainly bash scripts. So it shouldn't be affected by
> any C libraries or headers.

Right. I was retracing my steps aloud :)

>
>>
>> btw tests should run on older kernels failing gracefully when feature isn't
>> supported and/or enabled.
>
> Correct, it should do that.
>
>>
>> So the expectation is for ftracetest to run cleanly skipping tests on older
>> kernels.
>
> Note, when a bug is found, we do add the reproducer to ftracetest. So
> depending on whether you have the latest stable, or the stable has a
> fix, ftracetest can cause the machine to crash on older releases.

Yeah - that could be problem, I would worry more if ftracetest can be run
as a non-root user. As ftracetest is intrusive in nature just like the timer
tests, we could say user needs to be aware.

If the outcome isn't desirable, we could run ftracetest conditionally as
a last resort. I think it is important for it to be run as part of kselftest
suite run.

thanks,
-- Shuah

2017-06-08 21:39:50

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Thu, 8 Jun 2017 15:33:39 -0600
Shuah Khan <[email protected]> wrote:


> > Note, when a bug is found, we do add the reproducer to ftracetest. So
> > depending on whether you have the latest stable, or the stable has a
> > fix, ftracetest can cause the machine to crash on older releases.
>
> Yeah - that could be problem, I would worry more if ftracetest can be run
> as a non-root user. As ftracetest is intrusive in nature just like the timer
> tests, we could say user needs to be aware.
>
> If the outcome isn't desirable, we could run ftracetest conditionally as
> a last resort. I think it is important for it to be run as part of kselftest
> suite run.

Well, I wouldn't worry too much. It shouldn't do any damage. And
anything that can trigger a bug in previous kernels should be
backported as well to the stable releases. Everyone runs the latest
stable kernels, right?

Also, did you see my reply about having the right config? You have
HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
your report.

One more thing, is this 100% reproducible. That is, does it always fail?

-- Steve

2017-06-08 21:44:12

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 06/08/2017 03:39 PM, Steven Rostedt wrote:
> On Thu, 8 Jun 2017 15:33:39 -0600
> Shuah Khan <[email protected]> wrote:
>
>
>>> Note, when a bug is found, we do add the reproducer to ftracetest. So
>>> depending on whether you have the latest stable, or the stable has a
>>> fix, ftracetest can cause the machine to crash on older releases.
>>
>> Yeah - that could be problem, I would worry more if ftracetest can be run
>> as a non-root user. As ftracetest is intrusive in nature just like the timer
>> tests, we could say user needs to be aware.
>>
>> If the outcome isn't desirable, we could run ftracetest conditionally as
>> a last resort. I think it is important for it to be run as part of kselftest
>> suite run.
>
> Well, I wouldn't worry too much. It shouldn't do any damage. And
> anything that can trigger a bug in previous kernels should be
> backported as well to the stable releases. Everyone runs the latest
> stable kernels, right?
>
> Also, did you see my reply about having the right config? You have
> HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
> your report.

I did see that one. Didn't get a chance to look at that yet. Do you expect
the tests to be skipped in this case? Could it be that tests aren't run?
I will look at this and let you know what I find on my test system.

>
> One more thing, is this 100% reproducible. That is, does it always fail?
>
Failed the two times I tried.

thanks,
-- Shuah


2017-06-08 21:51:49

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Thu, 8 Jun 2017 15:44:08 -0600
Shuah Khan <[email protected]> wrote:

> > Also, did you see my reply about having the right config? You have
> > HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
> > your report.
>
> I did see that one. Didn't get a chance to look at that yet. Do you expect
> the tests to be skipped in this case? Could it be that tests aren't run?
> I will look at this and let you know what I find on my test system.

Your first email showed that they passed, which would be hard to do
since the feature is not even enabled. ftracetest is very much set up
to look at the existing pseudo files to determine if a feature exists
or not, and if it does not, it returns "UNSUPPORTED". If it returned
PASSED when the feature is not enabled, that would be a big time bug in
the test.

>
> >
> > One more thing, is this 100% reproducible. That is, does it always fail?
> >
> Failed the two times I tried.

Great to hear. I like reproducibility :-)

-- Steve

2017-06-14 02:12:30

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

Hi Shuah and Steve,

Sorry for replying so late...

On Thu, 8 Jun 2017 17:51:44 -0400
Steven Rostedt <[email protected]> wrote:

> On Thu, 8 Jun 2017 15:44:08 -0600
> Shuah Khan <[email protected]> wrote:
>
> > > Also, did you see my reply about having the right config? You have
> > > HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
> > > your report.
> >
> > I did see that one. Didn't get a chance to look at that yet. Do you expect
> > the tests to be skipped in this case? Could it be that tests aren't run?
> > I will look at this and let you know what I find on my test system.
>
> Your first email showed that they passed, which would be hard to do
> since the feature is not even enabled. ftracetest is very much set up
> to look at the existing pseudo files to determine if a feature exists
> or not, and if it does not, it returns "UNSUPPORTED". If it returned
> PASSED when the feature is not enabled, that would be a big time bug in
> the test.

As far as I can see, what Steve you saw was my result on the 4.9 stable
kernel, which had been compiled with fully ftrace enabled :).

> >
> > >
> > > One more thing, is this 100% reproducible. That is, does it always fail?
> > >
> > Failed the two times I tried.

I've also tried to test the latest linus tree with this series with Shuah's
config on qemu, and could not reproduced it. (I attached the log)
As you can see, with Shuah's config, histogram tests are marked UNSUPPORTED.

Of course, that is 4.12.0-rc5+ and kconfig is a bit tweaked(attached).
I'll try kselftest tree too.

Thank you,

>
> Great to hear. I like reproducibility :-)
>
> -- Steve
>


--
Masami Hiramatsu <[email protected]>


Attachments:
ftracetest.log (2.76 kB)
mhiramat.config (181.77 kB)
Download all attachments

2017-06-14 04:53:19

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On Wed, 14 Jun 2017 11:12:17 +0900
Masami Hiramatsu <[email protected]> wrote:

> Hi Shuah and Steve,
>
> Sorry for replying so late...
>
> On Thu, 8 Jun 2017 17:51:44 -0400
> Steven Rostedt <[email protected]> wrote:
>
> > On Thu, 8 Jun 2017 15:44:08 -0600
> > Shuah Khan <[email protected]> wrote:
> >
> > > > Also, did you see my reply about having the right config? You have
> > > > HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
> > > > your report.
> > >
> > > I did see that one. Didn't get a chance to look at that yet. Do you expect
> > > the tests to be skipped in this case? Could it be that tests aren't run?
> > > I will look at this and let you know what I find on my test system.
> >
> > Your first email showed that they passed, which would be hard to do
> > since the feature is not even enabled. ftracetest is very much set up
> > to look at the existing pseudo files to determine if a feature exists
> > or not, and if it does not, it returns "UNSUPPORTED". If it returned
> > PASSED when the feature is not enabled, that would be a big time bug in
> > the test.
>
> As far as I can see, what Steve you saw was my result on the 4.9 stable
> kernel, which had been compiled with fully ftrace enabled :).
>
> > >
> > > >
> > > > One more thing, is this 100% reproducible. That is, does it always fail?
> > > >
> > > Failed the two times I tried.
>
> I've also tried to test the latest linus tree with this series with Shuah's
> config on qemu, and could not reproduced it. (I attached the log)
> As you can see, with Shuah's config, histogram tests are marked UNSUPPORTED.
>
> Of course, that is 4.12.0-rc5+ and kconfig is a bit tweaked(attached).
> I'll try kselftest tree too.

I've tried it on linux-kselftest/next, but not able to reproduce it...

Thank you,

>
> Thank you,
>
> >
> > Great to hear. I like reproducibility :-)
> >
> > -- Steve
> >
>
>
> --
> Masami Hiramatsu <[email protected]>


--
Masami Hiramatsu <[email protected]>

2017-06-14 14:17:50

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

Hi Masami,

On 06/13/2017 10:53 PM, Masami Hiramatsu wrote:
> On Wed, 14 Jun 2017 11:12:17 +0900
> Masami Hiramatsu <[email protected]> wrote:
>
>> Hi Shuah and Steve,
>>
>> Sorry for replying so late...
>>
>> On Thu, 8 Jun 2017 17:51:44 -0400
>> Steven Rostedt <[email protected]> wrote:
>>
>>> On Thu, 8 Jun 2017 15:44:08 -0600
>>> Shuah Khan <[email protected]> wrote:
>>>
>>>>> Also, did you see my reply about having the right config? You have
>>>>> HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
>>>>> your report.
>>>>
>>>> I did see that one. Didn't get a chance to look at that yet. Do you expect
>>>> the tests to be skipped in this case? Could it be that tests aren't run?
>>>> I will look at this and let you know what I find on my test system.
>>>
>>> Your first email showed that they passed, which would be hard to do
>>> since the feature is not even enabled. ftracetest is very much set up
>>> to look at the existing pseudo files to determine if a feature exists
>>> or not, and if it does not, it returns "UNSUPPORTED". If it returned
>>> PASSED when the feature is not enabled, that would be a big time bug in
>>> the test.
>>
>> As far as I can see, what Steve you saw was my result on the 4.9 stable
>> kernel, which had been compiled with fully ftrace enabled :).
>>
>>>>
>>>>>
>>>>> One more thing, is this 100% reproducible. That is, does it always fail?
>>>>>
>>>> Failed the two times I tried.
>>
>> I've also tried to test the latest linus tree with this series with Shuah's
>> config on qemu, and could not reproduced it. (I attached the log)
>> As you can see, with Shuah's config, histogram tests are marked UNSUPPORTED.
>>
>> Of course, that is 4.12.0-rc5+ and kconfig is a bit tweaked(attached).
>> I'll try kselftest tree too.
>
> I've tried it on linux-kselftest/next, but not able to reproduce it...
>
> Thank you,

Hmm. Not sure what's happening on my test system. I will try it one more
time with a clean build and see what happens.

Thanks for debugging this.

-- Shuah

2017-06-30 14:18:34

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH 0/7] selftests/ftrace: Some improvements of ftracetest

On 06/14/2017 08:17 AM, Shuah Khan wrote:
> Hi Masami,
>
> On 06/13/2017 10:53 PM, Masami Hiramatsu wrote:
>> On Wed, 14 Jun 2017 11:12:17 +0900
>> Masami Hiramatsu <[email protected]> wrote:
>>
>>> Hi Shuah and Steve,
>>>
>>> Sorry for replying so late...
>>>
>>> On Thu, 8 Jun 2017 17:51:44 -0400
>>> Steven Rostedt <[email protected]> wrote:
>>>
>>>> On Thu, 8 Jun 2017 15:44:08 -0600
>>>> Shuah Khan <[email protected]> wrote:
>>>>
>>>>>> Also, did you see my reply about having the right config? You have
>>>>>> HIST_TRIGGERS undefined but yet the histogram trigger tests all pass in
>>>>>> your report.
>>>>>
>>>>> I did see that one. Didn't get a chance to look at that yet. Do you expect
>>>>> the tests to be skipped in this case? Could it be that tests aren't run?
>>>>> I will look at this and let you know what I find on my test system.
>>>>
>>>> Your first email showed that they passed, which would be hard to do
>>>> since the feature is not even enabled. ftracetest is very much set up
>>>> to look at the existing pseudo files to determine if a feature exists
>>>> or not, and if it does not, it returns "UNSUPPORTED". If it returned
>>>> PASSED when the feature is not enabled, that would be a big time bug in
>>>> the test.
>>>
>>> As far as I can see, what Steve you saw was my result on the 4.9 stable
>>> kernel, which had been compiled with fully ftrace enabled :).
>>>
>>>>>
>>>>>>
>>>>>> One more thing, is this 100% reproducible. That is, does it always fail?
>>>>>>
>>>>> Failed the two times I tried.
>>>
>>> I've also tried to test the latest linus tree with this series with Shuah's
>>> config on qemu, and could not reproduced it. (I attached the log)
>>> As you can see, with Shuah's config, histogram tests are marked UNSUPPORTED.
>>>
>>> Of course, that is 4.12.0-rc5+ and kconfig is a bit tweaked(attached).
>>> I'll try kselftest tree too.
>>
>> I've tried it on linux-kselftest/next, but not able to reproduce it...
>>
>> Thank you,
>
> Hmm. Not sure what's happening on my test system. I will try it one more
> time with a clean build and see what happens.
>
> Thanks for debugging this.
>

Re-tested this on my test system on 4.12-rc7. No failures. Not sure why I was
seeing problems. It works now.

thanks,
-- Shuah