From owner-freebsd-performance@FreeBSD.ORG Tue Oct 28 09:49:27 2014 Return-Path: Delivered-To: freebsd-performance@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 15E4931F for ; Tue, 28 Oct 2014 09:49:27 +0000 (UTC) Received: from systemdatarecorder.org (mail.systemdatarecorder.org [54.246.96.61]) (using TLSv1.1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits)) (Client CN "localhost", Issuer "localhost" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id B428DF4B for ; Tue, 28 Oct 2014 09:49:25 +0000 (UTC) Received: from nereid (188-127-209-196.cust.suomicom.net [188.127.209.196]) (authenticated bits=0) by systemdatarecorder.org (8.14.4/8.14.4/Debian-2ubuntu2.1) with ESMTP id s9S9kepH012258 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT) for ; Tue, 28 Oct 2014 09:46:40 GMT Date: Tue, 28 Oct 2014 11:45:37 +0200 From: Stefan Parvu To: freebsd-performance@freebsd.org Subject: Re: pmcstat -z32 -G truncates callgraph to 8 Message-Id: <20141028114537.83f9f0a3c730949f453c3819@systemdatarecorder.org> In-Reply-To: References: Organization: systemdatarecorder.org X-Mailer: Sylpheed 3.4.2 (GTK+ 2.24.22; amd64-portbld-freebsd11.0) Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit X-BeenThere: freebsd-performance@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: Performance/tuning List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 28 Oct 2014 09:49:27 -0000 > 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