How to get a breakdown of a function-duration in go (profiling)
Update (January 24, 2019):
This question was asked 4 years ago about Go 1.4 (and is still getting opinions). Since then, profiling with pprof has changed a lot.
Original question:
I am trying to profile a server based on go martini I wrote, I want to profile a single request and get a full breakdown of the functions with their execution times. I tried to play around with runtime/pprof
and net/http/pprof
but the result looks like this:
Total: 3 samples
1 33.3% 33.3% 1 33.3% ExternalCode
1 33.3% 66.7% 1 33.3% runtime.futex
1 33.3% 100.0% 2 66.7% syscall.Syscall
Web browsing is also not very helpful.
We regularly profile another program, and it seems to me that I want the result:
20ms of 20ms total ( 100%)
flat flat% sum% cum cum%
10ms 50.00% 50.00% 10ms 50.00% runtime.duffcopy
10ms 50.00% 100% 10ms 50.00% runtime.fastrand1
0 0% 100% 20ms 100% main.func·004
0 0% 100% 20ms 100% main.pruneAlerts
0 0% 100% 20ms 100% runtime.memclr
I can't tell where the difference comes from.
source to share
pprof
is a timer-based sampling profiler originally from the gperftools suite . Rus Cox later ported the pprof tools to Go: http://research.swtch.com/pprof .
This timer based profiler works by using a system profiling timer and recording statistics whenever it gets SIGPROF
. The go mode is now set to a constant of 100 Hz. From pprof.go:
// The runtime routines allow a variable profiling rate,
// but in practice operating systems cannot trigger signals
// at more than about 500 Hz, and our processing of the
// signal is not cheap (mostly getting the stack trace).
// 100 Hz is a reasonable choice: it is frequent enough to
// produce useful data, rare enough not to bog down the
// system, and a nice round number to make it easy to
// convert sample counts to seconds. Instead of requiring
// each client to specify the frequency, we hard code it.
const hz = 100
You can set this frequency by calling runtime.SetCPUProfileRate
and writing the profile output yourself, and Gperftools allows you to set this frequency with CPUPROFILE_FREQUENCY
, but in practice this is not so useful.
To try a program, it must do what you are trying to measure at any time. Sampling in standby mode does not show anything useful. What you usually do is run the code you want in a benchmark or hot loop using as much CPU time as possible. After accumulating enough samples, there should be a sufficient number across all functions to show you proportionately how much time was spent on each function.
See also:
source to share