How to get the profile of a running Go program

This is a creation in Article, where the information may have evolved or changed. When the Go program starts running, the runtime samples the memory allocations at a certain frequency: when the memory allocation reaches a certain value (the default is 512KB, by the [' Runtime]. Memprofilerate '] (https://golang.google.cn/pkg/runtime/#pkg-variables), the runtime will record the current size of the memory allocation, call Stack and other information into profile. And the CPU profile is called from the [' Runtime/pprof package ' pprof. Startcpuprofile () '] (https://golang.google.cn/pkg/runtime/pprof/#StartCPUProfile) begins, to [' Pprof. Stopcpuprofile () '] (https://golang.google.cn/pkg/runtime/pprof/#StopCPUProfile) ends, sampled 100 times every 1 seconds, Each time a sample is logged, all the goroutine call stacks that are currently executing are recorded, and the more times a function appears in those snapshots, the more time it takes for the function to appear. All the profile information for the Go program that runs is by calling [' Runtime/pprof '] (https://golang.google.cn/pkg/runtime/pprof/) and [' Runtime/trace '] at runtime ( https://golang.google.cn/pkg/runtime/trace/) Two packets of interface fetch, the way to call these interfaces are directly called and through the HTTP request indirect call two, below we explain the various common profile information and their acquisition , how to use. # # # 1. * * The current function call stack for all goroutine is useful: * * To see which Goroutine are currently running, the number is right, there is not a lot of Goroutine card in the same place, there is no deadlock situation, Interval Refresh page Look at the number of changes in each goroutine to understand the program health changes. * * Indirect acquisition via HTTP request: * * Introduce package [' Net/http/pprof '] (https://golang.google.cn/pkg/net/http/pprof/) in the program and use only its initialization: import _ "net/ Http/pprof "This sentence causes the [' SourceThe actual execution of the code is '] (https://github.com/golang/go/blob/master/src/net/http/pprof/pprof.go#L71): Func init () {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)} above the URL and processing functions are [' registered to the HTTP package Defaultservemux inside '] (https://github.com/golang/ go/blob/master/src/net/http/server.go#l2374), so to use these URLs you must use Defaultservemux to listen to a port: Http.listenandserve (": 9999 ", nil) here the first parameter can be either port of the native, [' When the second parameter is nil, the HTTP packet's Defaultservemux is used to listen for and process the HTTP request '] (https://golang.google.cn/pkg/net/ http/#ListenAndServe), or when a custom Servemux is already in the program, you can pprof the handler [' Register to a custom Servemux '] like the above init function (https:// golang.google.cn/pkg/net/http/#ServeMux. Handlefunc). After adding the above code in the program, we can access the following HTTP address through the browser or wget to view the Goroutine information: http://localhost:9999/debug/pprof/goroutine?debug= 1 or go to the index page to see more items: http://localhost:9999/debug/pprof** Direct access: * * Not commonly used, you can view [' Source code '] (https://github.com/golang/go/blob/ master/src/net/http/pprof/pprof.go#l224) # # 2. * * CPU profile**** useful for a period of time: * * To see the CPU-consuming hotspot function, can reduce the number of calls, can avoid repeated calculations. * * Indirect acquisition via HTTP request: * * With the 1th inside get goroutine information, in the program introduced package [' Net/http/pprof '] (https://golang.google.cn/pkg/net/http/pprof/) and use only its initialization: import _ "Net/http/pprof" and then use Defaultservemux to listen to a port: Http.listenandserve (": 9999", nil) after adding the above code in the program, At runtime we can access the following HTTP address via the browser or wget to get the CPU profile:http://localhost:9999/debug/pprof/profile?seconds= 30 This HTTP request will wait for the number of seconds specified by the seconds parameter, during which the read request returns the binary format content, we save the returned content as a file, assuming that the name is Cpu.prof, this file contains the program received the request seconds seconds to run CPU-intensive situation. Next we look at the Cpu.prof:go tool by typing [' Go Tool pprof '] (https://golang.google.cn/cmd/pprof/) at the command line Pprof Cpu.prof This command will enter the command line interaction, we can enter a number of sub-commands to view the relevant information, the most common sub-command is: Top n This subcommand lists the most time-consuming n function calls, Entering cum or flat before entering the top command allows you to sort the list of top lists by cum or flat columns, flat is time consuming for a single function itself (excluding other functions called in the function), and cum is the total time-consuming function from entry to exit. If you want to see where a function is time-consuming, you can use the LIST subcommand to view: List func_name_in_top_list The command displays time-consuming code and line numbers, and if the source information is not found, you can do so in the ' Go Tool pprof ' The binary file that is stored in the local profile is specified later, and the binary file is compiled under the same platform as the program that generated the profile. For example, when running a go program on a remote profile Linux machine on a local Windows machine, ensure that the locally specified bInary is compiled on a Linux machine: Go tool pprof mybinarypath Prof_file_from_remote_hostgo tool pprof Mybinarypath https://myremotehost /debug/pprof/profile in order to see the call relationship of hot function more intuitively, we use SVG and Web subcommands more: svg > The Xxx.svgwebsvg command generates an SVG file with the specified file name, and the Web command generates an SVG file and opens the file with a browser, making sure that the Graphviz (brew install Graphviz is installed before the Web command is executed, and then brew List Graphviz View the installation location and add the bin directory of the installation location to path, and make sure that the default opener for the SVG file is the browser. This SVG file opened in the browser via the Web subcommand is very useful and can clearly see the call graph of the time consuming function. The above is to obtain the Cpu.prof file through the browser or wget, and then use the [' Go Tool pprof '] (https://golang.google.cn/cmd/pprof/) command to parse the file, the more direct way is to enter directly on the command line: Go Tool pprof http://localhost:9999/debug/pprof/profile?seconds=30 This command waits seconds the specified number of seconds, during which the read request returns the binary format content and writes the temporary file, and then uses the [' Go Tool pprof '] (https://golang.google.cn/cmd/pprof/) To view this file and enter the command line interaction, the process and save to the custom file is the same. * * Direct Access: * * The way the above is indirectly obtained through HTTP requests is actually ultimately the [' URL's handler called the Runtime/pprof Packet's interface '] (https://github.com/golang/go/blob/master/ src/net/http/pprof/pprof.go#l105): Import "Runtime/pprof" Func profile (w http. Responsewriter, R *http. Request) {sec, _: = StrConv. parseint (R.formvalue ("seconds"), ten, max) if sec = = 0 {sec = 30}if durationexceedswritetimeout (r, float64 (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 Startcpuprofile would 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 headers 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 ()} It is very convenient to use the above method when viewing the service on the line in different scenarios, the operation of different time periods, but in the development or optimization, we will change some of the code, and then we want to compare with before changes to see whether performance is improved, At this point we need to determine the fixed start and end positions in the code to Profie, such as a function from the entry to the exit, or a test program from start to exit, it can not be like the above at some point in time to emitHTTP request, and then roughly wait for a period of time, we need to call in the program [' Runtime/pprof '] (https://golang.google.cn/pkg/runtime/pprof/) package interface: Import " Runtime/pprof "var cpuprofile = flag. String ("Cpuprofile", "", "Write CPU profile ' file '") Func main () {flag. Parse () if *cpuprofile! = "" {f, err: = OS. Create (*cpuprofile) if err! = Nil {log. Fatal ("Could not create CPU profile:", err)} If err: = Pprof. Startcpuprofile (f); Err! = Nil {log. Fatal ("Could not start CPU profile:", err)} defer pprof. Stopcpuprofile ()}//... rest of the program ...} The period of the above Code Cup profile is from the start of the program to exit, the content of the profile is saved to the file specified by the Cpuprofile parameter, and the previous Cpu.prof obtained via HTTP request, we pass [' Go Tool pprof '] (https ://golang.google.cn/cmd/pprof/) to view this file. In addition to the code that adds the profile in the program as above, the ' Go Test ' command comes with the profile function and can specify [' profile-related flag '] when running the ' Go Test ' command (https://golang.google.cn/cmd /go/#hdr-description_of_testing_flags), for example, the following command runs the test case in the current directory and writes the CPU and heap profile to the specified file, and then we can use [' Go Tool pprof '] ( https://golang.google.cn/cmd/pprof/) To view these profiles: Go Test-cpuprofile cpu.prof-memprofile mem.prof-bench. # 3. * * The current memory usage of the program is useful: * * Check the current memory consumption, whether there is not timely release of memory, such as the growing slice or map; View memory allocation history statistics, whether there are objects allocated too frequently, can be reused allocated objects. * * Indirect acquisition via HTTP request: * * With the 1th inside get goroutine information, in the program introduced package [' Net/http/pprof '] (https://golang.google.cn/pkg/net/http/pprof/) and use only its initialization: import _ "Net/http/pprof" and then use Defaultservemux to listen to a port: Http.listenandserve (": 9999", nil) after adding the above code in the program, Runtime we can access the following HTTP address through the browser or wget to get the heap Profile:http://localhost:9999/debug/pprof/heap this HTTP request will immediately return the contents of the binary format, We save the returned content as a file, assuming that it is named Mem.prof, which contains the memory that the program is currently using. Next we look at the Mem.prof:go tool by typing [' Go Tool pprof '] (https://golang.google.cn/cmd/pprof/) at the command line Pprof Mem.prof This sentence is the memory that has not been freed after the allocation has been in-use: it is either in use or is not actually released in time, which is helpful for checking for memory leaks. We can also add several options to the command above:-inuse_space display in-use memory size, default-inuse_objects display In-use object counts-alloc_ Space Display allocated memory size-alloc_objects display allocated object counts the default is to use '-inuse_space ' without any of the above options. If we want to see the program from boot to now all allocated memory (contains already released), you can specify '-alloc_space ': Go tool pprof-alloc_space Mem.prof through this command we can view the statistics of the distribution history, know where to allocate memory too frequently, whether it can be reused. Above theThese commands go into the command line interaction, and we can enter many subcommands to see the information, and the most common subcommands are: Top n This subcommand lists the functions of the code that allocates the most memory at N. Enter cum or flat before entering the top command to sort the list of top lists by cum or flat columns, flat is the memory footprint of the individual function itself (excluding other functions called by the function), and cum is the total function occupancy. If you want to see where a function is specifically allocated memory, you can use the LIST subcommand to view: List func_name_in_top_list The command displays the code and line number of the allocated memory. To more intuitively see the call relationship of the Hotspot function, we are more using the WEB subcommand: web This command generates an SVG file and opens it with a browser to get the Mem.prof file via a browser or wget, then use [' Go Tool pprof '] ( https://golang.google.cn/cmd/pprof/) command to view this file, the more straightforward way is to enter directly on the command line: Go tool pprof http://localhost:9999/debug/pprof/ Heap This command writes the return of HTTP to the temporary file, and then uses [' Go Tool pprof '] (https://golang.google.cn/cmd/pprof/) to view the file and enter the command line interaction, which is the same as saving it to a custom file. * * Direct Access: * * import "runtime/pprof" ... f, err: = OS. Create (*memprofile) if err! = Nil {log. Fatal ("Could not create memory profile:", err)} runtime. GC ()//Get up-to-date statistics if err: = Pprof. Writeheapprofile (f); Err! = Nil {log. Fatal ("Could not write memory profile:", Err)} f.close () The above code can be executed anywhere in the program, the contents of the output file is the current memory usage of the program, As in the previous mem.prof with HTTP requests, we looked at the file through [' Go Tool pprof '] (https://golang.google.cn/cmd/pprof/). #### 4. * * The scheduling and execution of all goroutine during a period of time * * * * * * USE: * * The previous 3 points are useful for ensuring that the program works, but if we want to improve the performance of the program, such as how to make full use of the CPU in the case of a large network IO or database IO, At this point, the front 3 is not enough. We need to understand how the various goroutine are scheduled, how they are executed synchronously, the network waits, the synchronous lock waits, and where the wait for the system call takes place, where the CPU idle is wasted in these waiting places, and the information is in the trace. * * Indirect acquisition via HTTP request: * * With the 1th inside get goroutine information, in the program introduced package [' Net/http/pprof '] (https://golang.google.cn/pkg/net/http/pprof/) and use only its initialization: import _ "Net/http/pprof" and then use Defaultservemux to listen to a port: Http.listenandserve (": 9999", nil) after adding the above code in the program, At runtime we can access the following HTTP address via the browser or wget to get trace information: http://localhost:9999/debug/pprof/trace?seconds=10 This HTTP request waits seconds seconds, During this time the read request returns the binary format content, we save the returned content as a file, assuming named Trace.out, this file contains the trace information during this period. Next we look at the Trace.out:go tool trace by typing [' Go tool Trace '] (https://golang.google.cn/cmd/trace/) at the command line Trace.out This command opens a Web service and then open the browser to run a web app that shows the following Title:view tracegoroutine analysisnetwork blocking Profilesynchronization blocking Profilesyscall Blocking Profilescheduler latency profile Click on each title to access the details, where "view Trace "is a UI interface that allows you to see the order in which each goroutine is executed on each OS thread by timeline, and the detailed usage of this web app can beTo refer to [' This article '] (https://blog.gopheracademy.com/advent-2017/go-execution-tracer/). * * Direct Access: * * The way the above is indirectly obtained via HTTP requests is ultimately the [' URL's handler called the Runtime/trace Packet's interface '] (https://github.com/golang/go/blob/master/ src/net/http/pprof/pprof.go#l139): Import "Runtime/trace" func Trace (w http. Responsewriter, R *http. Request) {sec, err: = StrConv. Parsefloat (R.formvalue ("seconds"), if sec <= 0 | | Err! = Nil {sec = 1}if Durationexceedswritetimeout (r, 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 trace. Start would work,//because if it does it starts Writing.w.header (). Set ("Content-type", "Application/octet-stream") If err: = Trace. Start (w); Err! = Nil {//trace. Start failed, so no writes yet.//the Can change 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 tracing:%s\n", Err) Return}sleep (W, time. Duration (Sec*float64 (time. Second)) trace. Stop ()} We can call the interface of [' Runtime/trace '] (https://golang.google.cn/pkg/runtime/trace/) package directly inside the program: import "Runtime/trace" var traceprofile = flag. String ("Traceprofile", "", "Write trace profile ' file '") Func main () {flag. Parse () if *traceprofile! = "" {f, err: = OS. Create (*traceprofile) if err! = Nil {log. Fatal ("Could not create trace profile:", err)} If err: = Trace. Start (f); Err! = Nil {log. Fatal ("Could not start trace profile:", err)} defer trace. Stop ()}//... rest of the program ...} The previous code trace profile cycle is from the program startup to exit, the content of the profiles is saved to the file specified by the Traceprofile parameter, and the previous Trace.out obtained via HTTP request, we pass [' Go Tool Trace '] ( https://golang.google.cn/cmd/trace/) to view this file. # # # # * * Also refer to the following article for further information: **[golang Memory analysis/Dynamic tracking] (https://lrita.github.io/2017/05/26/golang-memory-pprof/) [Profiling Go Programs with Pprof] (https://jvns.ca/blog/2017/09/24/profiling-go-with-pprof/) [Custom pprof profiles] (https://rakyll.org/custom-profiles/) [Mutex profile] (https://rakyll.org/ mutexprofile/) [Pprof user Interface] (https://rakyll.org/pprof-ui/) [Go Execution Tracer] (https:// blog.gopheracademy.com/advent-2017/go-execution-tracer/) [Go tool trace] (https://making.pusher.com/go-tool-trace/ ) [An Introduction to go tool trace] (https://about.sourcegraph.com/go/an-introduction-to-go-tool-trace-rhys-hiltner/ ) [Go execution Tracer (design doc)] (https://docs.google.com/document/d/ 1FP5APQZBGR7AHCCGFO-YOVHK4YZRNIDNF9RYBNGBC14/EDIT#HEADING=H.AYZNTOSPGLB3) [Go, the Unwritten parts] (https:// rakyll.org/archive/) 636 reads