1

I'm trying to get a full call tree of gpbackup from https://github.com/greenplum-db/gpbackup. I use runtime/pprof, not net/http/pprof, so as far as I know there shouldn't be any time limitations for collecting stats. I start pprof server in a very beginning of a program and stop it right before os.Exit() command. To collect stats I run gpbackup, it works as intended and I get cpu.prof output. Then I use pprof --nodecount=100000 gpb cpu.prof and generate a call tree with png command. The problem is that call tree lacks of major number of functions. For example, DoBackup() starts with logging functions, but they miss in a call tree, and there are lots of other functions that don't seem to appear either. How can I make pprof show every single call in a call tree?

DENIS KOVALENKO
  • 31
  • 1
  • 7

1 Answers1

0

By default pprof removes nodes with less than 0.5% of the CPU time and edges with less then 0.1% of the CPU time. You can ask pprof to not do this by supplying the -nodefraction=0 and -edgefraction=0 flags, this might solve your issue.

so as far as I know there shouldn't be any time limitations for collecting stats

Not fully true, runtime/pprof samples 100 times per second. Every time it samples, it captures the full stack-trace. So you might miss functions if they execute faster than 100th of a second and are not part of the stack frame of longer running functions.

You could copy StartCPUProfile and change the hz variable so it captures more often.

Dylan Reimerink
  • 5,874
  • 2
  • 15
  • 21
  • Thanks, it helped showing some calls, but tree still doesn't have even 1/10 of all calls, though I tried setting refresh rate at 400-500 Hz. Actually, I don't get the mechanism cause I make a backup of the same test database, but every time I get different profiling results – DENIS KOVALENKO Jan 09 '22 at 21:59
  • When profiling, we request the OS to send interrupts to the process at given interval. This is the SIGPROF signal the docs talk about. When the runtime receives this signal, it interrupts the execution of the program and run profiling code. This profiling code looks at the stack trace and location where we were at the time of the interrupt. pprof then counts how often it was interrupted while in a specific func, which is how we get percentages. So if the interrupt never happens when in a function, it never appears in the profile. – Dylan Reimerink Jan 10 '22 at 08:29
  • Sorry, I didn't express my question correctly. Yeah, I know about interruptions, but why is pprof made that way it can miss some data if function didn't run long enough? For example, you have to compile c-program in a specific way, but it will be logged regardless execution time. So, the question was why pprof can give different outputs for the same command and dataset – DENIS KOVALENKO Jan 10 '22 at 08:53
  • The goal of pprof, profiling in general is to find out what part of your code is taking up the most time/memory so you can improve it(optimization). So if a function takes less then 100th of a second over the course of a whole profile, it is just noise for the purpose of finding the function which takes 50% of your CPU time. The second reason is that this is method can be used in production, you don't need to add instrumentation to your code which slows you down even if you are not profiling. You only pay for it while profiling is enabled. – Dylan Reimerink Jan 10 '22 at 11:13
  • If you are interested in exactly how much time is spent in which functions, you should use [trace](https://pkg.go.dev/runtime/trace) instead of pprof. With trace you can add user annotations to time specific parts of your code. But this requires manual instrumentation of your code. – Dylan Reimerink Jan 10 '22 at 11:17