Re: perf report warnings on tracepoint events hidden by ui

[David Carrillo-Cisneros]

>>
>> 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:

I was running an internal version. I found the bug in an internal
commit. It's true that upstream is all good.

Thank you for checking,
David

Re: perf report warnings on tracepoint events hidden by ui

[David Carrillo-Cisneros]

>>
>> 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:

I was running an internal version. I found the bug in an internal
commit. It's true that upstream is all good.

Thank you for checking,
David

Re: perf report warnings on tracepoint events hidden by ui

[David Carrillo-Cisneros]

>
> But I don't see any warning when I run it with --stdio.  Could you
> show me the format file of sys_enter_mmap?

I found the problem. The kernel version I was testing on fails to
initialize some fields in the tracepoint structure, so my format
looked like:

# cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_mmap/format
name: sys_enter_mmap
ID: 144
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: "addr: 0x%08lx, len: 0x%08lx, prot: 0x%08lx, flags:
0x%08lx, fd: 0x%08lx, off: 0x%08lx", ((unsigned long)(REC->addr)),
((unsigned long)(REC->len)), ((unsigned long)(REC->prot)), ((unsigned
long)(REC->flags)), ((unsigned long)(REC->fd)), ((unsigned
long)(REC->off))

rather than:

name: sys_enter_mmap
ID: 111
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;

field:int nr;   offset:8;   size:4; signed:1;
field:unsigned long addr;   offset:16;  size:8; signed:0;
field:unsigned long len;offset:24;  size:8; signed:0;
field:unsigned long prot;   offset:32;  size:8; signed:0;
field:unsigned long flags;  offset:40;  size:8; signed:0;
field:unsigned long fd; offset:48;  size:8; signed:0;
field:unsigned long off;offset:56;  size:8; signed:0;

print fmt: "addr: 0x%08lx, len: 0x%08lx, prot: 0x%08lx, flags:
0x%08lx, fd: 0x%08lx, off: 0x%08lx", ((unsigned long)(REC->addr)),
((unsigned long)(REC->len)), ((unsigned long)(REC->prot)), ((unsigned
long)(REC->flags)), ((unsigned long)(REC->fd)), ((unsigned
long)(REC->off))


Upstream is all good. It was my oversight not testing there first.

Thanks,
David

Re: perf report warnings on tracepoint events hidden by ui

[David Carrillo-Cisneros]

>
> But I don't see any warning when I run it with --stdio.  Could you
> show me the format file of sys_enter_mmap?

I found the problem. The kernel version I was testing on fails to
initialize some fields in the tracepoint structure, so my format
looked like:

# cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_mmap/format
name: sys_enter_mmap
ID: 144
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: "addr: 0x%08lx, len: 0x%08lx, prot: 0x%08lx, flags:
0x%08lx, fd: 0x%08lx, off: 0x%08lx", ((unsigned long)(REC->addr)),
((unsigned long)(REC->len)), ((unsigned long)(REC->prot)), ((unsigned
long)(REC->flags)), ((unsigned long)(REC->fd)), ((unsigned
long)(REC->off))

rather than:

name: sys_enter_mmap
ID: 111
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;

field:int nr;   offset:8;   size:4; signed:1;
field:unsigned long addr;   offset:16;  size:8; signed:0;
field:unsigned long len;offset:24;  size:8; signed:0;
field:unsigned long prot;   offset:32;  size:8; signed:0;
field:unsigned long flags;  offset:40;  size:8; signed:0;
field:unsigned long fd; offset:48;  size:8; signed:0;
field:unsigned long off;offset:56;  size:8; signed:0;

print fmt: "addr: 0x%08lx, len: 0x%08lx, prot: 0x%08lx, flags:
0x%08lx, fd: 0x%08lx, off: 0x%08lx", ((unsigned long)(REC->addr)),
((unsigned long)(REC->len)), ((unsigned long)(REC->prot)), ((unsigned
long)(REC->flags)), ((unsigned long)(REC->fd)), ((unsigned
long)(REC->off))


