github.com/reiver/go@v0.0.0-20150109200633-1d0c7792f172/src/runtime/cpuprof.go (about) 1 // Copyright 2011 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 // CPU profiling. 6 // Based on algorithms and data structures used in 7 // http://code.google.com/p/google-perftools/. 8 // 9 // The main difference between this code and the google-perftools 10 // code is that this code is written to allow copying the profile data 11 // to an arbitrary io.Writer, while the google-perftools code always 12 // writes to an operating system file. 13 // 14 // The signal handler for the profiling clock tick adds a new stack trace 15 // to a hash table tracking counts for recent traces. Most clock ticks 16 // hit in the cache. In the event of a cache miss, an entry must be 17 // evicted from the hash table, copied to a log that will eventually be 18 // written as profile data. The google-perftools code flushed the 19 // log itself during the signal handler. This code cannot do that, because 20 // the io.Writer might block or need system calls or locks that are not 21 // safe to use from within the signal handler. Instead, we split the log 22 // into two halves and let the signal handler fill one half while a goroutine 23 // is writing out the other half. When the signal handler fills its half, it 24 // offers to swap with the goroutine. If the writer is not done with its half, 25 // we lose the stack trace for this clock tick (and record that loss). 26 // The goroutine interacts with the signal handler by calling getprofile() to 27 // get the next log piece to write, implicitly handing back the last log 28 // piece it obtained. 29 // 30 // The state of this dance between the signal handler and the goroutine 31 // is encoded in the Profile.handoff field. If handoff == 0, then the goroutine 32 // is not using either log half and is waiting (or will soon be waiting) for 33 // a new piece by calling notesleep(&p->wait). If the signal handler 34 // changes handoff from 0 to non-zero, it must call notewakeup(&p->wait) 35 // to wake the goroutine. The value indicates the number of entries in the 36 // log half being handed off. The goroutine leaves the non-zero value in 37 // place until it has finished processing the log half and then flips the number 38 // back to zero. Setting the high bit in handoff means that the profiling is over, 39 // and the goroutine is now in charge of flushing the data left in the hash table 40 // to the log and returning that data. 41 // 42 // The handoff field is manipulated using atomic operations. 43 // For the most part, the manipulation of handoff is orderly: if handoff == 0 44 // then the signal handler owns it and can change it to non-zero. 45 // If handoff != 0 then the goroutine owns it and can change it to zero. 46 // If that were the end of the story then we would not need to manipulate 47 // handoff using atomic operations. The operations are needed, however, 48 // in order to let the log closer set the high bit to indicate "EOF" safely 49 // in the situation when normally the goroutine "owns" handoff. 50 51 package runtime 52 53 import "unsafe" 54 55 const ( 56 numBuckets = 1 << 10 57 logSize = 1 << 17 58 assoc = 4 59 maxCPUProfStack = 64 60 ) 61 62 type cpuprofEntry struct { 63 count uintptr 64 depth uintptr 65 stack [maxCPUProfStack]uintptr 66 } 67 68 type cpuProfile struct { 69 on bool // profiling is on 70 wait note // goroutine waits here 71 count uintptr // tick count 72 evicts uintptr // eviction count 73 lost uintptr // lost ticks that need to be logged 74 75 // Active recent stack traces. 76 hash [numBuckets]struct { 77 entry [assoc]cpuprofEntry 78 } 79 80 // Log of traces evicted from hash. 81 // Signal handler has filled log[toggle][:nlog]. 82 // Goroutine is writing log[1-toggle][:handoff]. 83 log [2][logSize / 2]uintptr 84 nlog uintptr 85 toggle int32 86 handoff uint32 87 88 // Writer state. 89 // Writer maintains its own toggle to avoid races 90 // looking at signal handler's toggle. 91 wtoggle uint32 92 wholding bool // holding & need to release a log half 93 flushing bool // flushing hash table - profile is over 94 eodSent bool // special end-of-data record sent; => flushing 95 } 96 97 var ( 98 cpuprofLock mutex 99 cpuprof *cpuProfile 100 101 eod = [3]uintptr{0, 1, 0} 102 ) 103 104 func setcpuprofilerate(hz int32) { 105 systemstack(func() { 106 setcpuprofilerate_m(hz) 107 }) 108 } 109 110 // lostProfileData is a no-op function used in profiles 111 // to mark the number of profiling stack traces that were 112 // discarded due to slow data writers. 113 func lostProfileData() {} 114 115 // SetCPUProfileRate sets the CPU profiling rate to hz samples per second. 116 // If hz <= 0, SetCPUProfileRate turns off profiling. 117 // If the profiler is on, the rate cannot be changed without first turning it off. 118 // 119 // Most clients should use the runtime/pprof package or 120 // the testing package's -test.cpuprofile flag instead of calling 121 // SetCPUProfileRate directly. 122 func SetCPUProfileRate(hz int) { 123 // Clamp hz to something reasonable. 124 if hz < 0 { 125 hz = 0 126 } 127 if hz > 1000000 { 128 hz = 1000000 129 } 130 131 lock(&cpuprofLock) 132 if hz > 0 { 133 if cpuprof == nil { 134 cpuprof = (*cpuProfile)(sysAlloc(unsafe.Sizeof(cpuProfile{}), &memstats.other_sys)) 135 if cpuprof == nil { 136 print("runtime: cpu profiling cannot allocate memory\n") 137 unlock(&cpuprofLock) 138 return 139 } 140 } 141 if cpuprof.on || cpuprof.handoff != 0 { 142 print("runtime: cannot set cpu profile rate until previous profile has finished.\n") 143 unlock(&cpuprofLock) 144 return 145 } 146 147 cpuprof.on = true 148 // pprof binary header format. 149 // http://code.google.com/p/google-perftools/source/browse/trunk/src/profiledata.cc#117 150 p := &cpuprof.log[0] 151 p[0] = 0 // count for header 152 p[1] = 3 // depth for header 153 p[2] = 0 // version number 154 p[3] = uintptr(1e6 / hz) // period (microseconds) 155 p[4] = 0 156 cpuprof.nlog = 5 157 cpuprof.toggle = 0 158 cpuprof.wholding = false 159 cpuprof.wtoggle = 0 160 cpuprof.flushing = false 161 cpuprof.eodSent = false 162 noteclear(&cpuprof.wait) 163 164 setcpuprofilerate(int32(hz)) 165 } else if cpuprof != nil && cpuprof.on { 166 setcpuprofilerate(0) 167 cpuprof.on = false 168 169 // Now add is not running anymore, and getprofile owns the entire log. 170 // Set the high bit in prof->handoff to tell getprofile. 171 for { 172 n := cpuprof.handoff 173 if n&0x80000000 != 0 { 174 print("runtime: setcpuprofile(off) twice\n") 175 } 176 if cas(&cpuprof.handoff, n, n|0x80000000) { 177 if n == 0 { 178 // we did the transition from 0 -> nonzero so we wake getprofile 179 notewakeup(&cpuprof.wait) 180 } 181 break 182 } 183 } 184 } 185 unlock(&cpuprofLock) 186 } 187 188 func cpuproftick(pc *uintptr, n int32) { 189 if n > maxCPUProfStack { 190 n = maxCPUProfStack 191 } 192 s := (*[maxCPUProfStack]uintptr)(unsafe.Pointer(pc))[:n] 193 cpuprof.add(s) 194 } 195 196 // add adds the stack trace to the profile. 197 // It is called from signal handlers and other limited environments 198 // and cannot allocate memory or acquire locks that might be 199 // held at the time of the signal, nor can it use substantial amounts 200 // of stack. It is allowed to call evict. 201 func (p *cpuProfile) add(pc []uintptr) { 202 // Compute hash. 203 h := uintptr(0) 204 for _, x := range pc { 205 h = h<<8 | (h >> (8 * (unsafe.Sizeof(h) - 1))) 206 h += x * 41 207 } 208 p.count++ 209 210 // Add to entry count if already present in table. 211 b := &p.hash[h%numBuckets] 212 Assoc: 213 for i := range b.entry { 214 e := &b.entry[i] 215 if e.depth != uintptr(len(pc)) { 216 continue 217 } 218 for j := range pc { 219 if e.stack[j] != pc[j] { 220 continue Assoc 221 } 222 } 223 e.count++ 224 return 225 } 226 227 // Evict entry with smallest count. 228 var e *cpuprofEntry 229 for i := range b.entry { 230 if e == nil || b.entry[i].count < e.count { 231 e = &b.entry[i] 232 } 233 } 234 if e.count > 0 { 235 if !p.evict(e) { 236 // Could not evict entry. Record lost stack. 237 p.lost++ 238 return 239 } 240 p.evicts++ 241 } 242 243 // Reuse the newly evicted entry. 244 e.depth = uintptr(len(pc)) 245 e.count = 1 246 copy(e.stack[:], pc) 247 } 248 249 // evict copies the given entry's data into the log, so that 250 // the entry can be reused. evict is called from add, which 251 // is called from the profiling signal handler, so it must not 252 // allocate memory or block. It is safe to call flushlog. 253 // evict returns true if the entry was copied to the log, 254 // false if there was no room available. 255 func (p *cpuProfile) evict(e *cpuprofEntry) bool { 256 d := e.depth 257 nslot := d + 2 258 log := &p.log[p.toggle] 259 if p.nlog+nslot > uintptr(len(p.log[0])) { 260 if !p.flushlog() { 261 return false 262 } 263 log = &p.log[p.toggle] 264 } 265 266 q := p.nlog 267 log[q] = e.count 268 q++ 269 log[q] = d 270 q++ 271 copy(log[q:], e.stack[:d]) 272 q += d 273 p.nlog = q 274 e.count = 0 275 return true 276 } 277 278 // flushlog tries to flush the current log and switch to the other one. 279 // flushlog is called from evict, called from add, called from the signal handler, 280 // so it cannot allocate memory or block. It can try to swap logs with 281 // the writing goroutine, as explained in the comment at the top of this file. 282 func (p *cpuProfile) flushlog() bool { 283 if !cas(&p.handoff, 0, uint32(p.nlog)) { 284 return false 285 } 286 notewakeup(&p.wait) 287 288 p.toggle = 1 - p.toggle 289 log := &p.log[p.toggle] 290 q := uintptr(0) 291 if p.lost > 0 { 292 lostPC := funcPC(lostProfileData) 293 log[0] = p.lost 294 log[1] = 1 295 log[2] = lostPC 296 q = 3 297 p.lost = 0 298 } 299 p.nlog = q 300 return true 301 } 302 303 // getprofile blocks until the next block of profiling data is available 304 // and returns it as a []byte. It is called from the writing goroutine. 305 func (p *cpuProfile) getprofile() []byte { 306 if p == nil { 307 return nil 308 } 309 310 if p.wholding { 311 // Release previous log to signal handling side. 312 // Loop because we are racing against SetCPUProfileRate(0). 313 for { 314 n := p.handoff 315 if n == 0 { 316 print("runtime: phase error during cpu profile handoff\n") 317 return nil 318 } 319 if n&0x80000000 != 0 { 320 p.wtoggle = 1 - p.wtoggle 321 p.wholding = false 322 p.flushing = true 323 goto Flush 324 } 325 if cas(&p.handoff, n, 0) { 326 break 327 } 328 } 329 p.wtoggle = 1 - p.wtoggle 330 p.wholding = false 331 } 332 333 if p.flushing { 334 goto Flush 335 } 336 337 if !p.on && p.handoff == 0 { 338 return nil 339 } 340 341 // Wait for new log. 342 notetsleepg(&p.wait, -1) 343 noteclear(&p.wait) 344 345 switch n := p.handoff; { 346 case n == 0: 347 print("runtime: phase error during cpu profile wait\n") 348 return nil 349 case n == 0x80000000: 350 p.flushing = true 351 goto Flush 352 default: 353 n &^= 0x80000000 354 355 // Return new log to caller. 356 p.wholding = true 357 358 return uintptrBytes(p.log[p.wtoggle][:n]) 359 } 360 361 // In flush mode. 362 // Add is no longer being called. We own the log. 363 // Also, p->handoff is non-zero, so flushlog will return false. 364 // Evict the hash table into the log and return it. 365 Flush: 366 for i := range p.hash { 367 b := &p.hash[i] 368 for j := range b.entry { 369 e := &b.entry[j] 370 if e.count > 0 && !p.evict(e) { 371 // Filled the log. Stop the loop and return what we've got. 372 break Flush 373 } 374 } 375 } 376 377 // Return pending log data. 378 if p.nlog > 0 { 379 // Note that we're using toggle now, not wtoggle, 380 // because we're working on the log directly. 381 n := p.nlog 382 p.nlog = 0 383 return uintptrBytes(p.log[p.toggle][:n]) 384 } 385 386 // Made it through the table without finding anything to log. 387 if !p.eodSent { 388 // We may not have space to append this to the partial log buf, 389 // so we always return a new slice for the end-of-data marker. 390 p.eodSent = true 391 return uintptrBytes(eod[:]) 392 } 393 394 // Finally done. Clean up and return nil. 395 p.flushing = false 396 if !cas(&p.handoff, p.handoff, 0) { 397 print("runtime: profile flush racing with something\n") 398 } 399 return nil 400 } 401 402 func uintptrBytes(p []uintptr) (ret []byte) { 403 pp := (*sliceStruct)(unsafe.Pointer(&p)) 404 rp := (*sliceStruct)(unsafe.Pointer(&ret)) 405 406 rp.array = pp.array 407 rp.len = pp.len * int(unsafe.Sizeof(p[0])) 408 rp.cap = rp.len 409 410 return 411 } 412 413 // CPUProfile returns the next chunk of binary CPU profiling stack trace data, 414 // blocking until data is available. If profiling is turned off and all the profile 415 // data accumulated while it was on has been returned, CPUProfile returns nil. 416 // The caller must save the returned data before calling CPUProfile again. 417 // 418 // Most clients should use the runtime/pprof package or 419 // the testing package's -test.cpuprofile flag instead of calling 420 // CPUProfile directly. 421 func CPUProfile() []byte { 422 return cpuprof.getprofile() 423 } 424 425 //go:linkname runtime_pprof_runtime_cyclesPerSecond runtime/pprof.runtime_cyclesPerSecond 426 func runtime_pprof_runtime_cyclesPerSecond() int64 { 427 return tickspersecond() 428 }