[BUG] libtraceevent: perf script -g python segfaults

From: Arnaldo Carvalho de Melo
Date: Thu Oct 17 2019 - 11:42:11 EST


I'll try and continue later, but if you guys can take a look...

The first call in that loop:

while ((event = trace_find_next_event(pevent, event)))

works and the event is valid, one of the sched: tracepoints, but then
the next call returns this:

struct tep_event *trace_find_next_event(struct tep_handle *pevent,
struct tep_event *event)
{
static int idx;
int events_count;
struct tep_event *all_events;

all_events = tep_get_first_event(pevent);
events_count = tep_get_events_count(pevent);
if (!pevent || !all_events || events_count < 1)
return NULL;

if (!event) {
idx = 0;
return all_events;
}

if (idx < events_count && event == (all_events + idx)) {
idx++;
if (idx == events_count)
return NULL;
return (all_events + idx);
}

for (idx = 1; idx < events_count; idx++) {
if (event == (all_events + (idx - 1)))
return (all_events + idx);
}
return NULL;
}

Oh, static int idx, oops, anyway, the all_events + idx returned for the
second call to trace_find_next_event() fails, in a hurry now, will get
back to this later.

- Arnaldo


[root@quaco ~]# perf record -e sched:* sleep 1
[ perf record: Woken up 33 times to write data ]
[ perf record: Captured and wrote 0.030 MB perf.data (8 samples) ]
[root@quaco ~]# perf script -g python
Segmentation fault (core dumped)
[root@quaco ~]#

Bisected to:

[acme@quaco perf]$ git bisect bad
bb3dd7e7c4d5e024d607c0ec06c2a2fb9408cc99 is the first bad commit
commit bb3dd7e7c4d5e024d607c0ec06c2a2fb9408cc99
Author: Tzvetomir Stoyanov <tstoyanov@xxxxxxxxxx>
Date: Fri Oct 5 12:22:25 2018 -0400

tools lib traceevent, perf tools: Move struct tep_handler definition in a local header file

As traceevent is going to be transferred into a proper library,
its local data should be protected from the library users.
This patch encapsulates struct tep_handler into a local header,
not visible outside of the library. It implements also a bunch
of new APIs, which library users can use to access tep_handler members.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@xxxxxxxxxx>
Cc: Jiri Olsa <jolsa@xxxxxxxxxx>
Cc: Namhyung Kim <namhyung@xxxxxxxxxx>
Cc: linux trace devel <linux-trace-devel@xxxxxxxxxxxxxxx>
Cc: tzvetomir stoyanov <tstoyanov@xxxxxxxxxx>
Link: http://lkml.kernel.org/r/20181005122225.522155df@xxxxxxxxxxxxxxxxxx
Signed-off-by: Steven Rostedt (VMware) <rostedt@xxxxxxxxxxx>
Signed-off-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>

:040000 040000 7a23aa486fd8ed255b681e6c959d6ab64d16f2f6 d95f601bb03b81bc04070b69635df40b62c70a1a M tools
[acme@quaco perf]$