Upstream is all good. It was my oversight not testing there first.

Thanks,
David

Re: perf report warnings on tracepoint events hidden by ui

[Namhyung Kim]

Hi,

On Fri, Apr 28, 2017 at 9:31 AM, David Carrillo-Cisneros
 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.

Yep, currently perf report TUI hides warnings since there's no space
to show them.

>
>   $ 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
>
>   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?

But I don't see any warning when I run it with --stdio.  Could you
show me the format file of sys_enter_mmap?


Thanks,
Namhyung

Re: perf report warnings on tracepoint events hidden by ui

[Namhyung Kim]

Hi,

On Fri, Apr 28, 2017 at 9:31 AM, David Carrillo-Cisneros
 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.

Yep, currently perf report TUI hides warnings since there's no space
to show them.

>
>   $ 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
>
>   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?

But I don't see any warning when I run it with --stdio.  Could you
show me the format file of sys_enter_mmap?


Thanks,
Namhyung

Re: perf report warnings on tracepoint events hidden by ui

[Steven Rostedt]

On Thu, 27 Apr 2017 20:51:28 -0600
David Ahern  wrote:

> On 4/27/17 8:49 PM, Steven Rostedt wrote:
> > On Thu, 27 Apr 2017 20:13:43 -0600
> > David Ahern  wrote:
> >   
> >> On 4/27/17 7:41 PM, Steven Rostedt wrote:  
> >>> On Thu, 27 Apr 2017 19:31:12 -0500
> >>> David Carrillo-Cisneros  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
> >>
> >> '-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.  
> > 
> > New kernels have both syscalls and raw_syscalls. The raw_syscalls are
> > the true tracepoints that the syscalls use. His option works on
> > 4.11-rc8.  
> 
> 
> What's old is new again?
> 
> root@kenny-jessie4:~# uname -a
> Linux kenny-jessie4 4.11.0-rc8+ #258 SMP Thu Apr 27 08:36:06 PDT 2017
> x86_64 GNU/Linux
> 
> root@kenny-jessie4:~# perf list | grep syscalls
>   raw_syscalls:sys_enter [Tracepoint event]
>   raw_syscalls:sys_exit  [Tracepoint event]
> 
> 
> Is an option needed to enable syscalls vs raw_syscalls?

Yep!

CONFIG_FTRACE_SYSCALLS=y

-- Steve

Re: perf report warnings on tracepoint events hidden by ui

[Steven Rostedt]

On Thu, 27 Apr 2017 20:51:28 -0600
David Ahern  wrote:

> On 4/27/17 8:49 PM, Steven Rostedt wrote:
> > On Thu, 27 Apr 2017 20:13:43 -0600
> > David Ahern  wrote:
> >   
> >> On 4/27/17 7:41 PM, Steven Rostedt wrote:  
> >>> On Thu, 27 Apr 2017 19:31:12 -0500
> >>> David Carrillo-Cisneros  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
> >>
> >> '-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.  
> > 
> > New kernels have both syscalls and raw_syscalls. The raw_syscalls are
> > the true tracepoints that the syscalls use. His option works on
> > 4.11-rc8.  
> 
> 
> What's old is new again?
> 
> root@kenny-jessie4:~# uname -a
> Linux kenny-jessie4 4.11.0-rc8+ #258 SMP Thu Apr 27 08:36:06 PDT 2017
> x86_64 GNU/Linux
> 
> root@kenny-jessie4:~# perf list | grep syscalls
>   raw_syscalls:sys_enter [Tracepoint event]
>   raw_syscalls:sys_exit  [Tracepoint event]
> 
> 
> Is an option needed to enable syscalls vs raw_syscalls?

Yep!

CONFIG_FTRACE_SYSCALLS=y

-- Steve

