This is a creation in Article, where the information may have evolved or changed. # # Overview Have you ever wondered how the Go runtime Dispatches goroutine? Have you ever studied why concurrency is sometimes added but performance is not improved? Go provides an execution tracker that can help you diagnose performance issues such as latency, competition, or low concurrency, and solve the previous questions. Go from the 1.5 version of the implementation of the Tracker is a tool, the principle is: Listen to the Go runtime of some specific events, such as: 1. The creation, start, and end of the goroutine. 2. Blocking/Unlocking some events of goroutine (System call, channel, lock) 3. Network I/O-related event 4. System call 5. The garbage collection tracker collects this information exactly, without any aggregation or sampling operations. For high-load applications, it is possible to generate a larger file that can be parsed by the Go Tool Trace command later. Before executing the tracker, Go has provided the PPROF parser to analyze the memory and CPU, so the question is, why add an official tool chain? The CPU profiler can clearly see which function is the most CPU-intensive, but you can't know for sure what causes goroutine not to run, or how the bottom layer dispatches goroutine on the operating system thread. And these are exactly what trackers are good at. Tracker's [design document] (HTTPS://DOCS.GOOGLE.COM/DOCUMENT/U/1/D/1FP5APQZBGR7AHCCGFO-YOVHK4YZRNIDNF9RYBNGBC14/PUB) Explains in detail the reason for the introduction of the tracker and how it works. # # Tracker "Journey" starts with a simple "Hello world" example. The ' Runtime/trace ' package is used to control the start/stop write tracking data, and the data is written to the standard error output. "' Gopackage mainimport (" OS "" Runtime/trace ") func main () {trace. Start (OS. STDERR) defer trace. Stop ()//Create new channel of type intch: = make (chan int)//start new anonymous Goroutinego func () {//Send to Channe LCH <-} ()//read from channel<-CH} "In this example, a non-buffered channel is created, and a goroutine is initialized to send the number 42 via the channel. The main goroutine will block until the other goroutine sends a value over the channel. By running the ' Go run main.go 2> trace.out ' command to output the trace information to the ' trace.out ' file, you can read the file using the ' Go Tool trace trace.out ' command. > Go 1.8, before you want to analyze the two things that trace data requires to provide executable binaries and tracked data, and for a program compiled after go 1.8, executing ' Go tool trace ' only uses the data that provides tracking, which contains everything. Once the command has been run, a browser window opens, displaying several options. Each option opens with a different view of the tracker, which contains different information about the execution of the program. [Trace] (https://raw.githubusercontent.com/studygolang/gctt-images/master/execution-tracer/trace-opts.png) 1. View trace (viewing tracking information) provides one of the most complex and powerful interactive visual interfaces to display the timeline of the entire program execution. For example, the interface shows what is running on each virtual processor and what is blocked waiting to be run again. This visual interface is described in more detail later in this article. Note that this interface only supports Chrome browser. 2. Goroutine Analysis (goroutine) shows the number of goroutine per type during the entire execution. Select a type to see information for each goroutine of that type. For example, how long each goroutine tries to acquire a mutex, or attempts to read data from the network, or how long it takes to wait for the dispatch to take place, etc. 3. Network/sync/syscall Blocking profile (Network/sync/system call blocking analysis) This piece contains graphs that show how long Goroutine has blocked each of these resources. Somewhat similar to the data provided by the PPROF memory/CPU parser. is a tool to analyze the lock competition. 4. The Scheduler Latency Profiler (Dispatch delay Analyzer) provides timing statistics for scheduling-level information, which shows which block is the most time-consuming of the scheduling process. # # View tracking information click "View trace "link, out of the window to show the entire program execution. > Press "? "Key, will pop up to explore the tracking information of some shortcut keys to help information marked a few important parts, are described below:! [View Trace] (https://raw.githubusercontent.com/studygolang/gctt-images/master/execution-tracer/view-trace.png) 1. Timeline (timeline) shows the time of execution, and the time unit can be adjusted by the navigation bar. Users can manipulate the timeline with keyboard shortcuts (WASD keys, just like in the game). 2. Heap shows memory allocations during execution and is useful for finding memory leaks and how much memory each run of garbage collection can release. 3. Goroutines shows how many groroutine are running, and how many of them are operational at each point in time (waiting to be dispatched). An excessive number of goroutine can mean scheduling competition, for example, when a program creates too many goroutine that can cause the scheduler to be busy. 4. OS Threads (OS thread) shows how many operating system threads are occupied and how many threads are blocked by system calls. 5. Virtual processors displays a virtual processor per line. The number of virtual processes is controlled by the GOMAXPROCS environment variable (default is the number of machine cores). 6.Goroutines and Events (Goroutine and event) show the contents of Goroutine running on each virtual processor/where to run. The line connecting the Goroutine represents the event. In the example diagram, we can see that goroutine "G1 Runtime.main" produces two different goroutine:g6 and G5 (the former is responsible for collecting tracking information, which is generated using the "Go" keyword). The second row of each virtual processor may display additional events, such as system calls and run-time events. It also includes some of the work that Goroutine does for the runtime (for example, to assist with garbage collection). Displays the information you get when you select a goroutine. [View-goroutine.png] (Https://raw.githubusercontent.com/studygolang/gctt-images/master/execution-tracer/view-goroutine.png) includes the following information: * Its name (title) * FROMStart time (Start) * Duration (Wall Duration) * Beginning Stack track * End time Stack track * The event generated by the goroutine we can see: The goroutine generates two events: Generate goroutine for tracking and in Chan Nel start sending the number 42 on the Goroutine.! [View-event.png] (https://raw.githubusercontent.com/studygolang/gctt-images/master/execution-tracer/view-event.png) By clicking on a particular event (a line in the diagram or by selecting an event after the point Goroutine), we can see: * The stack track at the start of the event * The duration of the event * The time included goroutine can be navigated to by clicking on these goroutine to their tracking data. # # Block Analysis The view of network/synchronization/system call blocking analysis can also be obtained by tracing. The image view shown by the blocking analysis is similar to the view of the Pprof memory/cpu analysis. The difference is that instead of showing how much memory each function allocates, it shows how long each goroutine is blocked on a particular resource. Displays the "Synchronous blocking analysis" for our sample code. [Blocking-profile.png] (https://raw.githubusercontent.com/studygolang/gctt-images/master/execution-tracer/blocking-profile.png) The diagram illustrates the main Goroutine takes 12.08 microseconds to receive data blocking time from the channel. This type of graph is useful for multiple goroutine competing resource locks and finding lock contention conditions. # # Three ways to collect tracking data: 1. Apply ' Runtime/trace ' package contains call ' trace. Start ' and ' trace. Stop ', which has been described in the "hello,tracing" example. 2. Using the ' trace=<file> ' test flag This method is useful for collecting tracking information for the code to be tested or for the test itself. 3. Using the Debug/pprof/trace processor is the best way to collect tracking data from a running web app. # # Track a web app to be able to collect tracking information for a running web app written by Go, you need to add '/debug/pprof/trace ' processor. The following sample code illustrates the ' HTTP. Defaultservermux ' How to do this: by simply introducing the ' net/http/pprof ' package. "' Gopackage mainimport (" Net/http "_" Net/http/pprof ") func Main () {http. Handle ("/hello", http. Handlerfunc (Hellohandler)) http. Listenandserve ("localhost:8181", http. Defaultservemux)}func Hellohandler (w http. Responsewriter, R *http. Request) {W.write ([]byte ("" Hello world! ")} "' Collect the tracking information, we need to send the request to the endpoint, for example, ' Curl localhost:8181/debug/pprof/trace?seconds=10 > Trace.out '. The request is blocked for 10 seconds and the tracking information is written to the ' trace.out ' file. The resulting tracking information can be viewed as before: through ' Go tool trace trace.out '. > Security Reminder: Note that it is not recommended to expose the Pprof processor to the Internet. It is recommended that these endpoints be exposed to a different HTTP. Server, the HTTP. The Server binds to the loopback port. [This blog] (http://mmcloughlin.com/posts/your-pprof-is-showing) discusses the risks that exist while providing sample code for how to properly expose the Pprof processor. Before collecting the tracking data, add some load to the service, using ' wrk ': ' $ wrk-c 100-t 10-d 60s Http://localhost:8181/hello ', the command will initiate the request in 60 seconds using 100 connections through 10 threads. While running ' wrk ', we can collect 5 s of tracking data: ' Curl localhost:8181/debug/pprof/trace?seconds=5 > Trace.out '. This command generates a 5 MB file on my 4 CPU machine (the file size increases rapidly with the load). Similarly, through the Go tool trThe ACE command opens the tracking data: ' Go tool trace trace.out '. Because the tool is analyzing the entire file, it takes longer than the precedent. When finished, the page looks a little bit different: "View Trace (0s-2.546634537s) view Trace (2.546634537s-5.00392737s) goroutine analysisnetwork Blocking profilesynchronization blocking Profilesyscall blocking Profilescheduler latency profile "in order to ensure that the browser can render all information, The tool has divided the tracking data into two contiguous sections. A higher-load application or longer tracking data may trigger the tool to split it into more parts. Click on "View Trace (2.546634537s-5.00392737s)" And we can see a lot of things:! [Trace-web.png] (https://raw.githubusercontent.com/studygolang/gctt-images/master/execution-tracer/trace-web.png) The display 1169 MS ~ A GC operation that ends after 1170 Ms begins, 1174 Ms. During this time, an operating system thread (PROC 1) started a goroutine specifically for GC, other Goroutine auxiliary GC operations (shown under Goroutine line, labeled Mark ASSIST), at the end of the intercept, we can see most of the allocated memory Has been released by the GC. Another particularly useful message is the number of goroutine in the "Runnable" state (13 when selected), which means we need more CPUs to handle the load if the value becomes larger over time. # # Summary Tracker is a powerful tool for debugging concurrency issues such as lock contention and logical contention. It does not solve everything: it is not the best tool to track which code consumes the most CPU time and memory. Use ' Go tool pprof ' is more suitable for this scenario. This tool is useful for understanding what each goroutine does when the program is not running and for viewing the program behavior by time. There is some overhead involved in collecting tracking data, and it is possible to generate large amounts of data for viewing. Unfortunately, the official documentation lacks some experimentation to let us experiment and understand the information displayed by the tracker. This is also an official document, community(such as blogs) to contribute [opportunities] (https://github.com/golang/go/issues/16526). André is a senior software engineer [globo.com] (http://www.globo.com/), developing the [Tsuru] (https://tsuru.io/) project. Twitter please @andresantostc, or Web message https://andrestc.com. # # reference 1. [Go Execution Tracer (design doc)] (https://docs.google.com/document/u/1/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub) 2. [Using The Go tracer to speed fractal rendering] (https://medium.com/justforfunc/ using-the-go-execution-tracer-to-speed-up-fractal-rendering-c06bb3760507) 3. [Go Tool Trace] (https://making.pusher.com/go-tool-trace/) 4. [Your Pprof is showing] (http://mmcloughlin.com/posts/your-pprof-is-showing)
via:https://blog.gopheracademy.com/advent-2017/go-execution-tracer/
Author: Andrécarvalho Translator: Dongfengkuayue proofreading: polaris1119
This article by GCTT original compilation, go language Chinese network honor launches
This article was originally translated by GCTT and the Go Language Chinese network. Also want to join the ranks of translators, for open source to do some of their own contribution? Welcome to join Gctt!
Translation work and translations are published only for the purpose of learning and communication, translation work in accordance with the provisions of the CC-BY-NC-SA agreement, if our work has violated your interests, please contact us promptly.
Welcome to the CC-BY-NC-SA agreement, please mark and keep the original/translation link and author/translator information in the text.
The article only represents the author's knowledge and views, if there are different points of view, please line up downstairs to spit groove
1062 reads ∙1 likes
