In some situations the libdw unwinder stopped working properly.
I.e. with libunwind we see:
~~~~~
heaptrack_gui 2228 135073.400112: 641314 cycles:
e8ed _dl_fixup (/usr/lib/ld-2.25.so)
15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
608f3 _GLOBAL__sub_I_kdynamicjobtracker.cpp (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
f199 call_init.part.0 (/usr/lib/ld-2.25.so)
f2a5 _dl_init (/usr/lib/ld-2.25.so)
db9 _dl_start_user (/usr/lib/ld-2.25.so)
~~~~~
But with libdw and without this patch this sample is not properly
unwound:
~~~~~
heaptrack_gui 2228 135073.400112: 641314 cycles:
e8ed _dl_fixup (/usr/lib/ld-2.25.so)
15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
~~~~~
Debug output showed me that libdw found a module for the last frame
address, but it thinks it belongs to /usr/lib/ld-2.25.so. This patch
double-checks what libdw sees and what perf knows. If the mappings
mismatch, we now report the elf known to perf. This fixes the
situation above, and the libdw unwinder produces the same stack as
libunwind.
Cc: Arnaldo Carvalho de Melo <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Jiri Olsa <[email protected]>
Signed-off-by: Milian Wolff <[email protected]>
---
tools/perf/util/unwind-libdw.c | 8 ++++++++
1 file changed, 8 insertions(+)
diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
index b4c20124d2ee..da45c4be5fb3 100644
--- a/tools/perf/util/unwind-libdw.c
+++ b/tools/perf/util/unwind-libdw.c
@@ -39,6 +39,14 @@ static int __report_module(struct addr_location *al, u64 ip,
return 0;
mod = dwfl_addrmodule(ui->dwfl, ip);
+ if (mod) {
+ Dwarf_Addr s;
+
+ dwfl_module_info(mod, NULL, &s, NULL, NULL, NULL, NULL, NULL);
+ if (s != al->map->start)
+ mod = 0;
+ }
+
if (!mod)
mod = dwfl_report_elf(ui->dwfl, dso->short_name,
dso->long_name, -1, al->map->start,
--
2.13.0
The PC returned by dwfl_frame_pc may map into a not-yet-reported
module. We have to report it before we continue unwinding. But when
we query for the isactivation flag in dwfl_frame_pc, libdw will
actually do one more unwinding step internally which can then break
and lead to missed frames or broken stacks.
With libunwind we get e.g.:
~~~~~
heaptrack_gui 2228 135073.400474: 613969 cycles:
108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
20439 __libc_start_main (/usr/lib/libc-2.25.so)
78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
heaptrack_gui 2228 135073.401156: 569521 cycles:
131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
f5a1c QGuiApplicationPrivate::createPlatformIntegration (/usr/lib/libQt5Gui.so.5.8.0)
f650c QGuiApplicationPrivate::createEventDispatcher (/usr/lib/libQt5Gui.so.5.8.0)
298524 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
20439 __libc_start_main (/usr/lib/libc-2.25.so)
78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
~~~~~
Note the two frames 1589e8 and 78622 in the first sample. These are
missing when unwinding with libdw. The second sample's breakage is
more obvious:
~~~~~
heaptrack_gui 2228 135073.400474: 613969 cycles:
108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
20439 __libc_start_main (/usr/lib/libc-2.25.so)
78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
heaptrack_gui 2228 135073.401156: 569521 cycles:
131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
723dbf [unknown] ([unknown])
~~~~~
This patch fixes this issue and the libdw unwinder mimicks the
libunwind behavior more closely.
Cc: Arnaldo Carvalho de Melo <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Jiri Olsa <[email protected]>
Signed-off-by: Milian Wolff <[email protected]>
---
tools/perf/util/unwind-libdw.c | 8 ++++++++
1 file changed, 8 insertions(+)
diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
index da45c4be5fb3..7755a5e0fe5e 100644
--- a/tools/perf/util/unwind-libdw.c
+++ b/tools/perf/util/unwind-libdw.c
@@ -178,6 +178,14 @@ frame_callback(Dwfl_Frame *state, void *arg)
Dwarf_Addr pc;
bool isactivation;
+ if (!dwfl_frame_pc(state, &pc, NULL)) {
+ pr_err("%s", dwfl_errmsg(-1));
+ return DWARF_CB_ABORT;
+ }
+
+ // report the module before we query for isactivation
+ report_module(pc, ui);
+
if (!dwfl_frame_pc(state, &pc, &isactivation)) {
pr_err("%s", dwfl_errmsg(-1));
return DWARF_CB_ABORT;
--
2.13.0
Em Fri, Jun 02, 2017 at 04:37:52PM +0200, Milian Wolff escreveu:
> In some situations the libdw unwinder stopped working properly.
> I.e. with libunwind we see:
>
> ~~~~~
> heaptrack_gui 2228 135073.400112: 641314 cycles:
> e8ed _dl_fixup (/usr/lib/ld-2.25.so)
> 15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
> ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
> 608f3 _GLOBAL__sub_I_kdynamicjobtracker.cpp (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
> f199 call_init.part.0 (/usr/lib/ld-2.25.so)
> f2a5 _dl_init (/usr/lib/ld-2.25.so)
> db9 _dl_start_user (/usr/lib/ld-2.25.so)
> ~~~~~
>
> But with libdw and without this patch this sample is not properly
> unwound:
>
> ~~~~~
> heaptrack_gui 2228 135073.400112: 641314 cycles:
> e8ed _dl_fixup (/usr/lib/ld-2.25.so)
> 15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
> ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
> ~~~~~
>
> Debug output showed me that libdw found a module for the last frame
> address, but it thinks it belongs to /usr/lib/ld-2.25.so. This patch
> double-checks what libdw sees and what perf knows. If the mappings
> mismatch, we now report the elf known to perf. This fixes the
> situation above, and the libdw unwinder produces the same stack as
> libunwind.
Looks ok, having both implementations matching and the callchains making
sense for your workloads is a good way to verify the sanity, thanks.
I wonder if we shouldn't somehow script this, i.e. build it with one
implementation, generate output from some test workload, build it with
the other, second output, diff it, report when not the same.
- Arnaldo
Em Fri, Jun 02, 2017 at 04:37:53PM +0200, Milian Wolff escreveu:
> The PC returned by dwfl_frame_pc may map into a not-yet-reported
> module. We have to report it before we continue unwinding. But when
> we query for the isactivation flag in dwfl_frame_pc, libdw will
> actually do one more unwinding step internally which can then break
> and lead to missed frames or broken stacks.
>
> With libunwind we get e.g.:
Jiri, can you review this one?
Thanks,
- Arnaldo
> ~~~~~
> heaptrack_gui 2228 135073.400474: 613969 cycles:
> 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
>
> heaptrack_gui 2228 135073.401156: 569521 cycles:
> 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> f5a1c QGuiApplicationPrivate::createPlatformIntegration (/usr/lib/libQt5Gui.so.5.8.0)
> f650c QGuiApplicationPrivate::createEventDispatcher (/usr/lib/libQt5Gui.so.5.8.0)
> 298524 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> ~~~~~
>
> Note the two frames 1589e8 and 78622 in the first sample. These are
> missing when unwinding with libdw. The second sample's breakage is
> more obvious:
>
> ~~~~~
> heaptrack_gui 2228 135073.400474: 613969 cycles:
> 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
>
> heaptrack_gui 2228 135073.401156: 569521 cycles:
> 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> 723dbf [unknown] ([unknown])
> ~~~~~
>
> This patch fixes this issue and the libdw unwinder mimicks the
> libunwind behavior more closely.
>
> Cc: Arnaldo Carvalho de Melo <[email protected]>
> Cc: Namhyung Kim <[email protected]>
> Cc: Jiri Olsa <[email protected]>
> Signed-off-by: Milian Wolff <[email protected]>
> ---
> tools/perf/util/unwind-libdw.c | 8 ++++++++
> 1 file changed, 8 insertions(+)
>
> diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
> index da45c4be5fb3..7755a5e0fe5e 100644
> --- a/tools/perf/util/unwind-libdw.c
> +++ b/tools/perf/util/unwind-libdw.c
> @@ -178,6 +178,14 @@ frame_callback(Dwfl_Frame *state, void *arg)
> Dwarf_Addr pc;
> bool isactivation;
>
> + if (!dwfl_frame_pc(state, &pc, NULL)) {
> + pr_err("%s", dwfl_errmsg(-1));
> + return DWARF_CB_ABORT;
> + }
> +
> + // report the module before we query for isactivation
> + report_module(pc, ui);
> +
> if (!dwfl_frame_pc(state, &pc, &isactivation)) {
> pr_err("%s", dwfl_errmsg(-1));
> return DWARF_CB_ABORT;
> --
> 2.13.0
On Freitag, 2. Juni 2017 17:23:41 CEST Arnaldo Carvalho de Melo wrote:
> Em Fri, Jun 02, 2017 at 04:37:52PM +0200, Milian Wolff escreveu:
> > In some situations the libdw unwinder stopped working properly.
> > I.e. with libunwind we see:
> >
> > ~~~~~
> >
> > heaptrack_gui 2228 135073.400112: 641314 cycles:
> > e8ed _dl_fixup (/usr/lib/ld-2.25.so)
> >
> > 15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
> > ed94c KDynamicJobTracker::KDynamicJobTracker
> > (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so
> > .5.35.0) 608f3 _GLOBAL__sub_I_kdynamicjobtracker.cpp
> > (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so
> > .5.35.0)>
> > f199 call_init.part.0 (/usr/lib/ld-2.25.so)
> > f2a5 _dl_init (/usr/lib/ld-2.25.so)
> >
> > db9 _dl_start_user (/usr/lib/ld-2.25.so)
> >
> > ~~~~~
> >
> > But with libdw and without this patch this sample is not properly
> > unwound:
> >
> > ~~~~~
> >
> > heaptrack_gui 2228 135073.400112: 641314 cycles:
> > e8ed _dl_fixup (/usr/lib/ld-2.25.so)
> >
> > 15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
> > ed94c KDynamicJobTracker::KDynamicJobTracker
> > (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so
> > .5.35.0)>
> > ~~~~~
> >
> > Debug output showed me that libdw found a module for the last frame
> > address, but it thinks it belongs to /usr/lib/ld-2.25.so. This patch
> > double-checks what libdw sees and what perf knows. If the mappings
> > mismatch, we now report the elf known to perf. This fixes the
> > situation above, and the libdw unwinder produces the same stack as
> > libunwind.
>
> Looks ok, having both implementations matching and the callchains making
> sense for your workloads is a good way to verify the sanity, thanks.
>
> I wonder if we shouldn't somehow script this, i.e. build it with one
> implementation, generate output from some test workload, build it with
> the other, second output, diff it, report when not the same.
That does sound like a good idea, but I'm unsure how to do it. Note that many
"simple" tests work just fine. Only larger complicated workloads trigger this
issue for me.
One potential way to test it would be `perf archive` - i.e. I send you the
binaries involved and then we can use perf script diffing to ensure it all
works...
Cheers
--
Milian Wolff | [email protected] | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts
Em Fri, Jun 02, 2017 at 06:21:44PM +0200, Milian Wolff escreveu:
> On Freitag, 2. Juni 2017 17:23:41 CEST Arnaldo Carvalho de Melo wrote:
> > Looks ok, having both implementations matching and the callchains making
> > sense for your workloads is a good way to verify the sanity, thanks.
> > I wonder if we shouldn't somehow script this, i.e. build it with one
> > implementation, generate output from some test workload, build it with
> > the other, second output, diff it, report when not the same.
> That does sound like a good idea, but I'm unsure how to do it. Note that many
> "simple" tests work just fine. Only larger complicated workloads trigger this
> issue for me.
> One potential way to test it would be `perf archive` - i.e. I send you the
> binaries involved and then we can use perf script diffing to ensure it all
> works...
Humm, I'm trying to cook up a:
perf data filter --pid 12345 --perf-data-offset 1234567 --output perf.data.subset
to allow when finding some case like that to get a small subset of a
perf.data file with just the sample we want to get the backtrace from +
the mmaps, etc up to that point.
With that I could keep a repo of interesting perf.data files to have in
my regression tests.
- Arnaldo
On Freitag, 2. Juni 2017 21:49:10 CEST Arnaldo Carvalho de Melo wrote:
> Em Fri, Jun 02, 2017 at 06:21:44PM +0200, Milian Wolff escreveu:
> > On Freitag, 2. Juni 2017 17:23:41 CEST Arnaldo Carvalho de Melo wrote:
> > > Looks ok, having both implementations matching and the callchains making
> > > sense for your workloads is a good way to verify the sanity, thanks.
> > >
> > > I wonder if we shouldn't somehow script this, i.e. build it with one
> > > implementation, generate output from some test workload, build it with
> > > the other, second output, diff it, report when not the same.
> >
> > That does sound like a good idea, but I'm unsure how to do it. Note that
> > many "simple" tests work just fine. Only larger complicated workloads
> > trigger this issue for me.
> >
> > One potential way to test it would be `perf archive` - i.e. I send you the
> > binaries involved and then we can use perf script diffing to ensure it all
> > works...
>
> Humm, I'm trying to cook up a:
>
> perf data filter --pid 12345 --perf-data-offset 1234567 --output
> perf.data.subset
>
> to allow when finding some case like that to get a small subset of a
> perf.data file with just the sample we want to get the backtrace from +
> the mmaps, etc up to that point.
>
> With that I could keep a repo of interesting perf.data files to have in
> my regression tests.
How do I find the data offset to use here? If that works, I can provide you
with one test file. But note how we'd also need the referenced mmap files. So
it's going to be perf.data + perf archive.
Bye
--
Milian Wolff | [email protected] | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts
On Fri, Jun 02, 2017 at 04:37:52PM +0200, Milian Wolff wrote:
> In some situations the libdw unwinder stopped working properly.
> I.e. with libunwind we see:
>
> ~~~~~
> heaptrack_gui 2228 135073.400112: 641314 cycles:
> e8ed _dl_fixup (/usr/lib/ld-2.25.so)
> 15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
> ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
> 608f3 _GLOBAL__sub_I_kdynamicjobtracker.cpp (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
> f199 call_init.part.0 (/usr/lib/ld-2.25.so)
> f2a5 _dl_init (/usr/lib/ld-2.25.so)
> db9 _dl_start_user (/usr/lib/ld-2.25.so)
> ~~~~~
>
> But with libdw and without this patch this sample is not properly
> unwound:
>
> ~~~~~
> heaptrack_gui 2228 135073.400112: 641314 cycles:
> e8ed _dl_fixup (/usr/lib/ld-2.25.so)
> 15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
> ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
> ~~~~~
>
> Debug output showed me that libdw found a module for the last frame
> address, but it thinks it belongs to /usr/lib/ld-2.25.so. This patch
> double-checks what libdw sees and what perf knows. If the mappings
> mismatch, we now report the elf known to perf. This fixes the
> situation above, and the libdw unwinder produces the same stack as
> libunwind.
hum, sounds like libdw bug right? CC-ing Jan... any idea?
anyway, I think we can keep that as sanity check
thanks,
jirka
>
> Cc: Arnaldo Carvalho de Melo <[email protected]>
> Cc: Namhyung Kim <[email protected]>
> Cc: Jiri Olsa <[email protected]>
> Signed-off-by: Milian Wolff <[email protected]>
> ---
> tools/perf/util/unwind-libdw.c | 8 ++++++++
> 1 file changed, 8 insertions(+)
>
> diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
> index b4c20124d2ee..da45c4be5fb3 100644
> --- a/tools/perf/util/unwind-libdw.c
> +++ b/tools/perf/util/unwind-libdw.c
> @@ -39,6 +39,14 @@ static int __report_module(struct addr_location *al, u64 ip,
> return 0;
>
> mod = dwfl_addrmodule(ui->dwfl, ip);
> + if (mod) {
> + Dwarf_Addr s;
> +
> + dwfl_module_info(mod, NULL, &s, NULL, NULL, NULL, NULL, NULL);
> + if (s != al->map->start)
> + mod = 0;
> + }
> +
> if (!mod)
> mod = dwfl_report_elf(ui->dwfl, dso->short_name,
> dso->long_name, -1, al->map->start,
> --
> 2.13.0
>
On Fri, Jun 02, 2017 at 12:25:08PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Fri, Jun 02, 2017 at 04:37:53PM +0200, Milian Wolff escreveu:
> > The PC returned by dwfl_frame_pc may map into a not-yet-reported
> > module. We have to report it before we continue unwinding. But when
> > we query for the isactivation flag in dwfl_frame_pc, libdw will
> > actually do one more unwinding step internally which can then break
> > and lead to missed frames or broken stacks.
> >
> > With libunwind we get e.g.:
sounds like a libdw design issue.. Jan is there a specific way
to handle the case that Milian described?
thanks,
jirka
>
> Thanks,
>
> - Arnaldo
>
> > ~~~~~
> > heaptrack_gui 2228 135073.400474: 613969 cycles:
> > 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> > 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> > 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> > 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> > 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> > 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> >
> > heaptrack_gui 2228 135073.401156: 569521 cycles:
> > 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> > 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> > 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> > 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> > 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> > e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> > f5a1c QGuiApplicationPrivate::createPlatformIntegration (/usr/lib/libQt5Gui.so.5.8.0)
> > f650c QGuiApplicationPrivate::createEventDispatcher (/usr/lib/libQt5Gui.so.5.8.0)
> > 298524 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> > 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > ~~~~~
> >
> > Note the two frames 1589e8 and 78622 in the first sample. These are
> > missing when unwinding with libdw. The second sample's breakage is
> > more obvious:
> >
> > ~~~~~
> > heaptrack_gui 2228 135073.400474: 613969 cycles:
> > 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> > 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> > 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> > 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> > 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> >
> > heaptrack_gui 2228 135073.401156: 569521 cycles:
> > 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> > 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> > 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> > 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> > 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> > e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> > 723dbf [unknown] ([unknown])
> > ~~~~~
> >
> > This patch fixes this issue and the libdw unwinder mimicks the
> > libunwind behavior more closely.
> >
> > Cc: Arnaldo Carvalho de Melo <[email protected]>
> > Cc: Namhyung Kim <[email protected]>
> > Cc: Jiri Olsa <[email protected]>
> > Signed-off-by: Milian Wolff <[email protected]>
> > ---
> > tools/perf/util/unwind-libdw.c | 8 ++++++++
> > 1 file changed, 8 insertions(+)
> >
> > diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
> > index da45c4be5fb3..7755a5e0fe5e 100644
> > --- a/tools/perf/util/unwind-libdw.c
> > +++ b/tools/perf/util/unwind-libdw.c
> > @@ -178,6 +178,14 @@ frame_callback(Dwfl_Frame *state, void *arg)
> > Dwarf_Addr pc;
> > bool isactivation;
> >
> > + if (!dwfl_frame_pc(state, &pc, NULL)) {
> > + pr_err("%s", dwfl_errmsg(-1));
> > + return DWARF_CB_ABORT;
> > + }
> > +
> > + // report the module before we query for isactivation
> > + report_module(pc, ui);
> > +
> > if (!dwfl_frame_pc(state, &pc, &isactivation)) {
> > pr_err("%s", dwfl_errmsg(-1));
> > return DWARF_CB_ABORT;
> > --
> > 2.13.0
Commit-ID: 2538b9e2450ae255337c04356e9e0f8cb9ec48d9
Gitweb: http://git.kernel.org/tip/2538b9e2450ae255337c04356e9e0f8cb9ec48d9
Author: Milian Wolff <[email protected]>
AuthorDate: Fri, 2 Jun 2017 16:37:52 +0200
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 5 Jun 2017 14:18:05 -0300
perf report: Ensure the perf DSO mapping matches what libdw sees
In some situations the libdw unwinder stopped working properly. I.e.
with libunwind we see:
~~~~~
heaptrack_gui 2228 135073.400112: 641314 cycles:
e8ed _dl_fixup (/usr/lib/ld-2.25.so)
15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
608f3 _GLOBAL__sub_I_kdynamicjobtracker.cpp (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
f199 call_init.part.0 (/usr/lib/ld-2.25.so)
f2a5 _dl_init (/usr/lib/ld-2.25.so)
db9 _dl_start_user (/usr/lib/ld-2.25.so)
~~~~~
But with libdw and without this patch this sample is not properly
unwound:
~~~~~
heaptrack_gui 2228 135073.400112: 641314 cycles:
e8ed _dl_fixup (/usr/lib/ld-2.25.so)
15f06 _dl_runtime_resolve_sse_vex (/usr/lib/ld-2.25.so)
ed94c KDynamicJobTracker::KDynamicJobTracker (/home/milian/projects/compiled/kf5/lib64/libKF5KIOWidgets.so.5.35.0)
~~~~~
Debug output showed me that libdw found a module for the last frame
address, but it thinks it belongs to /usr/lib/ld-2.25.so. This patch
double-checks what libdw sees and what perf knows. If the mappings
mismatch, we now report the elf known to perf. This fixes the situation
above, and the libdw unwinder produces the same stack as libunwind.
Signed-off-by: Milian Wolff <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/unwind-libdw.c | 8 ++++++++
1 file changed, 8 insertions(+)
diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
index b4c2012..da45c4b 100644
--- a/tools/perf/util/unwind-libdw.c
+++ b/tools/perf/util/unwind-libdw.c
@@ -39,6 +39,14 @@ static int __report_module(struct addr_location *al, u64 ip,
return 0;
mod = dwfl_addrmodule(ui->dwfl, ip);
+ if (mod) {
+ Dwarf_Addr s;
+
+ dwfl_module_info(mod, NULL, &s, NULL, NULL, NULL, NULL, NULL);
+ if (s != al->map->start)
+ mod = 0;
+ }
+
if (!mod)
mod = dwfl_report_elf(ui->dwfl, dso->short_name,
dso->long_name, -1, al->map->start,
On Mon, 05 Jun 2017 12:47:20 +0200, Jiri Olsa wrote:
> On Fri, Jun 02, 2017 at 12:25:08PM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Fri, Jun 02, 2017 at 04:37:53PM +0200, Milian Wolff escreveu:
> > > The PC returned by dwfl_frame_pc may map into a not-yet-reported
> > > module. We have to report it before we continue unwinding. But when
> > > we query for the isactivation flag in dwfl_frame_pc, libdw will
> > > actually do one more unwinding step internally which can then break
> > > and lead to missed frames or broken stacks.
> > >
> > > With libunwind we get e.g.:
>
> sounds like a libdw design issue.. Jan is there a specific way
> to handle the case that Milian described?
I agree with the patch.
Just be aware for performance then the __report_module() call in entry() is no
longer useful as the '--pc' adjustment should never cross a module boundary.
Although for perf unwinding performance there is still a wide gap there
(such as caching the loaded modules for multiple backtraces.)
Thanks,
Jan
On Mon, 05 Jun 2017 12:41:30 +0200, Jiri Olsa wrote:
> On Fri, Jun 02, 2017 at 04:37:52PM +0200, Milian Wolff wrote:
> > Debug output showed me that libdw found a module for the last frame
> > address, but it thinks it belongs to /usr/lib/ld-2.25.so.
I find your patch as a correct workaround of an elfutils bug.
I have filed it as:
dwfl_addrmodule reports bogus modules for unmapped areas
https://sourceware.org/bugzilla/show_bug.cgi?id=21602
Thanks,
Jan
Em Fri, Jun 02, 2017 at 12:25:08PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Jun 02, 2017 at 04:37:53PM +0200, Milian Wolff escreveu:
> > The PC returned by dwfl_frame_pc may map into a not-yet-reported
> > module. We have to report it before we continue unwinding. But when
> > we query for the isactivation flag in dwfl_frame_pc, libdw will
> > actually do one more unwinding step internally which can then break
> > and lead to missed frames or broken stacks.
> >
> > With libunwind we get e.g.:
>
> Jiri, can you review this one?
ping
> Thanks,
>
> - Arnaldo
>
> > ~~~~~
> > heaptrack_gui 2228 135073.400474: 613969 cycles:
> > 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> > 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> > 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> > 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> > 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> > 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> >
> > heaptrack_gui 2228 135073.401156: 569521 cycles:
> > 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> > 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> > 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> > 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> > 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> > e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> > f5a1c QGuiApplicationPrivate::createPlatformIntegration (/usr/lib/libQt5Gui.so.5.8.0)
> > f650c QGuiApplicationPrivate::createEventDispatcher (/usr/lib/libQt5Gui.so.5.8.0)
> > 298524 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> > 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > ~~~~~
> >
> > Note the two frames 1589e8 and 78622 in the first sample. These are
> > missing when unwinding with libdw. The second sample's breakage is
> > more obvious:
> >
> > ~~~~~
> > heaptrack_gui 2228 135073.400474: 613969 cycles:
> > 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> > 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> > 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> > 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> > 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> >
> > heaptrack_gui 2228 135073.401156: 569521 cycles:
> > 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> > 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> > 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> > 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> > 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> > e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> > 723dbf [unknown] ([unknown])
> > ~~~~~
> >
> > This patch fixes this issue and the libdw unwinder mimicks the
> > libunwind behavior more closely.
> >
> > Cc: Arnaldo Carvalho de Melo <[email protected]>
> > Cc: Namhyung Kim <[email protected]>
> > Cc: Jiri Olsa <[email protected]>
> > Signed-off-by: Milian Wolff <[email protected]>
> > ---
> > tools/perf/util/unwind-libdw.c | 8 ++++++++
> > 1 file changed, 8 insertions(+)
> >
> > diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
> > index da45c4be5fb3..7755a5e0fe5e 100644
> > --- a/tools/perf/util/unwind-libdw.c
> > +++ b/tools/perf/util/unwind-libdw.c
> > @@ -178,6 +178,14 @@ frame_callback(Dwfl_Frame *state, void *arg)
> > Dwarf_Addr pc;
> > bool isactivation;
> >
> > + if (!dwfl_frame_pc(state, &pc, NULL)) {
> > + pr_err("%s", dwfl_errmsg(-1));
> > + return DWARF_CB_ABORT;
> > + }
> > +
> > + // report the module before we query for isactivation
> > + report_module(pc, ui);
> > +
> > if (!dwfl_frame_pc(state, &pc, &isactivation)) {
> > pr_err("%s", dwfl_errmsg(-1));
> > return DWARF_CB_ABORT;
> > --
> > 2.13.0
> --
> To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
Em Fri, Jun 16, 2017 at 01:06:52PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Jun 02, 2017 at 12:25:08PM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Fri, Jun 02, 2017 at 04:37:53PM +0200, Milian Wolff escreveu:
> > > The PC returned by dwfl_frame_pc may map into a not-yet-reported
> > > module. We have to report it before we continue unwinding. But when
> > > we query for the isactivation flag in dwfl_frame_pc, libdw will
> > > actually do one more unwinding step internally which can then break
> > > and lead to missed frames or broken stacks.
> > >
> > > With libunwind we get e.g.:
> >
> > Jiri, can you review this one?
>
> ping
Sorry, saw yesterday's replies now, will apply the patch with an
Acked-by: Jan.
Thanks,
- Arnaldo
> > Thanks,
> >
> > - Arnaldo
> >
> > > ~~~~~
> > > heaptrack_gui 2228 135073.400474: 613969 cycles:
> > > 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > > 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> > > 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> > > 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > > 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> > > 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> > > 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > > 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> > > 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > >
> > > heaptrack_gui 2228 135073.401156: 569521 cycles:
> > > 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> > > 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> > > 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> > > 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> > > 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> > > e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> > > f5a1c QGuiApplicationPrivate::createPlatformIntegration (/usr/lib/libQt5Gui.so.5.8.0)
> > > f650c QGuiApplicationPrivate::createEventDispatcher (/usr/lib/libQt5Gui.so.5.8.0)
> > > 298524 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > > 1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
> > > 78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > > ~~~~~
> > >
> > > Note the two frames 1589e8 and 78622 in the first sample. These are
> > > missing when unwinding with libdw. The second sample's breakage is
> > > more obvious:
> > >
> > > ~~~~~
> > > heaptrack_gui 2228 135073.400474: 613969 cycles:
> > > 108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > > 1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
> > > 109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
> > > 10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
> > > 1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
> > > 92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
> > > 2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
> > > f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
> > > 20439 __libc_start_main (/usr/lib/libc-2.25.so)
> > > 78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
> > >
> > > heaptrack_gui 2228 135073.401156: 569521 cycles:
> > > 131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
> > > 1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
> > > 21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
> > > 1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
> > > 2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
> > > 279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
> > > e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
> > > 723dbf [unknown] ([unknown])
> > > ~~~~~
> > >
> > > This patch fixes this issue and the libdw unwinder mimicks the
> > > libunwind behavior more closely.
> > >
> > > Cc: Arnaldo Carvalho de Melo <[email protected]>
> > > Cc: Namhyung Kim <[email protected]>
> > > Cc: Jiri Olsa <[email protected]>
> > > Signed-off-by: Milian Wolff <[email protected]>
> > > ---
> > > tools/perf/util/unwind-libdw.c | 8 ++++++++
> > > 1 file changed, 8 insertions(+)
> > >
> > > diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
> > > index da45c4be5fb3..7755a5e0fe5e 100644
> > > --- a/tools/perf/util/unwind-libdw.c
> > > +++ b/tools/perf/util/unwind-libdw.c
> > > @@ -178,6 +178,14 @@ frame_callback(Dwfl_Frame *state, void *arg)
> > > Dwarf_Addr pc;
> > > bool isactivation;
> > >
> > > + if (!dwfl_frame_pc(state, &pc, NULL)) {
> > > + pr_err("%s", dwfl_errmsg(-1));
> > > + return DWARF_CB_ABORT;
> > > + }
> > > +
> > > + // report the module before we query for isactivation
> > > + report_module(pc, ui);
> > > +
> > > if (!dwfl_frame_pc(state, &pc, &isactivation)) {
> > > pr_err("%s", dwfl_errmsg(-1));
> > > return DWARF_CB_ABORT;
> > > --
> > > 2.13.0
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
> > the body of a message to [email protected]
> > More majordomo info at http://vger.kernel.org/majordomo-info.html
Commit-ID: 9126cbbacecb8917bd0418809ef1d26616b2061e
Gitweb: http://git.kernel.org/tip/9126cbbacecb8917bd0418809ef1d26616b2061e
Author: Milian Wolff <[email protected]>
AuthorDate: Fri, 2 Jun 2017 16:37:53 +0200
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Fri, 16 Jun 2017 14:37:30 -0300
perf unwind: Report module before querying isactivation in dwfl unwind
The PC returned by dwfl_frame_pc() may map into a not-yet-reported
module. We have to report it before we continue unwinding. But when we
query for the isactivation flag in dwfl_frame_pc, libdw will actually do
one more unwinding step internally which can then break and lead to
missed frames or broken stacks.
With libunwind we get e.g.:
~~~~~
heaptrack_gui 2228 135073.400474: 613969 cycles:
108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
20439 __libc_start_main (/usr/lib/libc-2.25.so)
78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
heaptrack_gui 2228 135073.401156: 569521 cycles:
131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
f5a1c QGuiApplicationPrivate::createPlatformIntegration (/usr/lib/libQt5Gui.so.5.8.0)
f650c QGuiApplicationPrivate::createEventDispatcher (/usr/lib/libQt5Gui.so.5.8.0)
298524 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
1589e8 QApplicationPrivate::init (/usr/lib/libQt5Widgets.so.5.8.0)
78622 main (/home/milian/projects/compiled/other/bin/heaptrack_gui)
20439 __libc_start_main (/usr/lib/libc-2.25.so)
78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
~~~~~
Note the two frames 1589e8 and 78622 in the first sample. These are
missing when unwinding with libdw. The second sample's breakage is
more obvious:
~~~~~
heaptrack_gui 2228 135073.400474: 613969 cycles:
108c8e [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1093bc [unknown] (/usr/lib/libQt5Core.so.5.8.0)
109e7b QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1470ff [unknown] (/usr/lib/libQt5Core.so.5.8.0)
147f67 QSystemLocale::query (/usr/lib/libQt5Core.so.5.8.0)
109fbf QLocalePrivate::updateSystemPrivate (/usr/lib/libQt5Core.so.5.8.0)
10aa27 QLocale::QLocale (/usr/lib/libQt5Core.so.5.8.0)
1e02c3 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
2113bb [unknown] (/usr/lib/libQt5Core.so.5.8.0)
211505 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b5df0 QFileInfo::exists (/usr/lib/libQt5Core.so.5.8.0)
92eb2 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93423 [unknown] (/usr/lib/libQt5Core.so.5.8.0)
93d2a QLibraryInfo::location (/usr/lib/libQt5Core.so.5.8.0)
2170af [unknown] (/usr/lib/libQt5Core.so.5.8.0)
297c53 QCoreApplicationPrivate::init (/usr/lib/libQt5Core.so.5.8.0)
f7cde QGuiApplicationPrivate::init (/usr/lib/libQt5Gui.so.5.8.0)
20439 __libc_start_main (/usr/lib/libc-2.25.so)
78299 _start (/home/milian/projects/compiled/other/bin/heaptrack_gui)
heaptrack_gui 2228 135073.401156: 569521 cycles:
131633 QString::endsWith (/usr/lib/libQt5Core.so.5.8.0)
1a0701 QDir::cleanPath (/usr/lib/libQt5Core.so.5.8.0)
21b82d [unknown] (/usr/lib/libQt5Core.so.5.8.0)
1b3727 QFileInfo::canonicalFilePath (/usr/lib/libQt5Core.so.5.8.0)
2780c7 QFactoryLoader::update (/usr/lib/libQt5Core.so.5.8.0)
279525 QFactoryLoader::QFactoryLoader (/usr/lib/libQt5Core.so.5.8.0)
e5bd0 QPlatformIntegrationFactory::create (/usr/lib/libQt5Gui.so.5.8.0)
723dbf [unknown] ([unknown])
~~~~~
This patch fixes this issue and the libdw unwinder mimicks the libunwind
behavior more closely.
Signed-off-by: Milian Wolff <[email protected]>
Acked-by: Jan Kratochvil <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/unwind-libdw.c | 8 ++++++++
1 file changed, 8 insertions(+)
diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
index da45c4b..7755a5e0 100644
--- a/tools/perf/util/unwind-libdw.c
+++ b/tools/perf/util/unwind-libdw.c
@@ -178,6 +178,14 @@ frame_callback(Dwfl_Frame *state, void *arg)
Dwarf_Addr pc;
bool isactivation;
+ if (!dwfl_frame_pc(state, &pc, NULL)) {
+ pr_err("%s", dwfl_errmsg(-1));
+ return DWARF_CB_ABORT;
+ }
+
+ // report the module before we query for isactivation
+ report_module(pc, ui);
+
if (!dwfl_frame_pc(state, &pc, &isactivation)) {
pr_err("%s", dwfl_errmsg(-1));
return DWARF_CB_ABORT;