Pprof of Go you didn't know - Moment For Technology

Introduction to the

Go has a number of useful tools that pprof can use to analyze the performance of a program. There are four types of PPROF:

CPU profiling: This is the most commonly used type. Analyze the execution time of a function or method.
Memory profiling: This type is also commonly used. Used to analyze the memory usage of the program;
Block profiling: This is unique to Go and is used to record the time goroutine spends waiting for shared resources;
Mutex profiling: Similar to Block profiling, but only logs waits or delays due to lock contention.

We will focus on the first two types. The pprof related functionality in Go is in the package Runtime /pprof.

CPU profiling

Pprof is very simple to use. CPU profiling is first enabled by calling pprof.startCpuProfile (). It takes an argument of type IO.Writer, to which pprof writes analysis results. To facilitate post-mortem analysis, we write it in a file.

Call pprof.stopCpuProfile () after the code to analyze. The code execution between StartCPUProfile() and StopCPUProfile() will be analyzed. For convenience, you can call StopCPUProfile() directly after StartCPUProfile() with defer, analyzing all the code after that.

We now implement a function that computes the NTH number of the Fibonacci sequence:

func fib(n int) int {
  if n <= 1 {
    return 1
  }

  return fib(n- 1) + fib(n2 -)}Copy the code

Then use pprof to analyze the run:

func main(a) {
  f, _ := os.OpenFile("cpu.profile", os.O_CREATE|os.O_RDWR, 0644)
  defer f.Close()
  pprof.StartCPUProfile(f)
  defer pprof.StopCPUProfile()

  n := 10
  for i := 1; i <= 5; i++ {
    fmt.Printf("fib(%d)=%d\n", n, fib(n))
    n += 3 * i
  }
}
Copy the code

Run main.go generates a cpu.profile file. This file records the running state of the program. Analyze this file using the go Tool pprof command:

Use the top command above to see the top 10 most time-consuming functions. It can be seen that fib function takes the highest time, with a total time of 390ms, accounting for 90.70% of the total time. We can also use the top5 and top20 to see the top5 and 20 functions that take the most time, respectively.

When we find a function that takes a lot of time, we can also use the list command to see how the function is called and what the time is on each call path. The list command is followed by a pattern representing the method name:

We know that there are a lot of repeated calculations using recursion to solve Fibonacci numbers. Let’s optimize this function:

func fib2(n int) int {
  if n <= 1 {
    return 1
  }

  f1, f2 := 1.1
  for i := 2; i <= n; i++ {
    f1, f2 = f2, f1+f2
  }

  return f2
}
Copy the code

How long does it take to iterate? Let’s measure it. The CPU. Profile file is generated by executing go run main.go and then using the go Tool pprof analysis:

Here top sees an empty list. Since CPU profiling is enabled, the runtime interrupts every 10ms to record the currently executing stack of each Goroutine to analyze time spent. Our optimized code executes before it can be interrupted at runtime, so there is no information.

All commands executed by go Tool pprof can be viewed with help:

Memory profiling

Memory analysis is different in that we can look at heap memory at any time while the program is running. Let’s write a function that generates a random string and repeats the string n times:

const Letters = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ"

func generate(n int) string {
  var buf bytes.Buffer
  for i := 0; i < n; i++ {
    buf.WriteByte(Letters[rand.Intn(len(Letters))])
  }
  return buf.String()
}

func repeat(s string, n int) string {
  var result string
  for i := 0; i < n; i++ {
    result += s
  }

  return result
}
Copy the code

Write a program, call the above function, record the memory usage:

func main(a) {
  f, _ := os.OpenFile("mem.profile", os.O_CREATE|os.O_RDWR, 0644)
  defer f.Close()
  for i := 0; i < 100; i++ {
    repeat(generate(100), 100)
  }

  pprof.Lookup("heap").WriteTo(f, 0)}Copy the code

Here at the end of the loop, pprofe.lookup (“heap”) looks at the heap usage and writes the result to the file mem.profile.

Run the go run main.go command to generate the mem.profile file and then use the go Tool pprof mem.profile to analyze:

You can also use the list command to see on which line memory is allocated:

The result is expected because string concatenation takes up a lot of temporary space.

`pkg/profile`

Runtime /pprof is a bit awkward to use because you have to write the code repeatedly to open the file, start the analysis, and end the analysis. So there is a library wrapped around runtime/pprof: PKG /profile. The GitHub storage address of PKG /profile is github.com/pkg/profile… Get github.com/pkg/profile ‘to get the library.

defer profile.Start().Stop()
Copy the code

CPU profiling is enabled by default, and data is written to the file CPU.pprof. Use it to analyze the performance of our FIB program:

$ go run main.go 
2021/06/09 21:10:36 profile: cpu profiling enabled, C:\Users\ADMINI~1\AppData\Local\Temp\profile594431395\cpu.pprof
fib(10) =89
fib(13) =377
fib(19) =6765
fib(28) =514229
fib(40) =165580141
2021/06/09 21:10:37 profile: cpu profiling disabled, C:\Users\ADMINI~1\AppData\Local\Temp\profile594431395\cpu.pprof
Copy the code

The console outputs the file path to which the analysis results are written.

To enable Memory profiling, you can pass in the function option MemProfile:

defer profile.Start(profile.MemProfile).Stop()
Copy the code

You can also control the memory sampling rate through function options, which default is 4096. We can change it to 1:

defer profile.Start(profile.MemProfile, profile.MemProfileRate(1)).Stop()
Copy the code

Flame figure

It is not intuitive to view the CPU or memory using the command line. Bredan Gregg invented the Flame Graph to visualize memory and CPU consumption. The new version of the Go Tool Pprof tool has integrated fire maps (I used GO 1.16). To generate a flame diagram, you must install Graphviz.

On the Mac:

brew install graphviz
Copy the code

On Ubuntu:

apt install graphviz
Copy the code

On Windows, download website page www.graphviz.org/download/ is an executable install file, download and install. Note Set PATH to the PATH.

Profile and MEM.profile generated by the above program we can view the flame map directly on the web page. Run the following command:

go tool pprof -http :8080 cpu.profile
Copy the code

By default, the browser window opens, displaying the following page:

We can toggle to show the flame map in the VIEW menu bar:

You can hover and click over the flame chart to see a specific call.

net/http/pprof

What can I do if I encounter high CPU or memory usage online? You can’t compile the above Profile code into production, which would have a significant impact on performance. Asp.net/HTTP /pprof provides a method that, when not used, has no impact, and profiling can be turned on to help troubleshoot problems. ListenAndServe() starts a default HTTP server on a port by simply using the import package and calling http.listenandServe () in a new Goroutine:

import(_"net/http/pprof"
)

func NewProfileHttpServer(addr string) {
  go func(a) {
    log.Fatalln(http.ListenAndServe(addr, nil}} ()))Copy the code

Let’s write an HTTP server that takes the Fibonacci number and repeated strings from the previous example and puts them on the Web. To make the test more obvious, I executed a function 1000 times that was previously executed once:

func fibHandler(w http.ResponseWriter, r *http.Request) {
  n, err := strconv.Atoi(r.URL.Path[len("/fib/":))iferr ! =nil {
    responseError(w, err)
    return
  }

  var result int
  for i := 0; i < 1000; i++ {
    result = fib(n)
  }
  response(w, result)
}

func repeatHandler(w http.ResponseWriter, r *http.Request) {
  parts := strings.SplitN(r.URL.Path[len("/repeat/":),"/".2)
  if len(parts) ! =2 {
    responseError(w, errors.New("invalid params"))
    return
  }

  s := parts[0]
  n, err := strconv.Atoi(parts[1])
  iferr ! =nil {
    responseError(w, err)
    return
  }

  var result string
  for i := 0; i < 1000; i++ {
    result = repeat(s, n)
  }
  response(w, result)
}
Copy the code

To create the HTTP server, register the handlers:

func main(a) {
  mux := http.NewServeMux()
  mux.HandleFunc("/fib/", fibHandler)
  mux.HandleFunc("/repeat/", repeatHandler)

  s := &http.Server{
    Addr:    ": 8080",
    Handler: mux,
  }

  NewProfileHttpServer(": 9999")

  iferr := s.ListenAndServe(); err ! =nil {
    log.Fatal(err)
  }
}
Copy the code

We started an additional HTTP server to handle pPROF related requests.

Also to test, I wrote a program that kept sending HTTP requests to the server:

func doHTTPRequest(url string) {
  resp, err := http.Get(url)
  iferr ! =nil {
    fmt.Println("error:", err)
    return
  }

  data, _ := ioutil.ReadAll(resp.Body)
  fmt.Println("ret:".len(data))
  resp.Body.Close()
}

func main(a) {
  var wg sync.WaitGroup
  wg.Add(2)
  go func(a) {
    defer wg.Done()
    for {
      doHTTPRequest(fmt.Sprintf("http://localhost:8080/fib/%d", rand.Intn(30)))
      time.Sleep(500 * time.Millisecond)
    }
  }()

  go func(a) {
    defer wg.Done()
    for {
      doHTTPRequest(fmt.Sprintf("http://localhost:8080/repeat/%s/%d", generate(rand.Intn(200)), rand.Intn(200)))
      time.Sleep(500 * time.Millisecond)
    }
  }()
  wg.Wait()
}
Copy the code

Run the go run main.go command to start the server. Run the above program to keep sending requests to the server. After a period of time, we can use the browser to open http://localhost:9999/debug/pprof/:

Go Tool Pprof also supports remote access to profile files:

$ go tool pprof -http :8080 localhost:9999/debug/pprof/profile? seconds=120
Copy the code

Seconds =120 indicates 120s sampling. The default value is 30s. The results are as follows:

It can be seen that fibHandler and repeatHandler are the main fibHandler and repeatHandler processes in addition to runtime consumption.

Of course, it is not possible to open this port online, because there is a great security risk. Therefore, we generally generate a profile on the machine online and download the file to local analysis. The above we can see the go tool pprof generates a file stored in the local, such as my machine is C: \ Users \ \ Administrator \ pprof \ pprof samples. CPU. 001. The pb. Gz. Download this file locally and then:

$ go tool pprof -http :8888 pprof.samples.cpu001..pb.gz
Copy the code

`net/http/pprof`implementation

The net/ HTTP /pprof implementation is no mystery, except that some handlers are registered in the init() function of the net/ HTTP /pprof package:

// src/net/http/pprof/pprof.go
func init(a) {
  http.HandleFunc("/debug/pprof/", Index)
  http.HandleFunc("/debug/pprof/cmdline", Cmdline)
  http.HandleFunc("/debug/pprof/profile", Profile)
  http.HandleFunc("/debug/pprof/symbol", Symbol)
  http.HandleFunc("/debug/pprof/trace", Trace)
}
Copy the code

Http.handlefunc () registers the handler function with the default ServeMux:

// src/net/http/server.go
var DefaultServeMux = &defaultServeMux
var defaultServeMux ServeMux

func HandleFunc(pattern string, handler func(ResponseWriter, *Request)) {
  DefaultServeMux.HandleFunc(pattern, handler)
}
Copy the code

This DefaultServeMux is a net/ HTTP packaging-level variable with only one instance. To avoid path conflicts, it is generally not recommended to use the default DefaultServeMux when writing your own HTTP server. A NewServeMux is typically created by calling http.newservemux (), as shown in the HTTP sample code above.

Net/HTTP /pprof package registration handlers:

// src/net/http/pprof/pprof.go
func Profile(w http.ResponseWriter, r *http.Request) {
  // ...
  iferr := pprof.StartCPUProfile(w); err ! =nil {
    serveError(w, http.StatusInternalServerError,
      fmt.Sprintf("Could not enable CPU profiling: %s", err))
    return
  }
  sleep(r, time.Duration(sec)*time.Second)
  pprof.StopCPUProfile()
}
Copy the code

This function also calls the Runtime /pprof StartCPUProfile(w) method to start CPU profiling and then sleep for a period of time (the sampling interval). Finally, call pprof.stopCPUProfile () to stop adoption. The StartCPUProfile() method passes in a variable of type http.responseWriter, so the sample results are written directly back to the HTTP client.

Memory profiling is implemented with a bit of finesse. First, we found no handlers for memory profiling in the init() function. The /debug/pprof/heap path goes to the Index() function:

// src/net/http/pprof/pprof.go
func Index(w http.ResponseWriter, r *http.Request) {
  if strings.HasPrefix(r.URL.Path, "/debug/pprof/") {
    name := strings.TrimPrefix(r.URL.Path, "/debug/pprof/")
    ifname ! ="" {
      handler(name).ServeHTTP(w, r)
      return}}// ...
}
Copy the code

Handler (name).servehttp (w, r). Handler is just a new type defined based on string, which defines the ServeHTTP() method:

type handler string

func (name handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
  p := pprof.Lookup(string(name))
  // ...
  p.WriteTo(w, debug)
}
Copy the code

Cut out the other irrelevant code, leaving the above two lines. The statistics will be written to http.responseWriter.

Benchmark

Profile and MEM.profile can also be generated using Benchmark. Let’s create a new bench_test.go file in the directory of the first example:

func BenchmarkFib(b *testing.B) {
  for i := 0; i < b.N; i++ {
    fib(30)}}Copy the code

Run the go test-bench. -test.cpuprofile cpu.profile command.

You can then analyze the CPU.profile file.

conclusion

This article introduces the use of the Pprof tool, the more user-friendly library PKG/Profile, and how to use NET/HTTP /pprof to insure online applications against problems that can be diagnosed at any time. The absence of problems does not have any impact on performance.

reference

PKG/profile GitHub:github.com/pkg/profile
What you don’t know Go GitHub: github.com/darjun/you-…

I

My blog is darjun.github. IO

Welcome to follow my wechat public account [GoUpUp], learn together, progress together ~

mo4tech.com (Moment For Technology) is a global community with thousands techies from across the global hang out!Passionate technologists, be it gadget freaks, tech enthusiasts, coders, technopreneurs, or CIOs, you would find them all here.

Pprof of Go you didn’t know

Introduction to the

CPU profiling

Memory profiling

`pkg/profile`

Flame figure

net/http/pprof

`net/http/pprof`implementation

Benchmark

conclusion

reference

I

Pprof of Go you didn’t know

Introduction to the

CPU profiling

Memory profiling

pkg/profile

Flame figure

net/http/pprof

net/http/pprofimplementation

Benchmark

conclusion

reference

I

Related Posts

Rsyslog LogStash Tencent OSS rabbitMq

JAVA crawler httpClient request Jsoup parsing instance code and dependency introduction

SpringBoot Logs Quickly start simple configuration

`pkg/profile`

`net/http/pprof`implementation