Message-ID: <20191017154205.GC8974@kernel.org>
Date:   Thu, 17 Oct 2019 12:42:05 -0300
From:   Arnaldo Carvalho de Melo <arnaldo.melo@...il.com>
To:     Tzvetomir Stoyanov <tstoyanov@...are.com>
Cc:     Steven Rostedt <rostedt@...dmis.org>, Jiri Olsa <jolsa@...nel.org>,
        Namhyung Kim <namhyung@...nel.org>,
        Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: [BUG] libtraceevent: perf script -g python segfaults

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@...co ~]# 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@...co ~]# perf script -g python
Segmentation fault (core dumped)
[root@...co ~]#

Bisected to:

[acme@...co perf]$ git bisect bad
bb3dd7e7c4d5e024d607c0ec06c2a2fb9408cc99 is the first bad commit
commit bb3dd7e7c4d5e024d607c0ec06c2a2fb9408cc99
Author: Tzvetomir Stoyanov <tstoyanov@...are.com>
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@...are.com>
    Cc: Jiri Olsa <jolsa@...hat.com>
    Cc: Namhyung Kim <namhyung@...nel.org>
    Cc: linux trace devel <linux-trace-devel@...r.kernel.org>
    Cc: tzvetomir stoyanov <tstoyanov@...are.com>
    Link: http://lkml.kernel.org/r/20181005122225.522155df@gandalf.local.home
    Signed-off-by: Steven Rostedt (VMware) <rostedt@...dmis.org>
    Signed-off-by: Arnaldo Carvalho de Melo <acme@...hat.com>

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

[root@...co ~]# 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

Powered by blists - more mailing lists