It seems like stackcollapse-perf.pl ignores the period associated with each sample record so all recorded samples are given the same weight. This ends up in the generated flamegraph not being consistent with what perf report outputs for the overhead of the different call stacks. I usually sample by specifying a frequency and the hardware CPU cycles event with something like perf record -e cpu-cycles -F 997 and I can get pretty different output. I was wondering if you run into the same thing.

This extends svg script to zoom/unzoom. This was only tested under chromium, but should not break from standard svg.

You may consider moving the "Reset Zoom" button to a more "clean" position.

Environment: hostname : xguan-ubuntu os release : 3.2.0-31-generic perf version : 3.2.28 arch : x86_64 cmdline : /usr/bin/perf_3.2.0-31 record -F 99 -p 19982 -g sleep 30

...

The perf.out:

java 19983 cycles: 7f7241fbe6d8 arrayOopDesc::base(BasicType) const (/home/xguan/opt/jdk1.8.0_112/jre/lib/amd64/server/libjvm.so) 7f7241239aec writeBytes (/home/xguan/opt/jdk1.8.0_112/jre/lib/amd64/libjava.so) 7f724123176f Java_java_io_FileOutputStream_writeBytes (/home/xguan/opt/jdk1.8.0_112/jre/lib/amd64/libjava.so) 7f722d119786 Ljava/io/FileOutputStream;::writeBytes (/tmp/perf-19982.map) 7f722d142778 Ljava/io/PrintStream;::print (/tmp/perf-19982.map) 7f722d12e1d4 LBusy;::main (/tmp/perf-19982.map) 7f722d0004e7 call_stub (/tmp/perf-19982.map) 7f72421d2d76 JavaCalls::call_helper(JavaValue_, methodHandle_, JavaCallArguments_, Thread_) (/home/xguan/opt/jdk1.8.0_112/jre/lib/amd64/server/libjvm.so) 7f72421ed566 jni_invoke_static(JNIEnv__, JavaValue_, jobject, JNICallType, jmethodID, JNI_ArgumentPusher_, Thread_) (/home/xguan/opt/jdk1.8.0_112/jre/lib/amd64/server/libjvm.so) 7f72421f987a jni_CallStaticVoidMethod (/home/xguan/opt/jdk1.8.0_112/jre/lib/amd64/server/libjvm.so) 7f724309ebdf JavaMain (/home/xguan/opt/jdk1.8.0_112/lib/amd64/jli/libjli.so) 7f72432b4e9a start_thread (/lib/x86_64-linux-gnu/libpthread-2.15.so)

When I tried:

./stackcollapse-perf.pl perf.out

Unrecognized line: java 19983 cycles: at ./stackcollapse-perf.pl line 264, <> line 3609. Use of uninitialized value $pname in string eq at ./stackcollapse-perf.pl line 246, <> line 3610.

And the fix is to tweak the regular expression in line 177.

I was playing with perf today for the first time and stackcollapse-perf.pl shows some warnings processing lines with the name of process having more than one space in it, like this one:

Plex DLNA Serve 26638 [001] 856620.530720: 2654110 cycles:

I think it also would close issue #78

I did not write perl code in the past, so please, test it... And thanks for FlameGraphs... ;)

This adds support for https://github.com/jrudolph/perf-map-agent/pull/35

You can see before/after here: https://gist.github.com/tjake/b762c51cc8a5ee89df290f2b4f361f81

Note: this patch is on top of #88

Frequently I see in perf sript entries like this:

httpd 18294 [008] 205996.782023:   10101010 cpu-clock:
                  2b20e5 [unknown] (/opt/remi/php56/root/usr/lib64/httpd/modules/libphp5.so)
            2b5e1de3f698 [unknown] ([unknown])
            2b5e00000013 [unknown] ([unknown])
        4c20ec834853fd89 [unknown] ([unknown])

mysqld 18314 [003] 205996.822418:   10101010 cpu-clock:
                  39a7c4 prev_record_reads(st_position*, unsigned int, unsigned long long) (/usr/libexec/mysqld)
                  39c65c best_access_path(JOIN*, st_join_table*, unsigned long long, unsigned int, bool, double, st_position*, st_position*) (/usr/libexec/mysqld)
                  39e997 [unknown] (/usr/libexec/mysqld)
                  39ed0f [unknown] (/usr/libexec/mysqld)
                  39ed0f [unknown] (/usr/libexec/mysqld)
                  39ed0f [unknown] (/usr/libexec/mysqld)
...

Then flame graph is occupied with a lot of [unknown] functions, even though some of unknowns have binary associated with them. Could you modify stackcollapse-perf.pl if it sees [unknown] but there's binary to show binary name, it could be like [/path/bin] for example. Or add option to do such replacements.

This adds support to process perf script output for programs containing threads with whitespace in the name. For example:

"java main 25607 4794564.109216: cycles:"

