summaryrefslogtreecommitdiff
path: root/libgo/go/runtime/pprof/pprof_test.go
diff options
context:
space:
mode:
Diffstat (limited to 'libgo/go/runtime/pprof/pprof_test.go')
-rw-r--r--libgo/go/runtime/pprof/pprof_test.go363
1 files changed, 323 insertions, 40 deletions
diff --git a/libgo/go/runtime/pprof/pprof_test.go b/libgo/go/runtime/pprof/pprof_test.go
index 5762e17d36d..bdbbf42f028 100644
--- a/libgo/go/runtime/pprof/pprof_test.go
+++ b/libgo/go/runtime/pprof/pprof_test.go
@@ -9,57 +9,66 @@ import (
"fmt"
"hash/crc32"
"os/exec"
+ "regexp"
"runtime"
. "runtime/pprof"
"strings"
+ "sync"
"testing"
+ "time"
"unsafe"
)
func TestCPUProfile(t *testing.T) {
- switch runtime.GOOS {
- case "darwin":
- out, err := exec.Command("uname", "-a").CombinedOutput()
- if err != nil {
- t.Fatal(err)
- }
- vers := string(out)
- t.Logf("uname -a: %v", vers)
- // Lion uses "Darwin Kernel Version 11".
- if strings.Contains(vers, "Darwin Kernel Version 10") && strings.Contains(vers, "RELEASE_X86_64") {
- t.Skip("skipping test on known-broken kernel (64-bit Leopard / Snow Leopard)")
+ buf := make([]byte, 100000)
+ testCPUProfile(t, []string{"crc32.update"}, func() {
+ // This loop takes about a quarter second on a 2 GHz laptop.
+ // We only need to get one 100 Hz clock tick, so we've got
+ // a 25x safety buffer.
+ for i := 0; i < 1000; i++ {
+ crc32.ChecksumIEEE(buf)
}
- case "plan9":
- // unimplemented
- return
- }
+ })
+}
+func TestCPUProfileMultithreaded(t *testing.T) {
buf := make([]byte, 100000)
- var prof bytes.Buffer
- if err := StartCPUProfile(&prof); err != nil {
- t.Fatal(err)
- }
- // This loop takes about a quarter second on a 2 GHz laptop.
- // We only need to get one 100 Hz clock tick, so we've got
- // a 25x safety buffer.
- for i := 0; i < 1000; i++ {
- crc32.ChecksumIEEE(buf)
- }
- StopCPUProfile()
+ defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(2))
+ testCPUProfile(t, []string{"crc32.update"}, func() {
+ c := make(chan int)
+ go func() {
+ for i := 0; i < 2000; i++ {
+ crc32.Update(0, crc32.IEEETable, buf)
+ }
+ c <- 1
+ }()
+ // This loop takes about a quarter second on a 2 GHz laptop.
+ // We only need to get one 100 Hz clock tick, so we've got
+ // a 25x safety buffer.
+ for i := 0; i < 2000; i++ {
+ crc32.ChecksumIEEE(buf)
+ }
+ <-c
+ })
+}
+func parseProfile(t *testing.T, bytes []byte, f func(uintptr, []uintptr)) {
// Convert []byte to []uintptr.
- bytes := prof.Bytes()
l := len(bytes) / int(unsafe.Sizeof(uintptr(0)))
val := *(*[]uintptr)(unsafe.Pointer(&bytes))
val = val[:l]
- if l < 13 {
- t.Fatalf("profile too short: %#x", val)
+ // 5 for the header, 2 for the per-sample header on at least one sample, 3 for the trailer.
+ if l < 5+2+3 {
+ t.Logf("profile too short: %#x", val)
+ if badOS[runtime.GOOS] {
+ t.Skipf("ignoring failure on %s; see golang.org/issue/6047", runtime.GOOS)
+ return
+ }
+ t.FailNow()
}
- fmt.Println(val, l)
hd, val, tl := val[:5], val[5:l-3], val[l-3:]
- fmt.Println(hd, val, tl)
if hd[0] != 0 || hd[1] != 3 || hd[2] != 0 || hd[3] != 1e6/100 || hd[4] != 0 {
t.Fatalf("unexpected header %#x", hd)
}
@@ -68,26 +77,300 @@ func TestCPUProfile(t *testing.T) {
t.Fatalf("malformed end-of-data marker %#x", tl)
}
- // Check that profile is well formed and contains ChecksumIEEE.
- found := false
for len(val) > 0 {
if len(val) < 2 || val[0] < 1 || val[1] < 1 || uintptr(len(val)) < 2+val[1] {
t.Fatalf("malformed profile. leftover: %#x", val)
}
- for _, pc := range val[2 : 2+val[1]] {
+ f(val[0], val[2:2+val[1]])
+ val = val[2+val[1]:]
+ }
+}
+
+func testCPUProfile(t *testing.T, need []string, f func()) {
+ switch runtime.GOOS {
+ case "darwin":
+ out, err := exec.Command("uname", "-a").CombinedOutput()
+ if err != nil {
+ t.Fatal(err)
+ }
+ vers := string(out)
+ t.Logf("uname -a: %v", vers)
+ case "plan9":
+ // unimplemented
+ return
+ }
+
+ var prof bytes.Buffer
+ if err := StartCPUProfile(&prof); err != nil {
+ t.Fatal(err)
+ }
+ f()
+ StopCPUProfile()
+
+ // Check that profile is well formed and contains ChecksumIEEE.
+ have := make([]uintptr, len(need))
+ parseProfile(t, prof.Bytes(), func(count uintptr, stk []uintptr) {
+ for _, pc := range stk {
f := runtime.FuncForPC(pc)
if f == nil {
continue
}
- if strings.Contains(f.Name(), "ChecksumIEEE") ||
- (strings.Contains(f.Name(), "update") && strings.Contains(f.Name(), "crc32")) {
- found = true
+ for i, name := range need {
+ if strings.Contains(f.Name(), name) {
+ have[i] += count
+ }
}
}
- val = val[2+val[1]:]
+ })
+
+ var total uintptr
+ for i, name := range need {
+ total += have[i]
+ t.Logf("%s: %d\n", name, have[i])
+ }
+ ok := true
+ if total == 0 {
+ t.Logf("no CPU profile samples collected")
+ ok = false
+ }
+ min := total / uintptr(len(have)) / 3
+ for i, name := range need {
+ if have[i] < min {
+ t.Logf("%s has %d samples out of %d, want at least %d, ideally %d", name, have[i], total, min, total/uintptr(len(have)))
+ ok = false
+ }
+ }
+
+ if !ok {
+ if badOS[runtime.GOOS] {
+ t.Skipf("ignoring failure on %s; see golang.org/issue/6047", runtime.GOOS)
+ return
+ }
+ t.FailNow()
+ }
+}
+
+func TestCPUProfileWithFork(t *testing.T) {
+ // Fork can hang if preempted with signals frequently enough (see issue 5517).
+ // Ensure that we do not do this.
+ heap := 1 << 30
+ if testing.Short() {
+ heap = 100 << 20
}
+ // This makes fork slower.
+ garbage := make([]byte, heap)
+ // Need to touch the slice, otherwise it won't be paged in.
+ done := make(chan bool)
+ go func() {
+ for i := range garbage {
+ garbage[i] = 42
+ }
+ done <- true
+ }()
+ <-done
- if !found {
- t.Fatal("did not find ChecksumIEEE in the profile")
+ var prof bytes.Buffer
+ if err := StartCPUProfile(&prof); err != nil {
+ t.Fatal(err)
}
+ defer StopCPUProfile()
+
+ for i := 0; i < 10; i++ {
+ exec.Command("go").CombinedOutput()
+ }
+}
+
+// Test that profiler does not observe runtime.gogo as "user" goroutine execution.
+// If it did, it would see inconsistent state and would either record an incorrect stack
+// or crash because the stack was malformed.
+func TestGoroutineSwitch(t *testing.T) {
+ if runtime.GOOS == "windows" {
+ t.Skip("flaky test; see http://golang.org/issue/6417")
+ }
+ // How much to try. These defaults take about 1 seconds
+ // on a 2012 MacBook Pro. The ones in short mode take
+ // about 0.1 seconds.
+ tries := 10
+ count := 1000000
+ if testing.Short() {
+ tries = 1
+ }
+ for try := 0; try < tries; try++ {
+ var prof bytes.Buffer
+ if err := StartCPUProfile(&prof); err != nil {
+ t.Fatal(err)
+ }
+ for i := 0; i < count; i++ {
+ runtime.Gosched()
+ }
+ StopCPUProfile()
+
+ // Read profile to look for entries for runtime.gogo with an attempt at a traceback.
+ // The special entry
+ parseProfile(t, prof.Bytes(), func(count uintptr, stk []uintptr) {
+ // An entry with two frames with 'System' in its top frame
+ // exists to record a PC without a traceback. Those are okay.
+ if len(stk) == 2 {
+ f := runtime.FuncForPC(stk[1])
+ if f != nil && f.Name() == "System" {
+ return
+ }
+ }
+
+ // Otherwise, should not see runtime.gogo.
+ // The place we'd see it would be the inner most frame.
+ f := runtime.FuncForPC(stk[0])
+ if f != nil && f.Name() == "runtime.gogo" {
+ var buf bytes.Buffer
+ for _, pc := range stk {
+ f := runtime.FuncForPC(pc)
+ if f == nil {
+ fmt.Fprintf(&buf, "%#x ?:0\n", pc)
+ } else {
+ file, line := f.FileLine(pc)
+ fmt.Fprintf(&buf, "%#x %s:%d\n", pc, file, line)
+ }
+ }
+ t.Fatalf("found profile entry for runtime.gogo:\n%s", buf.String())
+ }
+ })
+ }
+}
+
+// Operating systems that are expected to fail the tests. See issue 6047.
+var badOS = map[string]bool{
+ "darwin": true,
+ "netbsd": true,
+ "openbsd": true,
+}
+
+func TestBlockProfile(t *testing.T) {
+ t.Skip("lots of details are different for gccgo; FIXME")
+ type TestCase struct {
+ name string
+ f func()
+ re string
+ }
+ tests := [...]TestCase{
+ {"chan recv", blockChanRecv, `
+[0-9]+ [0-9]+ @ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+
+# 0x[0-9,a-f]+ runtime\.chanrecv1\+0x[0-9,a-f]+ .*/src/pkg/runtime/chan.c:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.blockChanRecv\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+`},
+ {"chan send", blockChanSend, `
+[0-9]+ [0-9]+ @ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+
+# 0x[0-9,a-f]+ runtime\.chansend1\+0x[0-9,a-f]+ .*/src/pkg/runtime/chan.c:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.blockChanSend\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+`},
+ {"chan close", blockChanClose, `
+[0-9]+ [0-9]+ @ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+
+# 0x[0-9,a-f]+ runtime\.chanrecv1\+0x[0-9,a-f]+ .*/src/pkg/runtime/chan.c:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.blockChanClose\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+`},
+ {"select recv async", blockSelectRecvAsync, `
+[0-9]+ [0-9]+ @ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+
+# 0x[0-9,a-f]+ runtime\.selectgo\+0x[0-9,a-f]+ .*/src/pkg/runtime/chan.c:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.blockSelectRecvAsync\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+`},
+ {"select send sync", blockSelectSendSync, `
+[0-9]+ [0-9]+ @ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+
+# 0x[0-9,a-f]+ runtime\.selectgo\+0x[0-9,a-f]+ .*/src/pkg/runtime/chan.c:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.blockSelectSendSync\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+`},
+ {"mutex", blockMutex, `
+[0-9]+ [0-9]+ @ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+ 0x[0-9,a-f]+
+# 0x[0-9,a-f]+ sync\.\(\*Mutex\)\.Lock\+0x[0-9,a-f]+ .*/src/pkg/sync/mutex\.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.blockMutex\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+# 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/pkg/runtime/pprof/pprof_test.go:[0-9]+
+`},
+ }
+
+ runtime.SetBlockProfileRate(1)
+ defer runtime.SetBlockProfileRate(0)
+ for _, test := range tests {
+ test.f()
+ }
+ var w bytes.Buffer
+ Lookup("block").WriteTo(&w, 1)
+ prof := w.String()
+
+ if !strings.HasPrefix(prof, "--- contention:\ncycles/second=") {
+ t.Fatalf("Bad profile header:\n%v", prof)
+ }
+
+ for _, test := range tests {
+ if !regexp.MustCompile(test.re).MatchString(prof) {
+ t.Fatalf("Bad %v entry, expect:\n%v\ngot:\n%v", test.name, test.re, prof)
+ }
+ }
+}
+
+const blockDelay = 10 * time.Millisecond
+
+func blockChanRecv() {
+ c := make(chan bool)
+ go func() {
+ time.Sleep(blockDelay)
+ c <- true
+ }()
+ <-c
+}
+
+func blockChanSend() {
+ c := make(chan bool)
+ go func() {
+ time.Sleep(blockDelay)
+ <-c
+ }()
+ c <- true
+}
+
+func blockChanClose() {
+ c := make(chan bool)
+ go func() {
+ time.Sleep(blockDelay)
+ close(c)
+ }()
+ <-c
+}
+
+func blockSelectRecvAsync() {
+ c := make(chan bool, 1)
+ c2 := make(chan bool, 1)
+ go func() {
+ time.Sleep(blockDelay)
+ c <- true
+ }()
+ select {
+ case <-c:
+ case <-c2:
+ }
+}
+
+func blockSelectSendSync() {
+ c := make(chan bool)
+ c2 := make(chan bool)
+ go func() {
+ time.Sleep(blockDelay)
+ <-c
+ }()
+ select {
+ case c <- true:
+ case c2 <- true:
+ }
+}
+
+func blockMutex() {
+ var mu sync.Mutex
+ mu.Lock()
+ go func() {
+ time.Sleep(blockDelay)
+ mu.Unlock()
+ }()
+ mu.Lock()
}
View Lorry Controller Status