All of lore.kernel.org
 help / color / mirror / Atom feed
From: Emanuele Aina <emanuele.aina@collabora.com>
To: linux-kernel@vger.kernel.org
Cc: Peter Zijlstra <peterz@infradead.org>,
	Ingo Molnar <mingo@redhat.com>,
	Arnaldo Carvalho de Melo <acme@kernel.org>,
	Alexander Shishkin <alexander.shishkin@linux.intel.com>
Subject: Incomplete backtraces/call stacks with `perf record --call-graph dwarf`
Date: Tue, 21 Jun 2016 18:27:28 +0200	[thread overview]
Message-ID: <1466526448.2944.18.camel@collabora.com> (raw)

Hello,
 I'm trying to trace applications with the intention of creating a
flame chart of their execution and I'm (ab)using `perf` to do so.

Unfortunately I keep getting incomplete call stacks, ie. stacks that
don't end up in main(). Using `--call-graph dwarf` improves the
situation a bit by storing some complete chains but some events still
don't go up to main().

$ perf record --call-graph dwarf -p $PID
$ perf script
[...]
cairo-checker-p 16494 48335.846306:     397338 cycles:ppp: 
            7f0a24bbddd7 sse2_fill (/usr/lib/x86_64-linux-gnu/libpixman-1.so.0.33.6)
            7f0a24ba21fb _pixman_implementation_fill (/usr/lib/x86_64-linux-gnu/libpixman-1.so.0.33.6)
            7f0a24b5c8b9 pixman_fill (/usr/lib/x86_64-linux-gnu/libpixman-1.so.0.33.6)
            7f0a2940e0c6 fill_boxes (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a29447af0 clip_and_composite_boxes.part.11 (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a29447fce clip_and_composite_boxes (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a294482e9 _cairo_spans_compositor_mask (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a294027f9 _cairo_compositor_paint (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a2944b191 _cairo_surface_paint (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a2940b12f _cairo_gstate_fill (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a294042f9 _cairo_default_context_fill (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a293fd335 cairo_fill (/usr/lib/x86_64-linux-gnu/libcairo.so.2.11400.6)
            7f0a2aad1b8a gdk_window_begin_paint_region (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a2af81487 gtk_main_do_event (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2000.6)
            7f0a2aab77b5 _gdk_event_emit (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a2aac64f8 _gdk_window_process_updates_recurse_helper (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a2aac761c gdk_window_process_updates_internal (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a2aac77d3 gdk_window_process_updates_with_mode (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a29a121d4 _g_closure_invoke_va (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.4800.1)
            7f0a29a2c9a6 g_signal_emit_valist (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.4800.1)
            7f0a29a2d08f g_signal_emit (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.4800.1)
            7f0a2aabf76e gdk_frame_clock_paint_idle (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a2aaadb38 gdk_threads_dispatch (/usr/lib/x86_64-linux-gnu/libgdk-3.so.0.2000.6)
            7f0a2973bac3 g_timeout_dispatch (/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
            7f0a2973b05a g_main_context_dispatch (/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
            7f0a2973b400 g_main_context_iterate.isra.29 (/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
            7f0a2973b722 g_main_loop_run (/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
            7f0a2af807d5 gtk_main (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2000.6)
                  40190c main (/home/em/zzz/cairo-checker-pattern)
            7f0a28e3c5f0 __libc_start_main (/lib/x86_64-linux-gnu/libc-2.22.so)
                  4011b9 _start (/home/em/zzz/cairo-checker-pattern)

cairo-checker-p 16494 48335.846485:     445044 cycles:ppp: 
            7f0a24b9352e bits_image_fetch_nearest_affine_normal_r5g6b5 (/usr/lib/x86_64-linux-gnu/libpixman-1.so.0.33.6)
            7f0a24ba063c general_composite_rect (/usr/lib/x86_64-linux-gnu/libpixman-1.so.0.33.6)

[...]

The first event is ok, I wonder why the second one does not chain up
like the first one (it's not something specific to libpixman, it
happens sometimes in libgtk-3 too).

Debug symbols are installed, gdb can get a full backtrace for
bits_image_fetch_nearest_affine_normal_r5g6b5() too:

gdb bits_image_fetch_nearest_affine_normal_r5g6b5()
> bt
#0  0x00007f74f0cdc450 in bits_image_fetch_nearest_affine_normal_r5g6b5 (iter=0x7ffd9ac65d10, mask=0x0) at ../../pixman/pixman-fast-path.c:3165
#1  0x00007f74f0ce963c in general_composite_rect (imp=0x1832e00, info=<optimized out>) at ../../pixman/pixman-general.c:220
#2  0x00007f74f0ca5761 in pixman_image_composite32 (op=op@entry=PIXMAN_OP_SRC, src=src@entry=0x1861920, mask=mask@entry=0x0, dest=dest@entry=0x19fc620, src_x=0, src_y=0, mask_x=0, mask_y=0, dest_x=0, dest_y=0, width=252, height=341) at ../../pixman/pixman.c:700
#3  0x00007f74f5556ac4 in composite_boxes (_dst=<optimized out>, op=<optimized out>, abstract_src=<optimized out>, abstract_mask=<optimized out>, src_x=0, src_y=0, mask_x=0, mask_y=0, dst_x=0, dst_y=0, boxes=0x7ffd9ac6c550, extents=0x7ffd9ac6c81c) at ../../../../src/cairo-image-compositor.c:538
#4  0x00007f74f5590a1a in clip_and_composite_boxes (boxes=0x7ffd9ac6c550, extents=0x7ffd9ac6c7e0, compositor=0x7f74f5838040 <spans>) at ../../../../src/cairo-spans-compositor.c:683
#5  0x00007f74f5590a1a in clip_and_composite_boxes (compositor=compositor@entry=0x7f74f5838040 <spans>, extents=extents@entry=0x7ffd9ac6c7e0, boxes=boxes@entry=0x7ffd9ac6c550) at ../../../../src/cairo-spans-compositor.c:882
#6  0x00007f74f5590fce in clip_and_composite_boxes (compositor=0x7f74f5838040 <spans>, extents=0x7ffd9ac6c7e0, boxes=0x7ffd9ac6c550) at ../../../../src/cairo-spans-compositor.c:901
#7  0x00007f74f55912e9 in _cairo_spans_compositor_mask (_compositor=0x7f74f5838040 <spans>, extents=0x7ffd9ac6c7e0) at ../../../../src/cairo-spans-compositor.c:999
#8  0x00007f74f554b7f9 in _cairo_compositor_paint (compositor=0x7f74f5838040 <spans>, surface=0x1936c20, op=<optimized out>, source=<optimized out>, clip=<optimized out>) at ../../../../src/cairo-compositor.c:65
#9  0x00007f74f5594191 in _cairo_surface_paint (surface=0x1936c20, op=CAIRO_OPERATOR_SOURCE, source=0x7ffd9ac6cb20, clip=0x1936ec0) at ../../../../src/cairo-surface.c:2117
#10 0x00007f74f5553895 in _cairo_gstate_paint (gstate=0x1ab9bd8) at ../../../../src/cairo-gstate.c:1067
#11 0x00007f74f5546175 in INT_cairo_paint (cr=0x1ab9a10) at ../../../../src/cairo.c:2003
#12 0x000000000040177a in drawCallback (widget=0x18be400 [GtkWindow], cr=0x1ab9a10, userData=0x7ffd9ac6f401) at cairo-checker-pattern.c:121
#13 0x00007f74f70cb48c in _gtk_marshal_BOOLEAN__BOXED (closure=closure@entry=0x1985b30, return_value=return_value@entry=0x7ffd9ac6ce80, n_param_values=n_param_values@entry=2, param_values=param_values@entry=0x7ffd9ac6cee0, invocation_hint=invocation_hint@entry=0x7ffd9ac6ce60, marshal_data=marshal_data@entry=0x0) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gtk/gtkmarshalers.c:86
#14 0x00007f74f720bfaf in gtk_widget_draw_marshaller (closure=0x1985b30, return_value=0x7ffd9ac6ce80, n_param_values=2, param_values=0x7ffd9ac6cee0, invocation_hint=0x7ffd9ac6ce60, marshal_data=0x0) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gtk/gtkwidget.c:955
#18 0x00007f74f5b7608f in <emit signal ??? on instance 0x18be400 [GtkWindow]> (instance=instance@entry=0x18be400, signal_id=<optimized out>, detail=detail@entry=0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gsignal.c:3441
    #15 0x00007f74f5b5afa5 in g_closure_invoke (closure=0x1985b30, return_value=return_value@entry=0x7ffd9ac6ce80, n_param_values=2, param_values=param_values@entry=0x7ffd9ac6cee0, invocation_hint=invocation_hint@entry=0x7ffd9ac6ce60) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gclosure.c:804
    #16 0x00007f74f5b6cfc1 in signal_emit_unlocked_R (node=node@entry=0x1889430, detail=detail@entry=0, instance=instance@entry=0x18be400, emission_return=emission_return@entry=0x7ffd9ac6cff0, instance_and_params=instance_and_params@entry=0x7ffd9ac6cee0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gsignal.c:3629
    #17 0x00007f74f5b757f9 in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffd9ac6d0a0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gsignal.c:3395
#19 0x00007f74f7218ada in gtk_widget_draw_internal (widget=0x18be400 [GtkWindow], cr=0x1ab9a10, clip_to_size=<optimized out>) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gtk/gtkwidget.c:6983
#20 0x00007f74f7218dd9 in gtk_widget_send_expose (widget=widget@entry=0x18be400 [GtkWindow], event=event@entry=0x7ffd9ac6d2c0) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gtk/gtkwidget.c:7528
#21 0x00007f74f70ca492 in gtk_main_do_event (event=0x7ffd9ac6d2c0) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gtk/gtkmain.c:1798
#22 0x00007f74f6c007b5 in _gdk_event_emit (event=event@entry=0x7ffd9ac6d2c0) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdkevents.c:73
#23 0x00007f74f6c0f4f8 in _gdk_window_process_updates_recurse_helper (window=0x184a5c0 [GdkWaylandWindow], expose_region=<optimized out>) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdkwindow.c:3587
#24 0x00007f74f6c1061c in gdk_window_process_updates_internal (window=0x184a5c0 [GdkWaylandWindow]) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdkwindow.c:3733
#25 0x00007f74f6c107d3 in gdk_window_process_updates_with_mode (window=<optimized out>, recurse_mode=<optimized out>) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdkwindow.c:3934
#26 0x00007f74f5b5b1d4 in _g_closure_invoke_va (closure=closure@entry=0x19c2fb0, return_value=return_value@entry=0x0, instance=instance@entry=0x188e230, args=args@entry=0x7ffd9ac6d5e0, n_params=<optimized out>, param_types=0x0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gclosure.c:867
#27 0x00007f74f5b759a6 in g_signal_emit_valist (instance=0x188e230, signal_id=<optimized out>, detail=0, var_args=var_args@entry=0x7ffd9ac6d5e0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gsignal.c:3294
#28 0x00007f74f5b7608f in g_signal_emit (instance=instance@entry=0x188e230, signal_id=<optimized out>, detail=detail@entry=0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./gobject/gsignal.c:3441
#29 0x00007f74f6c080bf in _gdk_frame_clock_emit_paint (frame_clock=frame_clock@entry=0x188e230 [GdkFrameClockIdle]) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdkframeclock.c:640
#30 0x00007f74f6c0876e in gdk_frame_clock_paint_idle (data=0x188e230) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdkframeclockidle.c:430
#31 0x00007f74f6bf6b38 in gdk_threads_dispatch (data=0x19acc40, data@entry=<error reading variable: value has been optimized out>) at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gdk/gdk.c:720
#32 0x00007f74f5884ac3 in g_timeout_dispatch (source=0x1afab00, callback=<optimized out>, user_data=<optimized out>) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./glib/gmain.c:4577
#33 0x00007f74f588405a in g_main_context_dispatch (context=0x183c200) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./glib/gmain.c:3154
#34 0x00007f74f588405a in g_main_context_dispatch (context=context@entry=0x183c200) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./glib/gmain.c:3769
#35 0x00007f74f5884400 in g_main_context_iterate (context=0x183c200, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./glib/gmain.c:3840
#36 0x00007f74f5884722 in g_main_loop_run (loop=0x19773a0) at /build/glib2.0-wnDt2X/glib2.0-2.48.1/./glib/gmain.c:4034
#37 0x00007f74f70c97d5 in gtk_main () at /build/gtk+3.0-UYMeaD/gtk+3.0-3.20.6/./gtk/gtkmain.c:1269
#38 0x000000000040190c in main (argc=2, argv=0x7ffd9ac6d998) at cairo-checker-pattern.c:152

I'm on Debian unstable, kernel 4.6.2-1 x86_64.

Any idea of what I'm doing wrong?

Thanks!

-- 

Emanuele Aina
www.collabora.com

                 reply	other threads:[~2016-06-21 16:29 UTC|newest]

Thread overview: [no followups] expand[flat|nested]  mbox.gz  Atom feed

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=1466526448.2944.18.camel@collabora.com \
    --to=emanuele.aina@collabora.com \
    --cc=acme@kernel.org \
    --cc=alexander.shishkin@linux.intel.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mingo@redhat.com \
    --cc=peterz@infradead.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.