Commit ac49e673 authored by Matthew Dempsky's avatar Matthew Dempsky Committed by Russ Cox

runtime: convert cpuprof from C to Go

LGTM=dvyukov, rsc
R=golang-codereviews, dvyukov, rsc
CC=golang-codereviews
https://golang.org/cl/132440043
parent a19e638d
...@@ -49,150 +49,144 @@ ...@@ -49,150 +49,144 @@
// in the situation when normally the goroutine "owns" handoff. // in the situation when normally the goroutine "owns" handoff.
package runtime package runtime
#include "runtime.h"
#include "arch_GOARCH.h" import "unsafe"
#include "malloc.h"
const (
enum numBuckets = 1 << 10
{ logSize = 1 << 17
HashSize = 1<<10, assoc = 4
LogSize = 1<<17, maxCPUProfStack = 64
Assoc = 4, )
MaxStack = 64,
}; type cpuprofEntry struct {
count uintptr
typedef struct Profile Profile; depth uintptr
typedef struct Bucket Bucket; stack [maxCPUProfStack]uintptr
typedef struct Entry Entry; }
struct Entry { type cpuProfile struct {
uintptr count; on bool // profiling is on
uintptr depth; wait note // goroutine waits here
uintptr stack[MaxStack]; count uintptr // tick count
}; evicts uintptr // eviction count
lost uintptr // lost ticks that need to be logged
struct Bucket {
Entry entry[Assoc];
};
struct Profile {
bool on; // profiling is on
Note wait; // goroutine waits here
uintptr count; // tick count
uintptr evicts; // eviction count
uintptr lost; // lost ticks that need to be logged
// Active recent stack traces. // Active recent stack traces.
Bucket hash[HashSize]; hash [numBuckets]struct {
entry [assoc]cpuprofEntry
}
// Log of traces evicted from hash. // Log of traces evicted from hash.
// Signal handler has filled log[toggle][:nlog]. // Signal handler has filled log[toggle][:nlog].
// Goroutine is writing log[1-toggle][:handoff]. // Goroutine is writing log[1-toggle][:handoff].
uintptr log[2][LogSize/2]; log [2][logSize / 2]uintptr
uintptr nlog; nlog uintptr
int32 toggle; toggle int32
uint32 handoff; handoff uint32
// Writer state. // Writer state.
// Writer maintains its own toggle to avoid races // Writer maintains its own toggle to avoid races
// looking at signal handler's toggle. // looking at signal handler's toggle.
uint32 wtoggle; wtoggle uint32
bool wholding; // holding & need to release a log half wholding bool // holding & need to release a log half
bool flushing; // flushing hash table - profile is over flushing bool // flushing hash table - profile is over
bool eod_sent; // special end-of-data record sent; => flushing eodSent bool // special end-of-data record sent; => flushing
}; }
static Mutex lk; var (
static Profile *prof; cpuprofLock mutex
cpuprof *cpuProfile
static void tick(uintptr*, int32); eod = [3]uintptr{0, 1, 0}
static void add(Profile*, uintptr*, int32); )
static bool evict(Profile*, Entry*);
static bool flushlog(Profile*);
static uintptr eod[3] = {0, 1, 0}; func setcpuprofilerate(int32) // proc.c
// LostProfileData is a no-op function used in profiles // lostProfileData is a no-op function used in profiles
// to mark the number of profiling stack traces that were // to mark the number of profiling stack traces that were
// discarded due to slow data writers. // discarded due to slow data writers.
static void func lostProfileData() {}
LostProfileData(void)
{
}
// SetCPUProfileRate sets the CPU profiling rate.
// The user documentation is in debug.go.
void
runtime·SetCPUProfileRate(intgo hz)
{
uintptr *p;
uintptr n;
// SetCPUProfileRate sets the CPU profiling rate to hz samples per second.
// If hz <= 0, SetCPUProfileRate turns off profiling.
// If the profiler is on, the rate cannot be changed without first turning it off.
//
// Most clients should use the runtime/pprof package or
// the testing package's -test.cpuprofile flag instead of calling
// SetCPUProfileRate directly.
func SetCPUProfileRate(hz int) {
// Clamp hz to something reasonable. // Clamp hz to something reasonable.
if(hz < 0) if hz < 0 {
hz = 0; hz = 0
if(hz > 1000000) }
hz = 1000000; if hz > 1000000 {
hz = 1000000
}
runtime·lock(&lk); lock(&cpuprofLock)
if(hz > 0) { if hz > 0 {
if(prof == nil) { if cpuprof == nil {
prof = runtime·sysAlloc(sizeof *prof, &mstats.other_sys); cpuprof = (*cpuProfile)(sysAlloc(unsafe.Sizeof(cpuProfile{}), &memstats.other_sys))
if(prof == nil) { if cpuprof == nil {
runtime·printf("runtime: cpu profiling cannot allocate memory\n"); print("runtime: cpu profiling cannot allocate memory\n")
runtime·unlock(&lk); unlock(&cpuprofLock)
return; return
} }
} }
if(prof->on || prof->handoff != 0) { if cpuprof.on || cpuprof.handoff != 0 {
runtime·printf("runtime: cannot set cpu profile rate until previous profile has finished.\n"); print("runtime: cannot set cpu profile rate until previous profile has finished.\n")
runtime·unlock(&lk); unlock(&cpuprofLock)
return; return
} }
prof->on = true; cpuprof.on = true
p = prof->log[0];
// pprof binary header format. // pprof binary header format.
// http://code.google.com/p/google-perftools/source/browse/trunk/src/profiledata.cc#117 // http://code.google.com/p/google-perftools/source/browse/trunk/src/profiledata.cc#117
*p++ = 0; // count for header p := &cpuprof.log[0]
*p++ = 3; // depth for header p[0] = 0 // count for header
*p++ = 0; // version number p[1] = 3 // depth for header
*p++ = 1000000 / hz; // period (microseconds) p[2] = 0 // version number
*p++ = 0; p[3] = uintptr(1e6 / hz) // period (microseconds)
prof->nlog = p - prof->log[0]; p[4] = 0
prof->toggle = 0; cpuprof.nlog = 5
prof->wholding = false; cpuprof.toggle = 0
prof->wtoggle = 0; cpuprof.wholding = false
prof->flushing = false; cpuprof.wtoggle = 0
prof->eod_sent = false; cpuprof.flushing = false
runtime·noteclear(&prof->wait); cpuprof.eodSent = false
noteclear(&cpuprof.wait)
runtime·setcpuprofilerate(tick, hz);
} else if(prof != nil && prof->on) { setcpuprofilerate(int32(hz))
runtime·setcpuprofilerate(nil, 0); } else if cpuprof != nil && cpuprof.on {
prof->on = false; setcpuprofilerate(0)
cpuprof.on = false
// Now add is not running anymore, and getprofile owns the entire log. // Now add is not running anymore, and getprofile owns the entire log.
// Set the high bit in prof->handoff to tell getprofile. // Set the high bit in prof->handoff to tell getprofile.
for(;;) { for {
n = prof->handoff; n := cpuprof.handoff
if(n&0x80000000) if n&0x80000000 != 0 {
runtime·printf("runtime: setcpuprofile(off) twice"); print("runtime: setcpuprofile(off) twice\n")
if(runtime·cas(&prof->handoff, n, n|0x80000000)) }
break; if cas(&cpuprof.handoff, n, n|0x80000000) {
} if n == 0 {
if(n == 0) {
// we did the transition from 0 -> nonzero so we wake getprofile // we did the transition from 0 -> nonzero so we wake getprofile
runtime·notewakeup(&prof->wait); notewakeup(&cpuprof.wait)
}
break
}
} }
} }
runtime·unlock(&lk); unlock(&cpuprofLock)
} }
static void func cpuproftick(pc *uintptr, n int32) {
tick(uintptr *pc, int32 n) if n > maxCPUProfStack {
{ n = maxCPUProfStack
add(prof, pc, n); }
s := (*[maxCPUProfStack]uintptr)(unsafe.Pointer(pc))[:n]
cpuprof.add(s)
} }
// add adds the stack trace to the profile. // add adds the stack trace to the profile.
...@@ -200,234 +194,231 @@ tick(uintptr *pc, int32 n) ...@@ -200,234 +194,231 @@ tick(uintptr *pc, int32 n)
// and cannot allocate memory or acquire locks that might be // and cannot allocate memory or acquire locks that might be
// held at the time of the signal, nor can it use substantial amounts // held at the time of the signal, nor can it use substantial amounts
// of stack. It is allowed to call evict. // of stack. It is allowed to call evict.
static void func (p *cpuProfile) add(pc []uintptr) {
add(Profile *p, uintptr *pc, int32 n)
{
int32 i, j;
uintptr h, x;
Bucket *b;
Entry *e;
if(n > MaxStack)
n = MaxStack;
// Compute hash. // Compute hash.
h = 0; h := uintptr(0)
for(i=0; i<n; i++) { for _, x := range pc {
h = h<<8 | (h>>(8*(sizeof(h)-1))); h = h<<8 | (h >> (8 * (unsafe.Sizeof(h) - 1)))
x = pc[i]; h += x*31 + x*7 + x*3
h += x*31 + x*7 + x*3;
} }
p->count++; p.count++
// Add to entry count if already present in table. // Add to entry count if already present in table.
b = &p->hash[h%HashSize]; b := &p.hash[h%numBuckets]
for(i=0; i<Assoc; i++) { Assoc:
e = &b->entry[i]; for i := range b.entry {
if(e->depth != n) e := &b.entry[i]
continue; if e.depth != uintptr(len(pc)) {
for(j=0; j<n; j++) continue
if(e->stack[j] != pc[j]) }
goto ContinueAssoc; for j := range pc {
e->count++; if e.stack[j] != pc[j] {
return; continue Assoc
ContinueAssoc:; }
}
e.count++
return
} }
// Evict entry with smallest count. // Evict entry with smallest count.
e = &b->entry[0]; var e *cpuprofEntry
for(i=1; i<Assoc; i++) for i := range b.entry {
if(b->entry[i].count < e->count) if e == nil || b.entry[i].count < e.count {
e = &b->entry[i]; e = &b.entry[i]
if(e->count > 0) { }
if(!evict(p, e)) { }
if e.count > 0 {
if !p.evict(e) {
// Could not evict entry. Record lost stack. // Could not evict entry. Record lost stack.
p->lost++; p.lost++
return; return
} }
p->evicts++; p.evicts++
} }
// Reuse the newly evicted entry. // Reuse the newly evicted entry.
e->depth = n; e.depth = uintptr(len(pc))
e->count = 1; e.count = 1
for(i=0; i<n; i++) for i := range pc {
e->stack[i] = pc[i]; e.stack[i] = pc[i]
}
} }
// evict copies the given entry's data into the log, so that // evict copies the given entry's data into the log, so that
// the entry can be reused. evict is called from add, which // the entry can be reused. evict is called from add, which
// is called from the profiling signal handler, so it must not // is called from the profiling signal handler, so it must not
// allocate memory or block. It is safe to call flushLog. // allocate memory or block. It is safe to call flushlog.
// evict returns true if the entry was copied to the log, // evict returns true if the entry was copied to the log,
// false if there was no room available. // false if there was no room available.
static bool func (p *cpuProfile) evict(e *cpuprofEntry) bool {
evict(Profile *p, Entry *e) d := e.depth
{ nslot := d + 2
int32 i, d, nslot; log := &p.log[p.toggle]
uintptr *log, *q; if p.nlog+nslot > uintptr(len(p.log[0])) {
if !p.flushlog() {
d = e->depth; return false
nslot = d+2; }
log = p->log[p->toggle]; log = &p.log[p.toggle]
if(p->nlog+nslot > nelem(p->log[0])) { }
if(!flushlog(p))
return false; q := p.nlog
log = p->log[p->toggle]; log[q] = e.count
} q++
log[q] = d
q = log+p->nlog; q++
*q++ = e->count; for i := uintptr(0); i < d; i++ {
*q++ = d; log[q] = e.stack[i]
for(i=0; i<d; i++) q++
*q++ = e->stack[i]; }
p->nlog = q - log; p.nlog = q
e->count = 0; e.count = 0
return true; return true
} }
// flushlog tries to flush the current log and switch to the other one. // flushlog tries to flush the current log and switch to the other one.
// flushlog is called from evict, called from add, called from the signal handler, // flushlog is called from evict, called from add, called from the signal handler,
// so it cannot allocate memory or block. It can try to swap logs with // so it cannot allocate memory or block. It can try to swap logs with
// the writing goroutine, as explained in the comment at the top of this file. // the writing goroutine, as explained in the comment at the top of this file.
static bool func (p *cpuProfile) flushlog() bool {
flushlog(Profile *p) if !cas(&p.handoff, 0, uint32(p.nlog)) {
{ return false
uintptr *log, *q; }
notewakeup(&p.wait)
if(!runtime·cas(&p->handoff, 0, p->nlog))
return false; p.toggle = 1 - p.toggle
runtime·notewakeup(&p->wait); log := &p.log[p.toggle]
q := uintptr(0)
p->toggle = 1 - p->toggle; if p.lost > 0 {
log = p->log[p->toggle]; f := lostProfileData
q = log; lostPC := **(**uintptr)(unsafe.Pointer(&f))
if(p->lost > 0) { log[0] = p.lost
*q++ = p->lost; log[1] = 1
*q++ = 1; log[2] = lostPC
*q++ = (uintptr)LostProfileData; q = 3
p->lost = 0; p.lost = 0
} }
p->nlog = q - log; p.nlog = q
return true; return true
} }
// getprofile blocks until the next block of profiling data is available // getprofile blocks until the next block of profiling data is available
// and returns it as a []byte. It is called from the writing goroutine. // and returns it as a []byte. It is called from the writing goroutine.
static Slice func (p *cpuProfile) getprofile() []byte {
getprofile(Profile *p) if p == nil {
{ return nil
uint32 i, j, n; }
Slice ret;
Bucket *b; if p.wholding {
Entry *e;
ret.array = nil;
ret.len = 0;
ret.cap = 0;
if(p == nil)
return ret;
if(p->wholding) {
// Release previous log to signal handling side. // Release previous log to signal handling side.
// Loop because we are racing against SetCPUProfileRate(0). // Loop because we are racing against SetCPUProfileRate(0).
for(;;) { for {
n = p->handoff; n := p.handoff
if(n == 0) { if n == 0 {
runtime·printf("runtime: phase error during cpu profile handoff\n"); print("runtime: phase error during cpu profile handoff\n")
return ret; return nil
} }
if(n & 0x80000000) { if n&0x80000000 != 0 {
p->wtoggle = 1 - p->wtoggle; p.wtoggle = 1 - p.wtoggle
p->wholding = false; p.wholding = false
p->flushing = true; p.flushing = true
goto flush; goto Flush
} }
if(runtime·cas(&p->handoff, n, 0)) if cas(&p.handoff, n, 0) {
break; break
} }
p->wtoggle = 1 - p->wtoggle; }
p->wholding = false; p.wtoggle = 1 - p.wtoggle
p.wholding = false
} }
if(p->flushing) if p.flushing {
goto flush; goto Flush
}
if(!p->on && p->handoff == 0) if !p.on && p.handoff == 0 {
return ret; return nil
}
// Wait for new log. // Wait for new log.
runtime·notetsleepg(&p->wait, -1); notetsleepg(&p.wait, -1)
runtime·noteclear(&p->wait); noteclear(&p.wait)
n = p->handoff; switch n := p.handoff; {
if(n == 0) { case n == 0:
runtime·printf("runtime: phase error during cpu profile wait\n"); print("runtime: phase error during cpu profile wait\n")
return ret; return nil
} case n == 0x80000000:
if(n == 0x80000000) { p.flushing = true
p->flushing = true; goto Flush
goto flush; default:
} n &^= 0x80000000
n &= ~0x80000000;
// Return new log to caller. // Return new log to caller.
p->wholding = true; p.wholding = true
ret.array = (byte*)p->log[p->wtoggle]; return uintptrBytes(p.log[p.wtoggle][:n])
ret.len = n*sizeof(uintptr); }
ret.cap = ret.len;
return ret;
flush:
// In flush mode. // In flush mode.
// Add is no longer being called. We own the log. // Add is no longer being called. We own the log.
// Also, p->handoff is non-zero, so flushlog will return false. // Also, p->handoff is non-zero, so flushlog will return false.
// Evict the hash table into the log and return it. // Evict the hash table into the log and return it.
for(i=0; i<HashSize; i++) { Flush:
b = &p->hash[i]; for i := range p.hash {
for(j=0; j<Assoc; j++) { b := &p.hash[i]
e = &b->entry[j]; for j := range b.entry {
if(e->count > 0 && !evict(p, e)) { e := &b.entry[j]
if e.count > 0 && !p.evict(e) {
// Filled the log. Stop the loop and return what we've got. // Filled the log. Stop the loop and return what we've got.
goto breakflush; break Flush
} }
} }
} }
breakflush:
// Return pending log data. // Return pending log data.
if(p->nlog > 0) { if p.nlog > 0 {
// Note that we're using toggle now, not wtoggle, // Note that we're using toggle now, not wtoggle,
// because we're working on the log directly. // because we're working on the log directly.
ret.array = (byte*)p->log[p->toggle]; n := p.nlog
ret.len = p->nlog*sizeof(uintptr); p.nlog = 0
ret.cap = ret.len; return uintptrBytes(p.log[p.toggle][:n])
p->nlog = 0;
return ret;
} }
// Made it through the table without finding anything to log. // Made it through the table without finding anything to log.
if(!p->eod_sent) { if !p.eodSent {
// We may not have space to append this to the partial log buf, // We may not have space to append this to the partial log buf,
// so we always return a new slice for the end-of-data marker. // so we always return a new slice for the end-of-data marker.
p->eod_sent = true; p.eodSent = true
ret.array = (byte*)eod; return uintptrBytes(eod[:])
ret.len = sizeof eod;
ret.cap = ret.len;
return ret;
} }
// Finally done. Clean up and return nil. // Finally done. Clean up and return nil.
p->flushing = false; p.flushing = false
if(!runtime·cas(&p->handoff, p->handoff, 0)) if !cas(&p.handoff, p.handoff, 0) {
runtime·printf("runtime: profile flush racing with something\n"); print("runtime: profile flush racing with something\n")
return ret; // set to nil at top of function }
return nil
} }
// CPUProfile returns the next cpu profile block as a []byte. func uintptrBytes(p []uintptr) (ret []byte) {
// The user documentation is in debug.go. pp := (*sliceStruct)(unsafe.Pointer(&p))
func CPUProfile() (ret Slice) { rp := (*sliceStruct)(unsafe.Pointer(&ret))
ret = getprofile(prof);
rp.array = pp.array
rp.len = pp.len * int(unsafe.Sizeof(p[0]))
rp.cap = rp.len
return
}
// CPUProfile returns the next chunk of binary CPU profiling stack trace data,
// blocking until data is available. If profiling is turned off and all the profile
// data accumulated while it was on has been returned, CPUProfile returns nil.
// The caller must save the returned data before calling CPUProfile again.
//
// Most clients should use the runtime/pprof package or
// the testing package's -test.cpuprofile flag instead of calling
// CPUProfile directly.
func CPUProfile() []byte {
return cpuprof.getprofile()
} }
...@@ -49,22 +49,3 @@ func NumGoroutine() int { ...@@ -49,22 +49,3 @@ func NumGoroutine() int {
} }
func gcount() int32 func gcount() int32
// CPUProfile returns the next chunk of binary CPU profiling stack trace data,
// blocking until data is available. If profiling is turned off and all the profile
// data accumulated while it was on has been returned, CPUProfile returns nil.
// The caller must save the returned data before calling CPUProfile again.
//
// Most clients should use the runtime/pprof package or
// the testing package's -test.cpuprofile flag instead of calling
// CPUProfile directly.
func CPUProfile() []byte
// SetCPUProfileRate sets the CPU profiling rate to hz samples per second.
// If hz <= 0, SetCPUProfileRate turns off profiling.
// If the profiler is on, the rate cannot be changed without first turning it off.
//
// Most clients should use the runtime/pprof package or
// the testing package's -test.cpuprofile flag instead of calling
// SetCPUProfileRate directly.
func SetCPUProfileRate(hz int)
...@@ -2395,13 +2395,13 @@ runtime·badreflectcall(void) // called from assembly ...@@ -2395,13 +2395,13 @@ runtime·badreflectcall(void) // called from assembly
static struct { static struct {
Mutex lock; Mutex lock;
void (*fn)(uintptr*, int32);
int32 hz; int32 hz;
} prof; } prof;
static void System(void) {} static void System(void) {}
static void ExternalCode(void) {} static void ExternalCode(void) {}
static void GC(void) {} static void GC(void) {}
extern void runtime·cpuproftick(uintptr*, int32);
extern byte runtime·etext[]; extern byte runtime·etext[];
// Called if we receive a SIGPROF signal. // Called if we receive a SIGPROF signal.
...@@ -2418,7 +2418,7 @@ runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp) ...@@ -2418,7 +2418,7 @@ runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp)
m = 0; m = 0;
USED(m); USED(m);
if(prof.fn == nil || prof.hz == 0) if(prof.hz == 0)
return; return;
// Profiling runs concurrently with GC, so it must not allocate. // Profiling runs concurrently with GC, so it must not allocate.
...@@ -2537,10 +2537,10 @@ runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp) ...@@ -2537,10 +2537,10 @@ runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp)
} }
} }
if(prof.fn != nil) { if(prof.hz != 0) {
runtime·lock(&prof.lock); runtime·lock(&prof.lock);
if(prof.fn != nil) if(prof.hz != 0)
prof.fn(stk, n); runtime·cpuproftick(stk, n);
runtime·unlock(&prof.lock); runtime·unlock(&prof.lock);
} }
mp->mallocing--; mp->mallocing--;
...@@ -2548,15 +2548,11 @@ runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp) ...@@ -2548,15 +2548,11 @@ runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp)
// Arrange to call fn with a traceback hz times a second. // Arrange to call fn with a traceback hz times a second.
void void
runtime·setcpuprofilerate(void (*fn)(uintptr*, int32), int32 hz) runtime·setcpuprofilerate(int32 hz)
{ {
// Force sane arguments. // Force sane arguments.
if(hz < 0) if(hz < 0)
hz = 0; hz = 0;
if(hz == 0)
fn = nil;
if(fn == nil)
hz = 0;
// Disable preemption, otherwise we can be rescheduled to another thread // Disable preemption, otherwise we can be rescheduled to another thread
// that has profiling enabled. // that has profiling enabled.
...@@ -2568,7 +2564,6 @@ runtime·setcpuprofilerate(void (*fn)(uintptr*, int32), int32 hz) ...@@ -2568,7 +2564,6 @@ runtime·setcpuprofilerate(void (*fn)(uintptr*, int32), int32 hz)
runtime·resetcpuprofiler(0); runtime·resetcpuprofiler(0);
runtime·lock(&prof.lock); runtime·lock(&prof.lock);
prof.fn = fn;
prof.hz = hz; prof.hz = hz;
runtime·unlock(&prof.lock); runtime·unlock(&prof.lock);
runtime·lock(&runtime·sched.lock); runtime·lock(&runtime·sched.lock);
......
...@@ -864,7 +864,7 @@ void runtime·freezetheworld(void); ...@@ -864,7 +864,7 @@ void runtime·freezetheworld(void);
void runtime·unwindstack(G*, byte*); void runtime·unwindstack(G*, byte*);
void runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp); void runtime·sigprof(uint8 *pc, uint8 *sp, uint8 *lr, G *gp, M *mp);
void runtime·resetcpuprofiler(int32); void runtime·resetcpuprofiler(int32);
void runtime·setcpuprofilerate(void(*)(uintptr*, int32), int32); void runtime·setcpuprofilerate(int32);
void runtime·usleep(uint32); void runtime·usleep(uint32);
int64 runtime·cputicks(void); int64 runtime·cputicks(void);
int64 runtime·tickspersecond(void); int64 runtime·tickspersecond(void);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment