When to go pprof sampling

This is a creation in Article, where the information may have evolved or changed.

import (_ "net/http/pprof")func main() {go func() {log.Println(http.ListenAndServe("localhost:6060", nil))}()}

This code should be familiar to everyone, the go tool pprof tool's general code, used to do performance analysis. I have tried this for two days, and there is a question: What is the sampling pprof , and when did this sample take place? is the program start sampling or when I curl localhost:$PORT/debug/pprof/$PROFILE_TYPE start?

Why do you think about this, mainly in the framework of the Watch integration pprof , the default open, if the program is initially sampled, it is a loss of performance. You don't have to believe that when people answer that question, let's just look at pprof the code.

The code of the standard library is $GOROOT/src below and we look for the pprof path on my Mac is/usr/local/Cellar/go/1.9.2/libexec/src/net/http/pprof/pprof.go

The first is the init function, which registers the analysis URLs we used:

func init() {    http.Handle("/debug/pprof/", http.HandlerFunc(Index))    http.Handle("/debug/pprof/cmdline", http.HandlerFunc(Cmdline))    http.Handle("/debug/pprof/profile", http.HandlerFunc(Profile))    http.Handle("/debug/pprof/symbol", http.HandlerFunc(Symbol))    http.Handle("/debug/pprof/trace", http.HandlerFunc(Trace))}

This is done at the start of the program, which is why we feel as if the import is going to be all right. Actually see here should understand, profile is just ordinary function call, program start just registered handler, real sampling should be executed after request.

But come here, we may as well look down, after all, need to look at the standard library is not many opportunities. Let's take cpu profile a look at the Profile function:

Profile responds with the Pprof-formatted CPU profile.//the package initialization registers it As/debug/pprof/profil E.func Profile (w http. Responsewriter, R *http. Request) {sec, _: = StrConv. parseint (R.formvalue ("seconds"), ten, () if sec = = 0 {sec = ten} if Durationexceedswritetimeout (R, Float6 4 (sec)) {W.header (). Set ("Content-type", "Text/plain; Charset=utf-8 ") W.header (). Set ("X-go-pprof", "1") W.writeheader (http. Statusbadrequest) fmt. Fprintln (W, "Profile duration exceeds server ' s WriteTimeout") return}//Set Content Type assuming Startcpup    Rofile'll work,//Because if it does it starts writing. W.header (). Set ("Content-type", "Application/octet-stream") if err: = Pprof. Startcpuprofile (w);        Err! = Nil {//Startcpuprofile failed, so no writes yet.        Can change the header back to text content//and send error code. W.header (). Set ("Content-type", "Text/plain; Charset=utf-8 ") W. Header (). Set ("X-go-pprof", "1") W.writeheader (http. Statusinternalservererror) fmt. fprintf (W, "Could not enable CPU profiling:%s\n", err) Return} sleep (W, time. Duration (sec) *time. Second) pprof. Stopcpuprofile ()}

Get a default time of 30 seconds, execute StartCPUProfile , inside should be a goroutine , call back after sleep a bit, end cpu profile . The sampling should be in StartCPUProfile , execution seconds time.

Look again.StartCPUProfile

func StartCPUProfile(w io.Writer) error {    // 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    cpu.Lock()    defer cpu.Unlock()    if cpu.done == nil {        cpu.done = make(chan bool)    }    // Double-check.    if cpu.profiling {        return fmt.Errorf("cpu profiling already in use")    }    cpu.profiling = true    runtime.SetCPUProfileRate(hz)    go profileWriter(w)    return nil}

Note explains the origin of the sampling frequency, let's look at the concept of CPU frequency:

The CPU clock frequency (CPU clock speed) that the CPU core is operating on. The basic unit of the CPU's frequency is Hertz (Hz), but it is more in megahertz (MHz) or megahertz (GHZ) units. The countdown of the clock frequency is the clock cycle. The base unit of the clock cycle is seconds (s), but more in milliseconds (ms), subtle (US), or nanosecond (NS). During a clock cycle, the CPU executes an operation instruction. In other words, a CPU operation instruction can be executed every 1 milliseconds at the CPU frequency of the three Hz. At a CPU frequency of 1 MHz, a CPU operation instruction can be executed every 1 subtle. At the CPU frequency of 1 GHz, a CPU operation instruction can be executed every 1 nanoseconds.

By default, the run-time system of the Go language samples CPU usage at a frequency of. That is, the sample is sampled 100 times per second, that is, every 10 milliseconds. Why use this frequency? Because it's enough to produce useful data, it doesn't stop the system from stalling. and 100 of this number is also easy to do conversion, such as gross position sampling count to the number of samples per second. In fact, the sampling of CPU usage described here is a sampling of the program counters on the current goroutine stack. Thus, we can analyze from the sample records which code is the most time-consuming or the most CPU-intensive part.

Code is easy to understand, lock the CPU, set the runtime sampling frequency, profileWriter is actually sampled.

So the conclusion is that the sampling will not take place until after the request, and there is no problem with the on-line open sampling interface.

Resources

• Profiling Go Programs
• Profiling Go programs with Pprof
• Go Tool pprof