github.com/megatontech/mynoteforgo@v0.0.0-20200507084910-5d0c6ea6e890/源码/cmd/trace/pprof.go (about) 1 // Copyright 2014 The Go Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style 3 // license that can be found in the LICENSE file. 4 5 // Serving of pprof-like profiles. 6 7 package main 8 9 import ( 10 "bufio" 11 "fmt" 12 "internal/trace" 13 "io" 14 "io/ioutil" 15 "net/http" 16 "os" 17 "os/exec" 18 "path/filepath" 19 "runtime" 20 "sort" 21 "strconv" 22 "time" 23 24 "github.com/google/pprof/profile" 25 ) 26 27 func goCmd() string { 28 var exeSuffix string 29 if runtime.GOOS == "windows" { 30 exeSuffix = ".exe" 31 } 32 path := filepath.Join(runtime.GOROOT(), "bin", "go"+exeSuffix) 33 if _, err := os.Stat(path); err == nil { 34 return path 35 } 36 return "go" 37 } 38 39 func init() { 40 http.HandleFunc("/io", serveSVGProfile(pprofByGoroutine(computePprofIO))) 41 http.HandleFunc("/block", serveSVGProfile(pprofByGoroutine(computePprofBlock))) 42 http.HandleFunc("/syscall", serveSVGProfile(pprofByGoroutine(computePprofSyscall))) 43 http.HandleFunc("/sched", serveSVGProfile(pprofByGoroutine(computePprofSched))) 44 45 http.HandleFunc("/regionio", serveSVGProfile(pprofByRegion(computePprofIO))) 46 http.HandleFunc("/regionblock", serveSVGProfile(pprofByRegion(computePprofBlock))) 47 http.HandleFunc("/regionsyscall", serveSVGProfile(pprofByRegion(computePprofSyscall))) 48 http.HandleFunc("/regionsched", serveSVGProfile(pprofByRegion(computePprofSched))) 49 } 50 51 // Record represents one entry in pprof-like profiles. 52 type Record struct { 53 stk []*trace.Frame 54 n uint64 55 time int64 56 } 57 58 // interval represents a time interval in the trace. 59 type interval struct { 60 begin, end int64 // nanoseconds. 61 } 62 63 func pprofByGoroutine(compute func(io.Writer, map[uint64][]interval, []*trace.Event) error) func(w io.Writer, r *http.Request) error { 64 return func(w io.Writer, r *http.Request) error { 65 id := r.FormValue("id") 66 events, err := parseEvents() 67 if err != nil { 68 return err 69 } 70 gToIntervals, err := pprofMatchingGoroutines(id, events) 71 if err != nil { 72 return err 73 } 74 return compute(w, gToIntervals, events) 75 } 76 } 77 78 func pprofByRegion(compute func(io.Writer, map[uint64][]interval, []*trace.Event) error) func(w io.Writer, r *http.Request) error { 79 return func(w io.Writer, r *http.Request) error { 80 filter, err := newRegionFilter(r) 81 if err != nil { 82 return err 83 } 84 gToIntervals, err := pprofMatchingRegions(filter) 85 if err != nil { 86 return err 87 } 88 events, _ := parseEvents() 89 90 return compute(w, gToIntervals, events) 91 } 92 } 93 94 // pprofMatchingGoroutines parses the goroutine type id string (i.e. pc) 95 // and returns the ids of goroutines of the matching type and its interval. 96 // If the id string is empty, returns nil without an error. 97 func pprofMatchingGoroutines(id string, events []*trace.Event) (map[uint64][]interval, error) { 98 if id == "" { 99 return nil, nil 100 } 101 pc, err := strconv.ParseUint(id, 10, 64) // id is string 102 if err != nil { 103 return nil, fmt.Errorf("invalid goroutine type: %v", id) 104 } 105 analyzeGoroutines(events) 106 var res map[uint64][]interval 107 for _, g := range gs { 108 if g.PC != pc { 109 continue 110 } 111 if res == nil { 112 res = make(map[uint64][]interval) 113 } 114 endTime := g.EndTime 115 if g.EndTime == 0 { 116 endTime = lastTimestamp() // the trace doesn't include the goroutine end event. Use the trace end time. 117 } 118 res[g.ID] = []interval{{begin: g.StartTime, end: endTime}} 119 } 120 if len(res) == 0 && id != "" { 121 return nil, fmt.Errorf("failed to find matching goroutines for id: %s", id) 122 } 123 return res, nil 124 } 125 126 // pprofMatchingRegions returns the time intervals of matching regions 127 // grouped by the goroutine id. If the filter is nil, returns nil without an error. 128 func pprofMatchingRegions(filter *regionFilter) (map[uint64][]interval, error) { 129 res, err := analyzeAnnotations() 130 if err != nil { 131 return nil, err 132 } 133 if filter == nil { 134 return nil, nil 135 } 136 137 gToIntervals := make(map[uint64][]interval) 138 for id, regions := range res.regions { 139 for _, s := range regions { 140 if filter.match(id, s) { 141 gToIntervals[s.G] = append(gToIntervals[s.G], interval{begin: s.firstTimestamp(), end: s.lastTimestamp()}) 142 } 143 } 144 } 145 146 for g, intervals := range gToIntervals { 147 // in order to remove nested regions and 148 // consider only the outermost regions, 149 // first, we sort based on the start time 150 // and then scan through to select only the outermost regions. 151 sort.Slice(intervals, func(i, j int) bool { 152 x := intervals[i].begin 153 y := intervals[j].begin 154 if x == y { 155 return intervals[i].end < intervals[j].end 156 } 157 return x < y 158 }) 159 var lastTimestamp int64 160 var n int 161 // select only the outermost regions. 162 for _, i := range intervals { 163 if lastTimestamp <= i.begin { 164 intervals[n] = i // new non-overlapping region starts. 165 lastTimestamp = i.end 166 n++ 167 } // otherwise, skip because this region overlaps with a previous region. 168 } 169 gToIntervals[g] = intervals[:n] 170 } 171 return gToIntervals, nil 172 } 173 174 // computePprofIO generates IO pprof-like profile (time spent in IO wait, currently only network blocking event). 175 func computePprofIO(w io.Writer, gToIntervals map[uint64][]interval, events []*trace.Event) error { 176 prof := make(map[uint64]Record) 177 for _, ev := range events { 178 if ev.Type != trace.EvGoBlockNet || ev.Link == nil || ev.StkID == 0 || len(ev.Stk) == 0 { 179 continue 180 } 181 overlapping := pprofOverlappingDuration(gToIntervals, ev) 182 if overlapping > 0 { 183 rec := prof[ev.StkID] 184 rec.stk = ev.Stk 185 rec.n++ 186 rec.time += overlapping.Nanoseconds() 187 prof[ev.StkID] = rec 188 } 189 } 190 return buildProfile(prof).Write(w) 191 } 192 193 // computePprofBlock generates blocking pprof-like profile (time spent blocked on synchronization primitives). 194 func computePprofBlock(w io.Writer, gToIntervals map[uint64][]interval, events []*trace.Event) error { 195 prof := make(map[uint64]Record) 196 for _, ev := range events { 197 switch ev.Type { 198 case trace.EvGoBlockSend, trace.EvGoBlockRecv, trace.EvGoBlockSelect, 199 trace.EvGoBlockSync, trace.EvGoBlockCond, trace.EvGoBlockGC: 200 // TODO(hyangah): figure out why EvGoBlockGC should be here. 201 // EvGoBlockGC indicates the goroutine blocks on GC assist, not 202 // on synchronization primitives. 203 default: 204 continue 205 } 206 if ev.Link == nil || ev.StkID == 0 || len(ev.Stk) == 0 { 207 continue 208 } 209 overlapping := pprofOverlappingDuration(gToIntervals, ev) 210 if overlapping > 0 { 211 rec := prof[ev.StkID] 212 rec.stk = ev.Stk 213 rec.n++ 214 rec.time += overlapping.Nanoseconds() 215 prof[ev.StkID] = rec 216 } 217 } 218 return buildProfile(prof).Write(w) 219 } 220 221 // computePprofSyscall generates syscall pprof-like profile (time spent blocked in syscalls). 222 func computePprofSyscall(w io.Writer, gToIntervals map[uint64][]interval, events []*trace.Event) error { 223 prof := make(map[uint64]Record) 224 for _, ev := range events { 225 if ev.Type != trace.EvGoSysCall || ev.Link == nil || ev.StkID == 0 || len(ev.Stk) == 0 { 226 continue 227 } 228 overlapping := pprofOverlappingDuration(gToIntervals, ev) 229 if overlapping > 0 { 230 rec := prof[ev.StkID] 231 rec.stk = ev.Stk 232 rec.n++ 233 rec.time += overlapping.Nanoseconds() 234 prof[ev.StkID] = rec 235 } 236 } 237 return buildProfile(prof).Write(w) 238 } 239 240 // computePprofSched generates scheduler latency pprof-like profile 241 // (time between a goroutine become runnable and actually scheduled for execution). 242 func computePprofSched(w io.Writer, gToIntervals map[uint64][]interval, events []*trace.Event) error { 243 prof := make(map[uint64]Record) 244 for _, ev := range events { 245 if (ev.Type != trace.EvGoUnblock && ev.Type != trace.EvGoCreate) || 246 ev.Link == nil || ev.StkID == 0 || len(ev.Stk) == 0 { 247 continue 248 } 249 overlapping := pprofOverlappingDuration(gToIntervals, ev) 250 if overlapping > 0 { 251 rec := prof[ev.StkID] 252 rec.stk = ev.Stk 253 rec.n++ 254 rec.time += overlapping.Nanoseconds() 255 prof[ev.StkID] = rec 256 } 257 } 258 return buildProfile(prof).Write(w) 259 } 260 261 // pprofOverlappingDuration returns the overlapping duration between 262 // the time intervals in gToIntervals and the specified event. 263 // If gToIntervals is nil, this simply returns the event's duration. 264 func pprofOverlappingDuration(gToIntervals map[uint64][]interval, ev *trace.Event) time.Duration { 265 if gToIntervals == nil { // No filtering. 266 return time.Duration(ev.Link.Ts-ev.Ts) * time.Nanosecond 267 } 268 intervals := gToIntervals[ev.G] 269 if len(intervals) == 0 { 270 return 0 271 } 272 273 var overlapping time.Duration 274 for _, i := range intervals { 275 if o := overlappingDuration(i.begin, i.end, ev.Ts, ev.Link.Ts); o > 0 { 276 overlapping += o 277 } 278 } 279 return overlapping 280 } 281 282 // serveSVGProfile serves pprof-like profile generated by prof as svg. 283 func serveSVGProfile(prof func(w io.Writer, r *http.Request) error) http.HandlerFunc { 284 return func(w http.ResponseWriter, r *http.Request) { 285 286 if r.FormValue("raw") != "" { 287 w.Header().Set("Content-Type", "application/octet-stream") 288 if err := prof(w, r); err != nil { 289 w.Header().Set("Content-Type", "text/plain; charset=utf-8") 290 w.Header().Set("X-Go-Pprof", "1") 291 http.Error(w, fmt.Sprintf("failed to get profile: %v", err), http.StatusInternalServerError) 292 return 293 } 294 return 295 } 296 297 blockf, err := ioutil.TempFile("", "block") 298 if err != nil { 299 http.Error(w, fmt.Sprintf("failed to create temp file: %v", err), http.StatusInternalServerError) 300 return 301 } 302 defer func() { 303 blockf.Close() 304 os.Remove(blockf.Name()) 305 }() 306 blockb := bufio.NewWriter(blockf) 307 if err := prof(blockb, r); err != nil { 308 http.Error(w, fmt.Sprintf("failed to generate profile: %v", err), http.StatusInternalServerError) 309 return 310 } 311 if err := blockb.Flush(); err != nil { 312 http.Error(w, fmt.Sprintf("failed to flush temp file: %v", err), http.StatusInternalServerError) 313 return 314 } 315 if err := blockf.Close(); err != nil { 316 http.Error(w, fmt.Sprintf("failed to close temp file: %v", err), http.StatusInternalServerError) 317 return 318 } 319 svgFilename := blockf.Name() + ".svg" 320 if output, err := exec.Command(goCmd(), "tool", "pprof", "-svg", "-output", svgFilename, blockf.Name()).CombinedOutput(); err != nil { 321 http.Error(w, fmt.Sprintf("failed to execute go tool pprof: %v\n%s", err, output), http.StatusInternalServerError) 322 return 323 } 324 defer os.Remove(svgFilename) 325 w.Header().Set("Content-Type", "image/svg+xml") 326 http.ServeFile(w, r, svgFilename) 327 } 328 } 329 330 func buildProfile(prof map[uint64]Record) *profile.Profile { 331 p := &profile.Profile{ 332 PeriodType: &profile.ValueType{Type: "trace", Unit: "count"}, 333 Period: 1, 334 SampleType: []*profile.ValueType{ 335 {Type: "contentions", Unit: "count"}, 336 {Type: "delay", Unit: "nanoseconds"}, 337 }, 338 } 339 locs := make(map[uint64]*profile.Location) 340 funcs := make(map[string]*profile.Function) 341 for _, rec := range prof { 342 var sloc []*profile.Location 343 for _, frame := range rec.stk { 344 loc := locs[frame.PC] 345 if loc == nil { 346 fn := funcs[frame.File+frame.Fn] 347 if fn == nil { 348 fn = &profile.Function{ 349 ID: uint64(len(p.Function) + 1), 350 Name: frame.Fn, 351 SystemName: frame.Fn, 352 Filename: frame.File, 353 } 354 p.Function = append(p.Function, fn) 355 funcs[frame.File+frame.Fn] = fn 356 } 357 loc = &profile.Location{ 358 ID: uint64(len(p.Location) + 1), 359 Address: frame.PC, 360 Line: []profile.Line{ 361 profile.Line{ 362 Function: fn, 363 Line: int64(frame.Line), 364 }, 365 }, 366 } 367 p.Location = append(p.Location, loc) 368 locs[frame.PC] = loc 369 } 370 sloc = append(sloc, loc) 371 } 372 p.Sample = append(p.Sample, &profile.Sample{ 373 Value: []int64{int64(rec.n), rec.time}, 374 Location: sloc, 375 }) 376 } 377 return p 378 }