pmcstat -z32 -G truncates callgraph to 8

Stefan Parvu sparvu at systemdatarecorder.org
Tue Oct 28 09:49:27 UTC 2014


 
> I'm using pmcstat to capture call graphs, however, these always seem
> truncated to 8 stack frames. Anyone else hit this? Anyone know a fix
> or workaround?

On FreeBSD 11.0-CURRENT Im seeing these:

kern.features.hwpmc_hooks: 1
kern.hwpmc.softevents: 16
kern.hwpmc.callchaindepth: 16
kern.hwpmc.hashsize: 1024
kern.hwpmc.nsamples: 1024
kern.hwpmc.mtxpoolsize: 2048
kern.hwpmc.logbuffersize: 4
kern.hwpmc.nbuffers: 1024

and for example a trace ...

00.53%  [48]       strcmp @ /lib/libc.so.7
 56.25%  [27]        0x1c4e43 @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
  100.0%  [27]         g_object_get_valist @ /usr/local/lib/libgobject-2.0.so.0.3600.3
   100.0%  [27]          g_object_get
    70.37%  [19]           _gtk_tooltip_handle_event @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
     100.0%  [19]            gtk_main_do_event
      100.0%  [19]             0x662e1 @ /usr/local/lib/libgdk-x11-2.0.so.0.2400.22
       100.0%  [19]              g_main_context_dispatch @ /usr/local/lib/libglib-2.0.so.0.3600.3
        100.0%  [19]               0x554e3
         78.95%  [15]                g_main_loop_run
          100.0%  [15]                 gtk_main @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
         21.05%  [4]                 g_main_context_iteration @ /usr/local/lib/libglib-2.0.so.0.3600.3
          100.0%  [4]                  gtk_main_iteration @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
           100.0%  [4]                   0x2ea45 @ /usr/local/lib/libsylph-0.so.1.2.0
            100.0%  [4]                    0x34786
             100.0%  [4]                     0x33208
    29.63%  [8]            0x2371d8 @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
     100.0%  [8]             _gtk_tooltip_handle_event
      100.0%  [8]              gtk_main_do_event
       100.0%  [8]               0x662e1 @ /usr/local/lib/libgdk-x11-2.0.so.0.2400.22
        100.0%  [8]                g_main_context_dispatch @ /usr/local/lib/libglib-2.0.so.0.3600.3
         100.0%  [8]                 0x554e3
          87.50%  [7]                  g_main_loop_run
           100.0%  [7]                   gtk_main @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
          12.50%  [1]                  g_main_context_iteration @ /usr/local/lib/libglib-2.0.so.0.3600.3
           100.0%  [1]                   gtk_main_iteration @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
            100.0%  [1]                    0x2ea45 @ /usr/local/lib/libsylph-0.so.1.2.0
             100.0%  [1]                     0x34786
              100.0%  [1]                      0x33208
 18.75%  [9]         g_hash_table_lookup @ /usr/local/lib/libglib-2.0.so.0.3600.3
  55.56%  [5]          0x1d89b @ /usr/local/lib/libgobject-2.0.so.0.3600.3
   100.0%  [5]           g_param_spec_pool_lookup
    40.00%  [2]            g_object_get_valist
     100.0%  [2]             g_object_get
      50.00%  [1]              0x23692f @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
       100.0%  [1]               _gtk_tooltip_handle_event
        100.0%  [1]                gtk_main_do_event
         100.0%  [1]                 0x662e1 @ /usr/local/lib/libgdk-x11-2.0.so.0.2400.22
          100.0%  [1]                  g_main_context_dispatch @ /usr/local/lib/libglib-2.0.so.0.3600.3
           100.0%  [1]                   0x554e3
:
00.54%  [49]       acpi_cpu_c1 @ /boot/kernel/kernel
 100.0%  [49]        acpi_cpu_idle
  100.0%  [49]         cpu_idle_acpi
   100.0%  [49]          cpu_idle
    100.0%  [49]           sched_idletd
     100.0%  [49]            fork_exit

00.53%  [48]       strcmp @ /lib/libc.so.7
 56.25%  [27]        0x1c4e43 @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
  100.0%  [27]         g_object_get_valist @ /usr/local/lib/libgobject-2.0.so.0.3600.3
   100.0%  [27]          g_object_get
    70.37%  [19]           _gtk_tooltip_handle_event @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
     100.0%  [19]            gtk_main_do_event
      100.0%  [19]             0x662e1 @ /usr/local/lib/libgdk-x11-2.0.so.0.2400.22
       100.0%  [19]              g_main_context_dispatch @ /usr/local/lib/libglib-2.0.so.0.3600.3
        100.0%  [19]               0x554e3
         78.95%  [15]                g_main_loop_run
          100.0%  [15]                 gtk_main @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
         21.05%  [4]                 g_main_context_iteration @ /usr/local/lib/libglib-2.0.so.0.3600.3
          100.0%  [4]                  gtk_main_iteration @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
           100.0%  [4]                   0x2ea45 @ /usr/local/lib/libsylph-0.so.1.2.0
            100.0%  [4]                    0x34786
             100.0%  [4]                     0x33208
    29.63%  [8]            0x2371d8 @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
     100.0%  [8]             _gtk_tooltip_handle_event
      100.0%  [8]              gtk_main_do_event
       100.0%  [8]               0x662e1 @ /usr/local/lib/libgdk-x11-2.0.so.0.2400.22
        100.0%  [8]                g_main_context_dispatch @ /usr/local/lib/libglib-2.0.so.0.3600.3
         100.0%  [8]                 0x554e3
          87.50%  [7]                  g_main_loop_run
           100.0%  [7]                   gtk_main @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
          12.50%  [1]                  g_main_context_iteration @ /usr/local/lib/libglib-2.0.so.0.3600.3
           100.0%  [1]                   gtk_main_iteration @ /usr/local/lib/libgtk-x11-2.0.so.0.2400.22
            100.0%  [1]                    0x2ea45 @ /usr/local/lib/libsylph-0.so.1.2.0
             100.0%  [1]                     0x34786
              100.0%  [1]                      0x33208


Full output here:
http://www.systemdatarecorder.org/out.pmc



-- 
Stefan Parvu <sparvu at systemdatarecorder.org>


More information about the freebsd-performance mailing list