On Wed, 7 Jun 2017 16:42:55 -0600
Shuah Khan <shuah@xxxxxxxxxx> 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) <mhiramat@xxxxxxxxxx>
> >
> >
>
> 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
--
To unsubscribe from this list: send the line "unsubscribe linux-kselftest" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
