github.com/varialus/godfly@v0.0.0-20130904042352-1934f9f095ab/src/pkg/runtime/pprof/pprof.go (about) 1 // Copyright 2010 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 // Package pprof writes runtime profiling data in the format expected 6 // by the pprof visualization tool. 7 // For more information about pprof, see 8 // http://code.google.com/p/google-perftools/. 9 package pprof 10 11 import ( 12 "bufio" 13 "bytes" 14 "fmt" 15 "io" 16 "runtime" 17 "sort" 18 "strings" 19 "sync" 20 "text/tabwriter" 21 ) 22 23 // BUG(rsc): Profiles are incomplete and inaccuate on NetBSD, OpenBSD, and OS X. 24 // See http://golang.org/issue/6047 for details. 25 26 // A Profile is a collection of stack traces showing the call sequences 27 // that led to instances of a particular event, such as allocation. 28 // Packages can create and maintain their own profiles; the most common 29 // use is for tracking resources that must be explicitly closed, such as files 30 // or network connections. 31 // 32 // A Profile's methods can be called from multiple goroutines simultaneously. 33 // 34 // Each Profile has a unique name. A few profiles are predefined: 35 // 36 // goroutine - stack traces of all current goroutines 37 // heap - a sampling of all heap allocations 38 // threadcreate - stack traces that led to the creation of new OS threads 39 // block - stack traces that led to blocking on synchronization primitives 40 // 41 // These predefined profiles maintain themselves and panic on an explicit 42 // Add or Remove method call. 43 // 44 // The CPU profile is not available as a Profile. It has a special API, 45 // the StartCPUProfile and StopCPUProfile functions, because it streams 46 // output to a writer during profiling. 47 // 48 type Profile struct { 49 name string 50 mu sync.Mutex 51 m map[interface{}][]uintptr 52 count func() int 53 write func(io.Writer, int) error 54 } 55 56 // profiles records all registered profiles. 57 var profiles struct { 58 mu sync.Mutex 59 m map[string]*Profile 60 } 61 62 var goroutineProfile = &Profile{ 63 name: "goroutine", 64 count: countGoroutine, 65 write: writeGoroutine, 66 } 67 68 var threadcreateProfile = &Profile{ 69 name: "threadcreate", 70 count: countThreadCreate, 71 write: writeThreadCreate, 72 } 73 74 var heapProfile = &Profile{ 75 name: "heap", 76 count: countHeap, 77 write: writeHeap, 78 } 79 80 var blockProfile = &Profile{ 81 name: "block", 82 count: countBlock, 83 write: writeBlock, 84 } 85 86 func lockProfiles() { 87 profiles.mu.Lock() 88 if profiles.m == nil { 89 // Initial built-in profiles. 90 profiles.m = map[string]*Profile{ 91 "goroutine": goroutineProfile, 92 "threadcreate": threadcreateProfile, 93 "heap": heapProfile, 94 "block": blockProfile, 95 } 96 } 97 } 98 99 func unlockProfiles() { 100 profiles.mu.Unlock() 101 } 102 103 // NewProfile creates a new profile with the given name. 104 // If a profile with that name already exists, NewProfile panics. 105 // The convention is to use a 'import/path.' prefix to create 106 // separate name spaces for each package. 107 func NewProfile(name string) *Profile { 108 lockProfiles() 109 defer unlockProfiles() 110 if name == "" { 111 panic("pprof: NewProfile with empty name") 112 } 113 if profiles.m[name] != nil { 114 panic("pprof: NewProfile name already in use: " + name) 115 } 116 p := &Profile{ 117 name: name, 118 m: map[interface{}][]uintptr{}, 119 } 120 profiles.m[name] = p 121 return p 122 } 123 124 // Lookup returns the profile with the given name, or nil if no such profile exists. 125 func Lookup(name string) *Profile { 126 lockProfiles() 127 defer unlockProfiles() 128 return profiles.m[name] 129 } 130 131 // Profiles returns a slice of all the known profiles, sorted by name. 132 func Profiles() []*Profile { 133 lockProfiles() 134 defer unlockProfiles() 135 136 var all []*Profile 137 for _, p := range profiles.m { 138 all = append(all, p) 139 } 140 141 sort.Sort(byName(all)) 142 return all 143 } 144 145 type byName []*Profile 146 147 func (x byName) Len() int { return len(x) } 148 func (x byName) Swap(i, j int) { x[i], x[j] = x[j], x[i] } 149 func (x byName) Less(i, j int) bool { return x[i].name < x[j].name } 150 151 // Name returns this profile's name, which can be passed to Lookup to reobtain the profile. 152 func (p *Profile) Name() string { 153 return p.name 154 } 155 156 // Count returns the number of execution stacks currently in the profile. 157 func (p *Profile) Count() int { 158 p.mu.Lock() 159 defer p.mu.Unlock() 160 if p.count != nil { 161 return p.count() 162 } 163 return len(p.m) 164 } 165 166 // Add adds the current execution stack to the profile, associated with value. 167 // Add stores value in an internal map, so value must be suitable for use as 168 // a map key and will not be garbage collected until the corresponding 169 // call to Remove. Add panics if the profile already contains a stack for value. 170 // 171 // The skip parameter has the same meaning as runtime.Caller's skip 172 // and controls where the stack trace begins. Passing skip=0 begins the 173 // trace in the function calling Add. For example, given this 174 // execution stack: 175 // 176 // Add 177 // called from rpc.NewClient 178 // called from mypkg.Run 179 // called from main.main 180 // 181 // Passing skip=0 begins the stack trace at the call to Add inside rpc.NewClient. 182 // Passing skip=1 begins the stack trace at the call to NewClient inside mypkg.Run. 183 // 184 func (p *Profile) Add(value interface{}, skip int) { 185 if p.name == "" { 186 panic("pprof: use of uninitialized Profile") 187 } 188 if p.write != nil { 189 panic("pprof: Add called on built-in Profile " + p.name) 190 } 191 192 stk := make([]uintptr, 32) 193 n := runtime.Callers(skip+1, stk[:]) 194 195 p.mu.Lock() 196 defer p.mu.Unlock() 197 if p.m[value] != nil { 198 panic("pprof: Profile.Add of duplicate value") 199 } 200 p.m[value] = stk[:n] 201 } 202 203 // Remove removes the execution stack associated with value from the profile. 204 // It is a no-op if the value is not in the profile. 205 func (p *Profile) Remove(value interface{}) { 206 p.mu.Lock() 207 defer p.mu.Unlock() 208 delete(p.m, value) 209 } 210 211 // WriteTo writes a pprof-formatted snapshot of the profile to w. 212 // If a write to w returns an error, WriteTo returns that error. 213 // Otherwise, WriteTo returns nil. 214 // 215 // The debug parameter enables additional output. 216 // Passing debug=0 prints only the hexadecimal addresses that pprof needs. 217 // Passing debug=1 adds comments translating addresses to function names 218 // and line numbers, so that a programmer can read the profile without tools. 219 // 220 // The predefined profiles may assign meaning to other debug values; 221 // for example, when printing the "goroutine" profile, debug=2 means to 222 // print the goroutine stacks in the same form that a Go program uses 223 // when dying due to an unrecovered panic. 224 func (p *Profile) WriteTo(w io.Writer, debug int) error { 225 if p.name == "" { 226 panic("pprof: use of zero Profile") 227 } 228 if p.write != nil { 229 return p.write(w, debug) 230 } 231 232 // Obtain consistent snapshot under lock; then process without lock. 233 var all [][]uintptr 234 p.mu.Lock() 235 for _, stk := range p.m { 236 all = append(all, stk) 237 } 238 p.mu.Unlock() 239 240 // Map order is non-deterministic; make output deterministic. 241 sort.Sort(stackProfile(all)) 242 243 return printCountProfile(w, debug, p.name, stackProfile(all)) 244 } 245 246 type stackProfile [][]uintptr 247 248 func (x stackProfile) Len() int { return len(x) } 249 func (x stackProfile) Stack(i int) []uintptr { return x[i] } 250 func (x stackProfile) Swap(i, j int) { x[i], x[j] = x[j], x[i] } 251 func (x stackProfile) Less(i, j int) bool { 252 t, u := x[i], x[j] 253 for k := 0; k < len(t) && k < len(u); k++ { 254 if t[k] != u[k] { 255 return t[k] < u[k] 256 } 257 } 258 return len(t) < len(u) 259 } 260 261 // A countProfile is a set of stack traces to be printed as counts 262 // grouped by stack trace. There are multiple implementations: 263 // all that matters is that we can find out how many traces there are 264 // and obtain each trace in turn. 265 type countProfile interface { 266 Len() int 267 Stack(i int) []uintptr 268 } 269 270 // printCountProfile prints a countProfile at the specified debug level. 271 func printCountProfile(w io.Writer, debug int, name string, p countProfile) error { 272 b := bufio.NewWriter(w) 273 var tw *tabwriter.Writer 274 w = b 275 if debug > 0 { 276 tw = tabwriter.NewWriter(w, 1, 8, 1, '\t', 0) 277 w = tw 278 } 279 280 fmt.Fprintf(w, "%s profile: total %d\n", name, p.Len()) 281 282 // Build count of each stack. 283 var buf bytes.Buffer 284 key := func(stk []uintptr) string { 285 buf.Reset() 286 fmt.Fprintf(&buf, "@") 287 for _, pc := range stk { 288 fmt.Fprintf(&buf, " %#x", pc) 289 } 290 return buf.String() 291 } 292 m := map[string]int{} 293 n := p.Len() 294 for i := 0; i < n; i++ { 295 m[key(p.Stack(i))]++ 296 } 297 298 // Print stacks, listing count on first occurrence of a unique stack. 299 for i := 0; i < n; i++ { 300 stk := p.Stack(i) 301 s := key(stk) 302 if count := m[s]; count != 0 { 303 fmt.Fprintf(w, "%d %s\n", count, s) 304 if debug > 0 { 305 printStackRecord(w, stk, false) 306 } 307 delete(m, s) 308 } 309 } 310 311 if tw != nil { 312 tw.Flush() 313 } 314 return b.Flush() 315 } 316 317 // printStackRecord prints the function + source line information 318 // for a single stack trace. 319 func printStackRecord(w io.Writer, stk []uintptr, allFrames bool) { 320 show := allFrames 321 wasPanic := false 322 for i, pc := range stk { 323 f := runtime.FuncForPC(pc) 324 if f == nil { 325 show = true 326 fmt.Fprintf(w, "#\t%#x\n", pc) 327 wasPanic = false 328 } else { 329 tracepc := pc 330 // Back up to call instruction. 331 if i > 0 && pc > f.Entry() && !wasPanic { 332 if runtime.GOARCH == "386" || runtime.GOARCH == "amd64" { 333 tracepc-- 334 } else { 335 tracepc -= 4 // arm, etc 336 } 337 } 338 file, line := f.FileLine(tracepc) 339 name := f.Name() 340 // Hide runtime.goexit and any runtime functions at the beginning. 341 // This is useful mainly for allocation traces. 342 wasPanic = name == "runtime.panic" 343 if name == "runtime.goexit" || !show && strings.HasPrefix(name, "runtime.") { 344 continue 345 } 346 show = true 347 fmt.Fprintf(w, "#\t%#x\t%s+%#x\t%s:%d\n", pc, name, pc-f.Entry(), file, line) 348 } 349 } 350 if !show { 351 // We didn't print anything; do it again, 352 // and this time include runtime functions. 353 printStackRecord(w, stk, true) 354 return 355 } 356 fmt.Fprintf(w, "\n") 357 } 358 359 // Interface to system profiles. 360 361 type byInUseBytes []runtime.MemProfileRecord 362 363 func (x byInUseBytes) Len() int { return len(x) } 364 func (x byInUseBytes) Swap(i, j int) { x[i], x[j] = x[j], x[i] } 365 func (x byInUseBytes) Less(i, j int) bool { return x[i].InUseBytes() > x[j].InUseBytes() } 366 367 // WriteHeapProfile is shorthand for Lookup("heap").WriteTo(w, 0). 368 // It is preserved for backwards compatibility. 369 func WriteHeapProfile(w io.Writer) error { 370 return writeHeap(w, 0) 371 } 372 373 // countHeap returns the number of records in the heap profile. 374 func countHeap() int { 375 n, _ := runtime.MemProfile(nil, true) 376 return n 377 } 378 379 // writeHeap writes the current runtime heap profile to w. 380 func writeHeap(w io.Writer, debug int) error { 381 // Find out how many records there are (MemProfile(nil, true)), 382 // allocate that many records, and get the data. 383 // There's a race—more records might be added between 384 // the two calls—so allocate a few extra records for safety 385 // and also try again if we're very unlucky. 386 // The loop should only execute one iteration in the common case. 387 var p []runtime.MemProfileRecord 388 n, ok := runtime.MemProfile(nil, true) 389 for { 390 // Allocate room for a slightly bigger profile, 391 // in case a few more entries have been added 392 // since the call to MemProfile. 393 p = make([]runtime.MemProfileRecord, n+50) 394 n, ok = runtime.MemProfile(p, true) 395 if ok { 396 p = p[0:n] 397 break 398 } 399 // Profile grew; try again. 400 } 401 402 sort.Sort(byInUseBytes(p)) 403 404 b := bufio.NewWriter(w) 405 var tw *tabwriter.Writer 406 w = b 407 if debug > 0 { 408 tw = tabwriter.NewWriter(w, 1, 8, 1, '\t', 0) 409 w = tw 410 } 411 412 var total runtime.MemProfileRecord 413 for i := range p { 414 r := &p[i] 415 total.AllocBytes += r.AllocBytes 416 total.AllocObjects += r.AllocObjects 417 total.FreeBytes += r.FreeBytes 418 total.FreeObjects += r.FreeObjects 419 } 420 421 // Technically the rate is MemProfileRate not 2*MemProfileRate, 422 // but early versions of the C++ heap profiler reported 2*MemProfileRate, 423 // so that's what pprof has come to expect. 424 fmt.Fprintf(w, "heap profile: %d: %d [%d: %d] @ heap/%d\n", 425 total.InUseObjects(), total.InUseBytes(), 426 total.AllocObjects, total.AllocBytes, 427 2*runtime.MemProfileRate) 428 429 for i := range p { 430 r := &p[i] 431 fmt.Fprintf(w, "%d: %d [%d: %d] @", 432 r.InUseObjects(), r.InUseBytes(), 433 r.AllocObjects, r.AllocBytes) 434 for _, pc := range r.Stack() { 435 fmt.Fprintf(w, " %#x", pc) 436 } 437 fmt.Fprintf(w, "\n") 438 if debug > 0 { 439 printStackRecord(w, r.Stack(), false) 440 } 441 } 442 443 // Print memstats information too. 444 // Pprof will ignore, but useful for people 445 if debug > 0 { 446 s := new(runtime.MemStats) 447 runtime.ReadMemStats(s) 448 fmt.Fprintf(w, "\n# runtime.MemStats\n") 449 fmt.Fprintf(w, "# Alloc = %d\n", s.Alloc) 450 fmt.Fprintf(w, "# TotalAlloc = %d\n", s.TotalAlloc) 451 fmt.Fprintf(w, "# Sys = %d\n", s.Sys) 452 fmt.Fprintf(w, "# Lookups = %d\n", s.Lookups) 453 fmt.Fprintf(w, "# Mallocs = %d\n", s.Mallocs) 454 fmt.Fprintf(w, "# Frees = %d\n", s.Frees) 455 456 fmt.Fprintf(w, "# HeapAlloc = %d\n", s.HeapAlloc) 457 fmt.Fprintf(w, "# HeapSys = %d\n", s.HeapSys) 458 fmt.Fprintf(w, "# HeapIdle = %d\n", s.HeapIdle) 459 fmt.Fprintf(w, "# HeapInuse = %d\n", s.HeapInuse) 460 fmt.Fprintf(w, "# HeapReleased = %d\n", s.HeapReleased) 461 fmt.Fprintf(w, "# HeapObjects = %d\n", s.HeapObjects) 462 463 fmt.Fprintf(w, "# Stack = %d / %d\n", s.StackInuse, s.StackSys) 464 fmt.Fprintf(w, "# MSpan = %d / %d\n", s.MSpanInuse, s.MSpanSys) 465 fmt.Fprintf(w, "# MCache = %d / %d\n", s.MCacheInuse, s.MCacheSys) 466 fmt.Fprintf(w, "# BuckHashSys = %d\n", s.BuckHashSys) 467 468 fmt.Fprintf(w, "# NextGC = %d\n", s.NextGC) 469 fmt.Fprintf(w, "# PauseNs = %d\n", s.PauseNs) 470 fmt.Fprintf(w, "# NumGC = %d\n", s.NumGC) 471 fmt.Fprintf(w, "# EnableGC = %v\n", s.EnableGC) 472 fmt.Fprintf(w, "# DebugGC = %v\n", s.DebugGC) 473 } 474 475 if tw != nil { 476 tw.Flush() 477 } 478 return b.Flush() 479 } 480 481 // countThreadCreate returns the size of the current ThreadCreateProfile. 482 func countThreadCreate() int { 483 n, _ := runtime.ThreadCreateProfile(nil) 484 return n 485 } 486 487 // writeThreadCreate writes the current runtime ThreadCreateProfile to w. 488 func writeThreadCreate(w io.Writer, debug int) error { 489 return writeRuntimeProfile(w, debug, "threadcreate", runtime.ThreadCreateProfile) 490 } 491 492 // countGoroutine returns the number of goroutines. 493 func countGoroutine() int { 494 return runtime.NumGoroutine() 495 } 496 497 // writeGoroutine writes the current runtime GoroutineProfile to w. 498 func writeGoroutine(w io.Writer, debug int) error { 499 if debug >= 2 { 500 return writeGoroutineStacks(w) 501 } 502 return writeRuntimeProfile(w, debug, "goroutine", runtime.GoroutineProfile) 503 } 504 505 func writeGoroutineStacks(w io.Writer) error { 506 // We don't know how big the buffer needs to be to collect 507 // all the goroutines. Start with 1 MB and try a few times, doubling each time. 508 // Give up and use a truncated trace if 64 MB is not enough. 509 buf := make([]byte, 1<<20) 510 for i := 0; ; i++ { 511 n := runtime.Stack(buf, true) 512 if n < len(buf) { 513 buf = buf[:n] 514 break 515 } 516 if len(buf) >= 64<<20 { 517 // Filled 64 MB - stop there. 518 break 519 } 520 buf = make([]byte, 2*len(buf)) 521 } 522 _, err := w.Write(buf) 523 return err 524 } 525 526 func writeRuntimeProfile(w io.Writer, debug int, name string, fetch func([]runtime.StackRecord) (int, bool)) error { 527 // Find out how many records there are (fetch(nil)), 528 // allocate that many records, and get the data. 529 // There's a race—more records might be added between 530 // the two calls—so allocate a few extra records for safety 531 // and also try again if we're very unlucky. 532 // The loop should only execute one iteration in the common case. 533 var p []runtime.StackRecord 534 n, ok := fetch(nil) 535 for { 536 // Allocate room for a slightly bigger profile, 537 // in case a few more entries have been added 538 // since the call to ThreadProfile. 539 p = make([]runtime.StackRecord, n+10) 540 n, ok = fetch(p) 541 if ok { 542 p = p[0:n] 543 break 544 } 545 // Profile grew; try again. 546 } 547 548 return printCountProfile(w, debug, name, runtimeProfile(p)) 549 } 550 551 type runtimeProfile []runtime.StackRecord 552 553 func (p runtimeProfile) Len() int { return len(p) } 554 func (p runtimeProfile) Stack(i int) []uintptr { return p[i].Stack() } 555 556 var cpu struct { 557 sync.Mutex 558 profiling bool 559 done chan bool 560 } 561 562 // StartCPUProfile enables CPU profiling for the current process. 563 // While profiling, the profile will be buffered and written to w. 564 // StartCPUProfile returns an error if profiling is already enabled. 565 func StartCPUProfile(w io.Writer) error { 566 // The runtime routines allow a variable profiling rate, 567 // but in practice operating systems cannot trigger signals 568 // at more than about 500 Hz, and our processing of the 569 // signal is not cheap (mostly getting the stack trace). 570 // 100 Hz is a reasonable choice: it is frequent enough to 571 // produce useful data, rare enough not to bog down the 572 // system, and a nice round number to make it easy to 573 // convert sample counts to seconds. Instead of requiring 574 // each client to specify the frequency, we hard code it. 575 const hz = 100 576 577 // Avoid queueing behind StopCPUProfile. 578 // Could use TryLock instead if we had it. 579 if cpu.profiling { 580 return fmt.Errorf("cpu profiling already in use") 581 } 582 583 cpu.Lock() 584 defer cpu.Unlock() 585 if cpu.done == nil { 586 cpu.done = make(chan bool) 587 } 588 // Double-check. 589 if cpu.profiling { 590 return fmt.Errorf("cpu profiling already in use") 591 } 592 cpu.profiling = true 593 runtime.SetCPUProfileRate(hz) 594 go profileWriter(w) 595 return nil 596 } 597 598 func profileWriter(w io.Writer) { 599 for { 600 data := runtime.CPUProfile() 601 if data == nil { 602 break 603 } 604 w.Write(data) 605 } 606 cpu.done <- true 607 } 608 609 // StopCPUProfile stops the current CPU profile, if any. 610 // StopCPUProfile only returns after all the writes for the 611 // profile have completed. 612 func StopCPUProfile() { 613 cpu.Lock() 614 defer cpu.Unlock() 615 616 if !cpu.profiling { 617 return 618 } 619 cpu.profiling = false 620 runtime.SetCPUProfileRate(0) 621 <-cpu.done 622 } 623 624 type byCycles []runtime.BlockProfileRecord 625 626 func (x byCycles) Len() int { return len(x) } 627 func (x byCycles) Swap(i, j int) { x[i], x[j] = x[j], x[i] } 628 func (x byCycles) Less(i, j int) bool { return x[i].Cycles > x[j].Cycles } 629 630 // countBlock returns the number of records in the blocking profile. 631 func countBlock() int { 632 n, _ := runtime.BlockProfile(nil) 633 return n 634 } 635 636 // writeBlock writes the current blocking profile to w. 637 func writeBlock(w io.Writer, debug int) error { 638 var p []runtime.BlockProfileRecord 639 n, ok := runtime.BlockProfile(nil) 640 for { 641 p = make([]runtime.BlockProfileRecord, n+50) 642 n, ok = runtime.BlockProfile(p) 643 if ok { 644 p = p[:n] 645 break 646 } 647 } 648 649 sort.Sort(byCycles(p)) 650 651 b := bufio.NewWriter(w) 652 var tw *tabwriter.Writer 653 w = b 654 if debug > 0 { 655 tw = tabwriter.NewWriter(w, 1, 8, 1, '\t', 0) 656 w = tw 657 } 658 659 fmt.Fprintf(w, "--- contention:\n") 660 fmt.Fprintf(w, "cycles/second=%v\n", runtime_cyclesPerSecond()) 661 for i := range p { 662 r := &p[i] 663 fmt.Fprintf(w, "%v %v @", r.Cycles, r.Count) 664 for _, pc := range r.Stack() { 665 fmt.Fprintf(w, " %#x", pc) 666 } 667 fmt.Fprint(w, "\n") 668 if debug > 0 { 669 printStackRecord(w, r.Stack(), true) 670 } 671 } 672 673 if tw != nil { 674 tw.Flush() 675 } 676 return b.Flush() 677 } 678 679 func runtime_cyclesPerSecond() int64