Messages in this thread | | | Date | Thu, 27 Apr 2017 21:41:47 -0400 | From | Steven Rostedt <> | Subject | Re: perf report warnings on tracepoint events hidden by ui |
| |
On Thu, 27 Apr 2017 19:31:12 -0500 David Carrillo-Cisneros <davidcc@google.com> wrote:
> When processing tracepoint events, perf report outputs warnings about > field not founds. The warnings are usually hidden by perf report UI > and appear when using the --stdio option. e.g. > > $ perf record -e syscalls:sys_enter_mmap some_load > > $ perf report --stdio > > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field addr not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field len not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field prot not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field flags not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field fd not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field off not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field addr not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field len not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field prot not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field flags not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field fd not found > Warning: [syscalls:sys_enter_mmap] eval_num_arg: field off not found > > I bisected the warnings to: > commit d49dadea78624 ("perf tools: Make 'trace' or 'trace_fields' > sort key default for tracepoint events"). > > that introduced sorting by trace. The event's format in my example is: > > $ cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_socket/format
It's not sys_enter_socket, it's sys_enter_mmap.
> > name: sys_enter_socket > ID: 1850 > format: > field:unsigned short common_type; offset:0; > size:2; signed:0; > field:unsigned char common_flags; offset:2; > size:1; signed:0; > field:unsigned char common_preempt_count; offset:3; > size:1; signed:0; > field:int common_pid; offset:4; size:4; signed:1; > > print fmt: "family: 0x%08lx, type: 0x%08lx, protocol: 0x%08lx", > ((unsigned long)(REC->family)), ((unsigned long)(REC->type)), > ((unsigned long)(REC->protocol)) > > > An appears to be correctly parsed by event_read_print in > tools/lib/tracevent/event-parse.c . Has anyone seen this before?
What kernel are you running?
I just built and booted v4.11-rc8 with a v4.11-rc8 perf:
+------------------+
[root@bxtest ~]# perf record -e syscalls:sys_enter_mmap /work/c/hackbench 10 Time: 4.896 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.049 MB perf.data (6 samples) ] [root@bxtest ~]# perf report --stdio # To display the perf.data header info, please use --header/--header-only options. # # # Total Lost Samples: 0 # # Samples: 6 of event 'syscalls:sys_enter_mmap' # Event count (approx.): 6 # # Overhead Trace output # ........ ................................................................................................................... # 33.33% addr: 0x00000000, len: 0x00002000, prot: 0x00000003, flags: 0x00000022, fd: 0xffffffffffffffff, off: 0x00000000 16.67% addr: 0x00000000, len: 0x00023bec, prot: 0x00000001, flags: 0x00000002, fd: 0x00000004, off: 0x00000000 16.67% addr: 0x00000000, len: 0x003c5960, prot: 0x00000005, flags: 0x00000802, fd: 0x00000004, off: 0x00000000 16.67% addr: 0x7f9db5be2000, len: 0x00006000, prot: 0x00000003, flags: 0x00000812, fd: 0x00000004, off: 0x001bc000 16.67% addr: 0x7f9db5be8000, len: 0x00003960, prot: 0x00000003, flags: 0x00000032, fd: 0xffffffffffffffff, off: 0x00000000
# # (Tip: If you have debuginfo enabled, try: perf report -s sym,srcline) # [root@bxtest ~]# perf --version perf version 4.11.rc8.g5a7ad11
+------------------+
Seems fine to me.
-- Steve
| |