{"id":169,"date":"2012-03-01T00:03:24","date_gmt":"2012-02-29T23:03:24","guid":{"rendered":"http:\/\/blog.mozilla.org\/jseward\/?p=169"},"modified":"2012-03-01T00:03:24","modified_gmt":"2012-02-29T23:03:24","slug":"visualising-profiling-results-by-aggregating-stack-traces","status":"publish","type":"post","link":"https:\/\/blog.mozilla.org\/jseward\/2012\/03\/01\/visualising-profiling-results-by-aggregating-stack-traces\/","title":{"rendered":"Visualising profiling results by aggregating stack traces"},"content":{"rendered":"<p>On Android, we have a couple of ways to periodically extract stack traces from a running Firefox: the built in profiler, and Valgrind.\u00a0 In principle oprofile could also produce stacks at intervals, although it doesn&#8217;t.<\/p>\n<p>Looking at zillions of stacks, or text-only output derived from them, isn&#8217;t much fun.\u00a0 What I&#8217;d really like to do is take a large number of stacks sampled at equal cost intervals, and use Josef Weidendorfer&#8217;s excellent <a title=\"KCachegrind GUI\" href=\"http:\/\/kcachegrind.sourceforge.net\/html\/Home.html\">KCachegrind GUI<\/a> to visualise the data.\u00a0 KCachegrind, if you haven&#8217;t tried it, makes it easy to examine the dynamic call graph and to see how costs flow between callers and callees.<\/p>\n<p>To do this, the call stacks need to be merged into an approximate dynamic call graph, cycles found and collapsed, and costs propagated back up from leaf nodes.\u00a0 This produces the approximate inclusive and exclusive costs for each node (function) encountered.<\/p>\n<p>So I wrote a program to do this.\u00a0 It takes Valgrind-style call stacks and produces KCachegrind output files.\u00a0 It could easily be generalised to other call stack generators &#8212; the call stack elements only need to be comparable for equality.<\/p>\n<p>I ran Firefox on Android, used the STR in <a href=\"https:\/\/bugzilla.mozilla.org\/show_bug.cgi?id=728846\">bug 728846<\/a> as a test workload, and obtained about 32000 16-entry stacks, sampled at approximately million-instruction intervals.\u00a0 Merging them and viewing the results in KCachegrind produces output which at least roughly tallies with the ad-hoc observations listed in the bug report.<\/p>\n<p>There&#8217;s clearly room for improvement, particularly in the handling of cycles, and the fact that it&#8217;s limited by how often the stack unwinder produces an incomplete trace.\u00a0 Nevertheless it&#8217;s an interesting bit of code to have around.\u00a0 Here&#8217;s a snapshot of a bit of the graph leading up to fast_composite_over_8888_0565, which features prominently in the report. <a href=\"http:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-1.png\"><img decoding=\"async\" loading=\"lazy\" class=\"alignleft size-full wp-image-171\" title=\"stack-merge-1\" src=\"http:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-1.png\" alt=\"\" width=\"582\" height=\"691\" srcset=\"https:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-1.png 582w, https:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-1-252x300.png 252w\" sizes=\"(max-width: 582px) 100vw, 582px\" \/><\/a><\/p>\n<p>&nbsp;<\/p>\n<p>And here&#8217;s a picture of KCachegrind showing the caller and callee relationships for moz_pixman_image_composite32.<\/p>\n<p><a href=\"http:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-2.png\"><img decoding=\"async\" loading=\"lazy\" class=\"alignleft size-full wp-image-172\" title=\"stack-merge-2\" src=\"http:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-2.png\" alt=\"\" width=\"418\" height=\"441\" srcset=\"https:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-2.png 418w, https:\/\/blog.mozilla.org\/jseward\/files\/2012\/02\/stack-merge-2-284x300.png 284w\" sizes=\"(max-width: 418px) 100vw, 418px\" \/><\/a><\/p>\n","protected":false},"excerpt":{"rendered":"<p>On Android, we have a couple of ways to periodically extract stack traces from a running Firefox: the built in profiler, and Valgrind.\u00a0 In principle oprofile could also produce stacks at intervals, although it doesn&#8217;t. Looking at zillions of stacks, &hellip; <a class=\"go\" href=\"https:\/\/blog.mozilla.org\/jseward\/2012\/03\/01\/visualising-profiling-results-by-aggregating-stack-traces\/\">Continue reading<\/a><\/p>\n","protected":false},"author":240,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"_links":{"self":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/posts\/169"}],"collection":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/users\/240"}],"replies":[{"embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/comments?post=169"}],"version-history":[{"count":0,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/posts\/169\/revisions"}],"wp:attachment":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/media?parent=169"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/categories?post=169"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/tags?post=169"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}