Better perf integration for interpreted script profiling

[awelzel]

@JustinAzoff dug into Python 3.12's perf support and was wondering how hard it would be for Zeek to support this similarly. Could likely pull it off in a plugin, actually. Involves dynamic code generation of trampoline functions, mprotect and writing "magic" files to /tmp that perf can recognize.

References:

https://docs.python.org/3/howto/perf_profiling.html

https://github.com/python/cpython/pull/96123/files?diff=unified&w=0

[timwoj]

Would this allow flamegraphs to break Exprs into their actual lines of code/functions/etc? If so, I'm a big fan. It'd make flamegraphs for Zeek a lot more useful. Are you thinking this could just work via HookCallFunction?

[JustinAzoff]

Yes, that's exactly what it will enable. Assuming one can create the trampoline in HookCallFunction, I think that will work. Basically the first time a function is called, a unique copy of the trampoline has to be created, and then the address of that trampoline + your metadata (script filename, line) gets written to the perf map file.

[awelzel]

Would this allow flamegraphs to break Exprs into their actual lines of code/functions/etc? If so, I'm a big fan. It'd make flamegraphs for Zeek a lot more useful. Are you thinking this could just work via HookCallFunction?

I was thinking more in the direction of replacing Stmts within the Func.Body instances with a custom Stmt subclass wrapping the original one. At Stmt::Exec time, the wrapper would go through it's unique trampoline and use name of the original function, but location information from the wrapped stmt.

This is zeek::detail area, but seems a plugin at least initially would be much easier to iterate on and possibly less friction for outside contributors (and could work with older Zeek versions, too). We could always add it as a default builtin plugin.

[awelzel]

@JustinAzoff - if you have an x86-64 system available for testing: https://github.com/awelzel/zeek-perf-support

I didn't look too much at the Python version and just did the brute-force approach.

[JustinAzoff]

Neat! It could also be useful for zeek::detail::StmtList::Exec to get expanded, but may not need that level of granularity. Usually just knowing which file a stack descends from is enough to figure out where something is.

[JustinAzoff]

Made this of a smb pcap I had. I filtered the stacks for .zeek first to ignore everything else.

[awelzel]

It could also be useful for zeek::detail::StmtList::Exec to get expanded, but may not need that level of granularity.

That would be more of a perf annotate view - with native code you don't really see that either. But yes, could be done.

Hmm, in your graph, the Log::write is right above "zeek". I would have expected that to be stacked somewhere above SMB::write_file_log - did you apply some other normalization - maybe that's how you want to look at things?

[JustinAzoff]

I think this build is just less than optimal, it's on my laptop and not really built with frame pointers throughout, so that's probably why. I'll try adding this plugin to a build using framepointers and should get results more like yours

[awelzel]

@JustinAzoff , do you think if we patch jeprof to understand /tmp/perf-%d.map files we could actually enable production Zeek script memory profiling when running with zeek-perf-support and jemalloc profiling enabled? Did you mention that, actually?

Might be worth contributing so it would work for Python and the like, too. If jeprof only wasn't in Perl.

jemalloc/jemalloc#746

[JustinAzoff]

Yeah, afaik jeprof can benefit from the same mapping file.

I've had the same issue with jeprof :-) One of the things I end up doing is running jeprof on the same system with many profiles, and it spends a lot of redundant time doing symbol lookup that could be cached between runs as long as none of the binaries or libraries changes.