Re: perf report warnings on tracepoint events hidden by ui

[David Ahern]

On 4/27/17 8:49 PM, Steven Rostedt wrote:
> On Thu, 27 Apr 2017 20:13:43 -0600
> David Ahern  wrote:
> 
>> On 4/27/17 7:41 PM, Steven Rostedt wrote:
>>> On Thu, 27 Apr 2017 19:31:12 -0500
>>> David Carrillo-Cisneros  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  
>>
>> '-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.
> 
> New kernels have both syscalls and raw_syscalls. The raw_syscalls are
> the true tracepoints that the syscalls use. His option works on
> 4.11-rc8.


What's old is new again?

root@kenny-jessie4:~# uname -a
Linux kenny-jessie4 4.11.0-rc8+ #258 SMP Thu Apr 27 08:36:06 PDT 2017
x86_64 GNU/Linux

root@kenny-jessie4:~# perf list | grep syscalls
  raw_syscalls:sys_enter [Tracepoint event]
  raw_syscalls:sys_exit  [Tracepoint event]


Is an option needed to enable syscalls vs raw_syscalls?

Re: perf report warnings on tracepoint events hidden by ui

[David Ahern]

On 4/27/17 8:49 PM, Steven Rostedt wrote:
> On Thu, 27 Apr 2017 20:13:43 -0600
> David Ahern  wrote:
> 
>> On 4/27/17 7:41 PM, Steven Rostedt wrote:
>>> On Thu, 27 Apr 2017 19:31:12 -0500
>>> David Carrillo-Cisneros  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  
>>
>> '-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.
> 
> New kernels have both syscalls and raw_syscalls. The raw_syscalls are
> the true tracepoints that the syscalls use. His option works on
> 4.11-rc8.


What's old is new again?

root@kenny-jessie4:~# uname -a
Linux kenny-jessie4 4.11.0-rc8+ #258 SMP Thu Apr 27 08:36:06 PDT 2017
x86_64 GNU/Linux

root@kenny-jessie4:~# perf list | grep syscalls
  raw_syscalls:sys_enter [Tracepoint event]
  raw_syscalls:sys_exit  [Tracepoint event]


Is an option needed to enable syscalls vs raw_syscalls?

Re: perf report warnings on tracepoint events hidden by ui

[Steven Rostedt]

On Thu, 27 Apr 2017 20:13:43 -0600
David Ahern  wrote:

> On 4/27/17 7:41 PM, Steven Rostedt wrote:
> > On Thu, 27 Apr 2017 19:31:12 -0500
> > David Carrillo-Cisneros  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  
> 
> '-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.

New kernels have both syscalls and raw_syscalls. The raw_syscalls are
the true tracepoints that the syscalls use. His option works on
4.11-rc8.

-- Steve


