Re: [PATCH v2 11/11] perf python tracepoint: Switch to using parse_events

[Arnaldo Carvalho de Melo <acme@kernel.org>]

On Tue, Mar 11, 2025 at 12:32:05PM -0300, Arnaldo Carvalho de Melo wrote:
>                 if (field->flags & TEP_FIELD_IS_STRING &&
>                     is_printable_array(data + offset, len)) {
>                         ret = PyUnicode_FromString((char *)data + offset);
>                 } else {
>                         ret = PyByteArray_FromStringAndSize((const char *) data + offset, len);
>                         field->flags &= ~TEP_FIELD_IS_STRING;
>                 }
> 
> 
> For some reason in sessions where bytearrays are returned, and all comes
> as bytearrays, the problem is not noticed.
> 
> But when it comes as a string it breaks after a short time, /me
> scratches head...

I think I'm getting closer, with some debugging sprinkled in the python
binding:

ip 0 pid=74131 tid=74131 cpu=3
 ( field 'prev_comm' ret=0x7f0a66a1b970 )  ( field 'prev_pid' ret=0x7f0a66b1bed0 )  ( field 'prev_prio' ret=0x7f0a74f60d08 )  ( field 'prev_state' ret=0x7f0a74f60e08 ) time 4503271651784 prev_comm=kworker/u112:14 prev_pid=74131 prev_prio=120 prev_state=0x80 ==>
 ( field 'next_comm' ret=0x7f0a66a1b970 )  ( field 'next_pid' ret=0x7f0a74f5fe08 )  ( field 'next_prio' ret=0x7f0a74f60d08 ) next_comm=swapper/3 next_pid=0 next_prio=120
ip 0 pid=80209 tid=80209 cpu=4
 ( field 'prev_comm' ret=0x7f0a66a1b970 )  ( field 'prev_pid' ret=0x7f0a66b1bed0 )  ( field 'prev_prio' ret=0x7f0a74f60d08 )  ( field 'prev_state' ret=0x7f0a74f60e08 ) time 4503280531143 prev_comm=kworker/u112:3 prev_pid=80209 prev_prio=120 prev_state=0x80 ==>
 ( field 'next_comm' ret=0x7f0a66a1b970 )  ( field 'next_pid' ret=0x7f0a74f5fe08 )  ( field 'next_prio' ret=0x7f0a74f60d08 ) next_comm=swapper/4 next_pid=0 next_prio=120
ip 0 pid=74131 tid=74131 cpu=5
 ( XXX '�!' len=16)  ( field 'prev_comm' ret=(nil) ) Traceback (most recent call last):
  File "/home/acme/git/perf-tools-next/tools/perf/python/tracepoint.py", line 51, in <module>
    main()
  File "/home/acme/git/perf-tools-next/tools/perf/python/tracepoint.py", line 40, in main
    event.prev_comm,
    ^^^^^^^^^^^^^^^
AttributeError: 'perf.sample_event' object has no attribute 'prev_comm'


So the size of the field, in the tracepoint format file is 16, its a
comm:

root@number:/home/acme/git/perf-tools-next# grep '_comm\[' /sys/kernel/tracing/events/sched/sched_switch/format 
	field:char prev_comm[16];	offset:8;	size:16;	signed:0;
	field:char next_comm[16];	offset:40;	size:16;	signed:0;
root@number:/home/acme/git/perf-tools-next#

But:

root@number:/home/acme/git/perf-tools-next# cat /proc/74131/comm
kworker/u112:14-events_unbound
root@number:/home/acme/git/perf-tools-next#

root@number:/home/acme/git/perf-tools-next# echo -n "kworker/u112:14-events_unbound" | wc -c
30
root@number:/home/acme/git/perf-tools-next#

Which should explain that:

( XXX '�!' len=16)  ( field 'prev_comm' ret=(nil) )

That is printed by:

+++ b/tools/perf/util/python.c
@@ -318,16 +318,17 @@ tracepoint_field(const struct pyrf_event *pe, struct tep_format_field *field)
                        if (tep_field_is_relative(field->flags))
                                offset += field->offset + field->size;
                }
-               if (field->flags & TEP_FIELD_IS_STRING &&
-                   is_printable_array(data + offset, len)) {
+               if (field->flags & TEP_FIELD_IS_STRING) {
                        ret = PyUnicode_FromString((char *)data + offset);
+                       if (ret == NULL) {
+                               printf(" ( XXX '%.*s' len=%d) ", len, (char *)data + offset, len); fflush(stdout);
+                       }
                } else {
                        ret = PyByteArray_FromStringAndSize((const char *) data + offset, len);
-                       field->flags &= ~TEP_FIELD_IS_STRING;
                }

So now trying to figure out why when the comm lenght is more than 16 the
raw_data appears to contain trash...

- Arnaldo