[root@quaco ~]# gdb perf
GNU gdb (GDB) Fedora 8.3-6.fc30
Reading symbols from perf...
(gdb) run script -g python
Starting program: /root/bin/perf script -g python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
[Detaching after fork from child process 10352]

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff76f55e5 in __strlen_avx2 () from /lib64/libc.so.6
Missing separate debuginfos, use: dnf debuginfo-install bzip2-libs-1.0.6-29.fc30.x86_64 elfutils-libelf-0.177-1.fc30.x86_64 elfutils-libs-0.177-1.fc30.x86_64 glib2-2.60.7-1.fc30.x86_64 libbabeltrace-1.5.6-2.fc30.x86_64 libcap-2.26-5.fc30.x86_64 libgcc-9.2.1-1.fc30.x86_64 libunwind-1.3.1-2.fc30.x86_64 libuuid-2.33.2-2.fc30.x86_64 libxcrypt-4.4.10-1.fc30.x86_64 libzstd-1.4.2-1.fc30.x86_64 numactl-libs-2.0.12-2.fc30.x86_64 pcre-8.43-2.fc30.x86_64 perl-libs-5.28.2-440.fc30.x86_64 popt-1.16-17.fc30.x86_64 slang-2.3.2-5.fc30.x86_64 xz-libs-5.2.4-5.fc30.x86_64 zlib-1.2.11-18.fc30.x86_64
(gdb) bt
#0 0x00007ffff76f55e5 in __strlen_avx2 () from /lib64/libc.so.6
#1 0x00007ffff7601a1e in __vfprintf_internal () from /lib64/libc.so.6
#2 0x00007ffff75ec2ba in fprintf () from /lib64/libc.so.6
#3 0x00000000005ec8db in python_generate_script (pevent=0xbedb10, outfile=0x71f761 "perf-script") at util/scripting-engines/trace-event-python.c:1739
#4 0x000000000046e94a in cmd_script (argc=0, argv=0x7fffffffd680) at builtin-script.c:3848
#5 0x00000000004e0d86 in run_builtin (p=0xa3d238 <commands+408>, argc=3, argv=0x7fffffffd680) at perf.c:312
#6 0x00000000004e0ff3 in handle_internal_command (argc=3, argv=0x7fffffffd680) at perf.c:364
#7 0x00000000004e113a in run_argv (argcp=0x7fffffffd4dc, argv=0x7fffffffd4d0) at perf.c:408
#8 0x00000000004e1506 in main (argc=3, argv=0x7fffffffd680) at perf.c:538
(gdb) fr 3
#3 0x00000000005ec8db in python_generate_script (pevent=0xbedb10, outfile=0x71f761 "perf-script") at util/scripting-engines/trace-event-python.c:1739
1739 fprintf(ofp, "def %s__%s(", event->system, event->name);
(gdb) p event
$1 = (struct tep_event *) 0xbfa298
(gdb) p *event
$2 = {tep = 0x31, name = 0x61775f6465686373 <error: Cannot access memory at address 0x61775f6465686373>, id = 1767859563, flags = 1600482404, format = {nr_common = 1752459639, nr_fields = 1601467759, common_fields = 0x6e6f6d6d00697069,
fields = 0x93b7367616c665f}, print_fmt = {format = 0x21 <error: Cannot access memory at address 0x21>, args = 0x64656e6769736e75}, system = 0x74726f687320 <error: Cannot access memory at address 0x74726f687320>,
handler = 0x656966090a3b303a, context = 0x51}
(gdb) list -20
1714 fprintf(ofp, "# in the format files. Those fields not available as "
1715 "handler params can\n");
1716
1717 fprintf(ofp, "# be retrieved using Python functions of the form "
1718 "common_*(context).\n");
1719
1720 fprintf(ofp, "# See the perf-script-python Documentation for the list "
1721 "of available functions.\n\n");
1722
1723 fprintf(ofp, "from __future__ import print_function\n\n");
(gdb)
1724 fprintf(ofp, "import os\n");
1725 fprintf(ofp, "import sys\n\n");
1726
1727 fprintf(ofp, "sys.path.append(os.environ['PERF_EXEC_PATH'] + \\\n");
1728 fprintf(ofp, "\t'/scripts/python/Perf-Trace-Util/lib/Perf/Trace')\n");
1729 fprintf(ofp, "\nfrom perf_trace_context import *\n");
1730 fprintf(ofp, "from Core import *\n\n\n");
1731
1732 fprintf(ofp, "def trace_begin():\n");
1733 fprintf(ofp, "\tprint(\"in trace_begin\")\n\n");
(gdb)
1734
1735 fprintf(ofp, "def trace_end():\n");
1736 fprintf(ofp, "\tprint(\"in trace_end\")\n\n");
1737
1738 while ((event = trace_find_next_event(pevent, event))) {
1739 fprintf(ofp, "def %s__%s(", event->system, event->name);
1740 fprintf(ofp, "event_name, ");
1741 fprintf(ofp, "context, ");
1742 fprintf(ofp, "common_cpu,\n");
1743 fprintf(ofp, "\tcommon_secs, ");


- Arnaldo