Hey @brendangregg,

looking through old PRs I found #134 very interesting. I have implemented a history safe (meaning the browsers back and forward functions won't interfere) solution that "safes" the zoom and/or search state.

It basically uses CSS attribute selectors[1] to match a frame ([x=100][y=200]) and uses GET parameters using the history API[2] to "store" the current zoom/search state.

Cheers,

Mike

[1] https://developer.mozilla.org/en-US/docs/Web/CSS/Attribute_selectors [2] https://developer.mozilla.org/en-US/docs/Web/API/History_API

Add the function's pc to the module name or the "unknown" string in order to identify where the unknown lies (useful for managed runtimes that are missing some reporting of JIT or other symbols) and to differentiate between unknowns.

I have installed kernel 4.8.6, and doing

perf record -F 99 -a -g -- sleep 10

followed by

perf script

gives

swapper     0 [000]   147.374682:          1 cycles:ppp: 
        ffffffff810631d4 native_write_msr+0x4 ([kernel.kallsyms])
        ffffffff8100b720 intel_pmu_enable_all+0x10 ([kernel.kallsyms])
        ffffffff81007403 x86_pmu_enable+0x263 ([kernel.kallsyms])
        ffffffff8117dcc2 perf_pmu_enable+0x22 ([kernel.kallsyms])
        ffffffff8117eba1 ctx_resched+0x51 ([kernel.kallsyms])
        ffffffff8117ed90 __perf_event_enable+0x1e0 ([kernel.kallsyms])
        ffffffff81177726 event_function+0xa6 ([kernel.kallsyms])
        ffffffff81178c1f remote_function+0x3f ([kernel.kallsyms])
        ffffffff8110887b flush_smp_call_function_queue+0x7b ([kernel.kallsyms])
        ffffffff81109363 generic_smp_call_function_single_interrupt+0x13 ([kernel.kallsyms])
        ffffffff81050d87 smp_call_function_single_interrupt+0x27 ([kernel.kallsyms])
        ffffffff8173ceec call_function_single_interrupt+0x8c ([kernel.kallsyms])
        ffffffff815b3427 cpuidle_enter+0x17 ([kernel.kallsyms])
        ffffffff810c6f6b cpu_startup_entry+0x2cb ([kernel.kallsyms])
        ffffffff8172dd47 rest_init+0x77 ([kernel.kallsyms])
        ffffffff81da5191 start_kernel+0x4a7 ([kernel.kallsyms])
        ffffffff81da45d6 x86_64_start_reservations+0x2a ([kernel.kallsyms])
        ffffffff81da4724 x86_64_start_kernel+0x14c ([kernel.kallsyms])

F.ex. x86_64_start_kernel+0x14c instead of x86_64_start_kernel.

Should stackcollapse-perf.pl automatically remove this, or should there be a new option for it ?

RHEL 7.2 w/ kernel-ml-4.8.6 from ELRepo.

Much faster implementation of text clipping, especially for Java stacks with long stack element texts. Makes zooming / unzooming less painful for big, complex FlameGraphs.

The command pipeline is as follows: perf record -g ./app perf script > app.perf cat app.perf | ./stackcollapse-perf.pl --all | ./flamegraph.pl > app.svg

My application is a multi-threaded application and the execution time is about 20 minutes. When I finished executing the above pipeline, I got an unexpected svg image, the flame graph does not truly reflect the actual situation。

ReadAlignChunk::mapChunk is a thread execution function, which should be a hotspot, and BarcodeMap::BarcodeMapping is a sub-function of a thread thread function, which should be a secondary hotspot. Another problem is that the call stack is too shallow, with less than 10 layers, far below expectations.

The loop in https://github.com/brendangregg/FlameGraph/blob/master/flamegraph.pl#L1077 which iterates over <g> elements, does not check if they have currently the .hide class. These elements still have their x and width values from before zoom, and seem to be collected in the matches hashmap, and counted towards count.

What I expected: The "Matched: x%" text should mean that the frames that (match the CTRL+F query) AND (are currently visible) consititute x% of the visible region.

What happens instead: The "Matched: x%" text seams to mean that the frames that (match the CTRL+F query) consititute x% of the visible region.

Why does it matter: This results in the Matched: 69.5% instead of Matched: 55.8% text in my case, but in general the differece can be arbitrarily huge. This is a problem to me, because I have function outer() which calls inner() and I wanted to know relation of inner()/outer() for each callstack separately - so I've zoomed to each call of outer() one by one and noted down the ratio, and was puzzled that the ratio is always larger than the average ratio (which I computed by zooming out and searching for outer() and inner() separately).

The text is displayed in the bottom left corner.

This text will show whenever the "Matched: x%" text is shown.

This can be useful when you're switching between multiple flamegraphs, and you come back to a graph with highlighted bars, but you don't remember what you searched for to highlight those bars.