> 
> 
> See the note I put into tools/perf/builtin-trace.c:
> 
> static struct perf_evsel *perf_evsel__syscall_newtp(const char
> *direction, void *handler)
> {
> struct perf_evsel *evsel = perf_evsel__newtp("raw_syscalls",
> direction);
> 
> /* older kernel (e.g., RHEL6) use syscalls:{enter,exit} */
> if (IS_ERR(evsel))
> evsel = perf_evsel__newtp("syscalls", direction);
> 
> 
> Are you running top of tree perf on RHEL6?

Re: perf report warnings on tracepoint events hidden by ui

[Steven Rostedt]

On Thu, 27 Apr 2017 20:13:43 -0600
David Ahern  wrote:

> On 4/27/17 7:41 PM, Steven Rostedt wrote:
> > On Thu, 27 Apr 2017 19:31:12 -0500
> > David Carrillo-Cisneros  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  
> 
> '-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.

New kernels have both syscalls and raw_syscalls. The raw_syscalls are
the true tracepoints that the syscalls use. His option works on
4.11-rc8.

-- Steve


> 
> 
> See the note I put into tools/perf/builtin-trace.c:
> 
> static struct perf_evsel *perf_evsel__syscall_newtp(const char
> *direction, void *handler)
> {
> struct perf_evsel *evsel = perf_evsel__newtp("raw_syscalls",
> direction);
> 
> /* older kernel (e.g., RHEL6) use syscalls:{enter,exit} */
> if (IS_ERR(evsel))
> evsel = perf_evsel__newtp("syscalls", direction);
> 
> 
> Are you running top of tree perf on RHEL6?

Re: perf report warnings on tracepoint events hidden by ui

[David Ahern]

On 4/27/17 7:41 PM, Steven Rostedt wrote:
> On Thu, 27 Apr 2017 19:31:12 -0500
> David Carrillo-Cisneros  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

'-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.


See the note I put into tools/perf/builtin-trace.c:

static struct perf_evsel *perf_evsel__syscall_newtp(const char
*direction, void *handler)
{
struct perf_evsel *evsel = perf_evsel__newtp("raw_syscalls",
direction);

/* older kernel (e.g., RHEL6) use syscalls:{enter,exit} */
if (IS_ERR(evsel))
evsel = perf_evsel__newtp("syscalls", direction);


Are you running top of tree perf on RHEL6?

Re: perf report warnings on tracepoint events hidden by ui

[David Ahern]

On 4/27/17 7:41 PM, Steven Rostedt wrote:
> On Thu, 27 Apr 2017 19:31:12 -0500
> David Carrillo-Cisneros  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

'-e syscalls' vs raw_syscalls suggests an older kernel -- like RHEL6.


See the note I put into tools/perf/builtin-trace.c:

static struct perf_evsel *perf_evsel__syscall_newtp(const char
*direction, void *handler)
{
struct perf_evsel *evsel = perf_evsel__newtp("raw_syscalls",
direction);

/* older kernel (e.g., RHEL6) use syscalls:{enter,exit} */
if (IS_ERR(evsel))
evsel = perf_evsel__newtp("syscalls", direction);


Are you running top of tree perf on RHEL6?

Re: perf report warnings on tracepoint events hidden by ui

[Steven Rostedt]

On Thu, 27 Apr 2017 19:31:12 -0500
David Carrillo-Cisneros  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: 0x, len: 0x2000, prot: 0x0003, flags: 
0x0022, fd: 0x, off: 0x
16.67%  addr: 0x, len: 0x00023bec, prot: 0x0001, flags: 
0x0002, fd: 0x0004, off: 0x
16.67%  addr: 0x, len: 0x003c5960, prot: 0x0005, flags: 
0x0802, fd: 0x0004, off: 0x
16.67%  addr: 0x7f9db5be2000, len: 0x6000, prot: 0x0003, flags: 
0x0812, fd: 0x0004, off: 0x001bc000
16.67%  addr: 0x7f9db5be8000, len: 0x3960, prot: 0x0003, flags: 
0x0032, fd: 0x, off: 0x


#
# (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

Re: perf report warnings on tracepoint events hidden by ui

[Steven Rostedt]

On Thu, 27 Apr 2017 19:31:12 -0500
David Carrillo-Cisneros  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: 0x, len: 0x2000, prot: 0x0003, flags: 
0x0022, fd: 0x, off: 0x
16.67%  addr: 0x, len: 0x00023bec, prot: 0x0001, flags: 
0x0002, fd: 0x0004, off: 0x
16.67%  addr: 0x, len: 0x003c5960, prot: 0x0005, flags: 
0x0802, fd: 0x0004, off: 0x
16.67%  addr: 0x7f9db5be2000, len: 0x6000, prot: 0x0003, flags: 
0x0812, fd: 0x0004, off: 0x001bc000
16.67%  addr: 0x7f9db5be8000, len: 0x3960, prot: 0x0003, flags: 
0x0032, fd: 0x, off: 0x


#
# (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