trace-cmd: Using the python wrapping to read trace markers

trace-cmd: Using the python wrapping to read trace markers

[Sharon Gabay]

Hi !

We are using this article to generate trace markers:
https://lwn.net/Articles/366796/

I am responsible for reading the trace.dat binary into our tools and we are using the trace-cmd python wrapping.

I'm trying to use the python wrapping in order to read trace markers, so far unsuccessfully (See below). I've noticed that the trace marker string is written directly into the event, without using pointers, indices etc, and that the size field in this case equals zero (in bold, below). So I'm guessing that the way to read it is a bit different (using the method for reading regular string field does not seem to work). Here's how the event description looks like inside trace.dat:

name: print
ID: 5
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:unsigned char common_migrate_disable;     offset:8;       size:1; signed:0;
        field:unsigned char common_preempt_lazy_count;  offset:9;       size:1; signed:0;
        field:unsigned long ip; offset:16;      size:8; signed:0;
        field:char buf[];       offset:24;      size:0; signed:1;
print fmt: "%ps: %s", (void *)REC->ip, REC->buf

And here are some of the methods I've tried to access the "buf" field above:
field_name = "buf"
// method 1:
f = tep_find_any_field(self._event, field_name)
if f is None:
    return None
str = py_field_get_str(f, self._record) // (returns empty string)

// method 2:
f = tep_find_any_field(self._event, name)
if f is None:
    return None
data = py_field_get_data(f, self._record) // (returns empty buffer)

Thanks in advance,
Sharon Gabay

Re: trace-cmd: Using the python wrapping to read trace markers

[Tzvetomir Stoyanov]

On Sun, Sep 11, 2022 at 11:03 PM Sharon Gabay <Sharon.Gabay@mobileye.com> wrote:
>
> Hi !

Hi Sharon,

>
> We are using this article to generate trace markers:
> https://lwn.net/Articles/366796/
>
> I am responsible for reading the trace.dat binary into our tools and we are using the trace-cmd python wrapping.

The trace-cmd python wrappers are auto generated. The logic for that
may not be up to date, so I do not know what is the current state of
those wrappers.

>
> I'm trying to use the python wrapping in order to read trace markers, so far unsuccessfully (See below). I've noticed that the trace marker string is written directly into the event, without using pointers, indices etc, and that the size field in this case equals zero (in bold, below). So I'm guessing that the way to read it is a bit different (using the method for reading regular string field does not seem to work). Here's how the event description looks like inside trace.dat:
>
> name: print
> ID: 5
> 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:unsigned char common_migrate_disable;     offset:8;       size:1; signed:0;
>         field:unsigned char common_preempt_lazy_count;  offset:9;       size:1; signed:0;
>         field:unsigned long ip; offset:16;      size:8; signed:0;
>         field:char buf[];       offset:24;      size:0; signed:1;
> print fmt: "%ps: %s", (void *)REC->ip, REC->buf
>
> And here are some of the methods I've tried to access the "buf" field above:
> field_name = "buf"
> // method 1:
> f = tep_find_any_field(self._event, field_name)
> if f is None:
>     return None
> str = py_field_get_str(f, self._record) // (returns empty string)
>
> // method 2:
> f = tep_find_any_field(self._event, name)
> if f is None:
>     return None
> data = py_field_get_data(f, self._record) // (returns empty buffer)
>

This is the flow that should work in your case, but I do not know if
it can be implemented with the existing python wrappers :

 1. Get the ID of the trace marker event. Event IDs are assigned at
kernel boot time, so the ID can be different, depending on the ftace
configuration:
     event = tep_find_event_by_name(tep, "ftrace", "print"), if you
are using the "trace_marker" file to inject marker events, or
     event = tep_find_event_by_name(tep, "ftrace", "raw_data"), if you
are using the "trace_marker_raw" file.
     marker_id = event->id
2. Iterate over the events from the file and look for events with id
== marker_id. For these events, you can the field with name "buf",
either as string or as binary buffer.

> Thanks in advance,

Thanks for using trace-cmd and helping to improve it!

If you are interested in writing Python programs for ftrace tracing, I
would encourage to try trace-cruncher:
  https://github.com/vmware/trace-cruncher
Although it is still in its beta development stage, it is quite useful
for use cases such as yours. Take a look at examples/sched_wakeup.py
file - it does exactly what you want to achieve. That example opens a
trace.dat file, iterates over all events from it looking for specific
events.

> Sharon Gabay




--
Tzvetomir (Ceco) Stoyanov
VMware Open Source Technology Center

Re: trace-cmd: Using the python wrapping to read trace markers

[Steven Rostedt]

On Mon, 12 Sep 2022 12:47:09 +0300
Tzvetomir Stoyanov <tz.stoyanov@gmail.com> wrote:

> Hi Sharon,
> 
> >
> > We are using this article to generate trace markers:
> > https://lwn.net/Articles/366796/
> >
> > I am responsible for reading the trace.dat binary into our tools and we are using the trace-cmd python wrapping.  
> 
> The trace-cmd python wrappers are auto generated. The logic for that
> may not be up to date, so I do not know what is the current state of
> those wrappers.

Thanks Tzvetomir for responding, and yes, trace-cruncher is something
to look at in this case.

Sharon,

I and many others that could help out with the wrapper code are
currently attending Linux Plumbers in Dublin (https://lpc.events), and
are not able to look into this at the moment. If we remember ( ;-) )
we'll look at this in a couple of weeks.

-- Steve