github.com/prattmic/llgo-embedded@v0.0.0-20150820070356-41cfecea0e1e/third_party/gofrontend/libgo/go/runtime/pprof/pprof_test.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 // +build !nacl 6 7 package pprof_test 8 9 import ( 10 "bytes" 11 "fmt" 12 "math/big" 13 "os/exec" 14 "regexp" 15 "runtime" 16 . "runtime/pprof" 17 "strings" 18 "sync" 19 "testing" 20 "time" 21 "unsafe" 22 ) 23 24 func cpuHogger(f func()) { 25 // We only need to get one 100 Hz clock tick, so we've got 26 // a 25x safety buffer. 27 // But do at least 500 iterations (which should take about 100ms), 28 // otherwise TestCPUProfileMultithreaded can fail if only one 29 // thread is scheduled during the 250ms period. 30 t0 := time.Now() 31 for i := 0; i < 500 || time.Since(t0) < 250*time.Millisecond; i++ { 32 f() 33 } 34 } 35 36 var ( 37 salt1 = 0 38 salt2 = 0 39 ) 40 41 // The actual CPU hogging function. 42 // Must not call other functions nor access heap/globals in the loop, 43 // otherwise under race detector the samples will be in the race runtime. 44 func cpuHog1() { 45 foo := salt1 46 for i := 0; i < 1e5; i++ { 47 if foo > 0 { 48 foo *= foo 49 } else { 50 foo *= foo + 1 51 } 52 } 53 salt1 = foo 54 } 55 56 func cpuHog2() { 57 foo := salt2 58 for i := 0; i < 1e5; i++ { 59 if foo > 0 { 60 foo *= foo 61 } else { 62 foo *= foo + 2 63 } 64 } 65 salt2 = foo 66 } 67 68 func TestCPUProfile(t *testing.T) { 69 testCPUProfile(t, []string{"pprof_test.cpuHog1"}, func() { 70 cpuHogger(cpuHog1) 71 }) 72 } 73 74 func TestCPUProfileMultithreaded(t *testing.T) { 75 defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(2)) 76 testCPUProfile(t, []string{"pprof_test.cpuHog1", "pprof_test.cpuHog2"}, func() { 77 c := make(chan int) 78 go func() { 79 cpuHogger(cpuHog1) 80 c <- 1 81 }() 82 cpuHogger(cpuHog2) 83 <-c 84 }) 85 } 86 87 func parseProfile(t *testing.T, bytes []byte, f func(uintptr, []uintptr)) { 88 // Convert []byte to []uintptr. 89 l := len(bytes) / int(unsafe.Sizeof(uintptr(0))) 90 val := *(*[]uintptr)(unsafe.Pointer(&bytes)) 91 val = val[:l] 92 93 // 5 for the header, 2 for the per-sample header on at least one sample, 3 for the trailer. 94 if l < 5+2+3 { 95 t.Logf("profile too short: %#x", val) 96 if badOS[runtime.GOOS] { 97 t.Skipf("ignoring failure on %s; see golang.org/issue/6047", runtime.GOOS) 98 return 99 } 100 t.FailNow() 101 } 102 103 hd, val, tl := val[:5], val[5:l-3], val[l-3:] 104 if hd[0] != 0 || hd[1] != 3 || hd[2] != 0 || hd[3] != 1e6/100 || hd[4] != 0 { 105 t.Fatalf("unexpected header %#x", hd) 106 } 107 108 if tl[0] != 0 || tl[1] != 1 || tl[2] != 0 { 109 t.Fatalf("malformed end-of-data marker %#x", tl) 110 } 111 112 for len(val) > 0 { 113 if len(val) < 2 || val[0] < 1 || val[1] < 1 || uintptr(len(val)) < 2+val[1] { 114 t.Fatalf("malformed profile. leftover: %#x", val) 115 } 116 f(val[0], val[2:2+val[1]]) 117 val = val[2+val[1]:] 118 } 119 } 120 121 func testCPUProfile(t *testing.T, need []string, f func()) { 122 switch runtime.GOOS { 123 case "darwin": 124 out, err := exec.Command("uname", "-a").CombinedOutput() 125 if err != nil { 126 t.Fatal(err) 127 } 128 vers := string(out) 129 t.Logf("uname -a: %v", vers) 130 case "plan9": 131 // unimplemented 132 return 133 } 134 135 var prof bytes.Buffer 136 if err := StartCPUProfile(&prof); err != nil { 137 t.Fatal(err) 138 } 139 f() 140 StopCPUProfile() 141 142 // Check that profile is well formed and contains need. 143 have := make([]uintptr, len(need)) 144 parseProfile(t, prof.Bytes(), func(count uintptr, stk []uintptr) { 145 for _, pc := range stk { 146 f := runtime.FuncForPC(pc) 147 if f == nil { 148 continue 149 } 150 t.Log(f.Name(), count) 151 for i, name := range need { 152 if strings.Contains(f.Name(), name) { 153 have[i] += count 154 } 155 } 156 } 157 }) 158 159 if len(need) == 0 { 160 return 161 } 162 163 var total uintptr 164 for i, name := range need { 165 total += have[i] 166 t.Logf("%s: %d\n", name, have[i]) 167 } 168 ok := true 169 if total == 0 { 170 t.Logf("no CPU profile samples collected") 171 ok = false 172 } 173 // We'd like to check a reasonable minimum, like 174 // total / len(have) / smallconstant, but this test is 175 // pretty flaky (see bug 7095). So we'll just test to 176 // make sure we got at least one sample. 177 min := uintptr(1) 178 for i, name := range need { 179 if have[i] < min { 180 t.Logf("%s has %d samples out of %d, want at least %d, ideally %d", name, have[i], total, min, total/uintptr(len(have))) 181 ok = false 182 } 183 } 184 185 if !ok { 186 if badOS[runtime.GOOS] { 187 t.Skipf("ignoring failure on %s; see golang.org/issue/6047", runtime.GOOS) 188 return 189 } 190 t.FailNow() 191 } 192 } 193 194 func TestCPUProfileWithFork(t *testing.T) { 195 // Fork can hang if preempted with signals frequently enough (see issue 5517). 196 // Ensure that we do not do this. 197 heap := 1 << 30 198 if testing.Short() { 199 heap = 100 << 20 200 } 201 // This makes fork slower. 202 garbage := make([]byte, heap) 203 // Need to touch the slice, otherwise it won't be paged in. 204 done := make(chan bool) 205 go func() { 206 for i := range garbage { 207 garbage[i] = 42 208 } 209 done <- true 210 }() 211 <-done 212 213 var prof bytes.Buffer 214 if err := StartCPUProfile(&prof); err != nil { 215 t.Fatal(err) 216 } 217 defer StopCPUProfile() 218 219 for i := 0; i < 10; i++ { 220 exec.Command("go").CombinedOutput() 221 } 222 } 223 224 // Test that profiler does not observe runtime.gogo as "user" goroutine execution. 225 // If it did, it would see inconsistent state and would either record an incorrect stack 226 // or crash because the stack was malformed. 227 func TestGoroutineSwitch(t *testing.T) { 228 // How much to try. These defaults take about 1 seconds 229 // on a 2012 MacBook Pro. The ones in short mode take 230 // about 0.1 seconds. 231 tries := 10 232 count := 1000000 233 if testing.Short() { 234 tries = 1 235 } 236 for try := 0; try < tries; try++ { 237 var prof bytes.Buffer 238 if err := StartCPUProfile(&prof); err != nil { 239 t.Fatal(err) 240 } 241 for i := 0; i < count; i++ { 242 runtime.Gosched() 243 } 244 StopCPUProfile() 245 246 // Read profile to look for entries for runtime.gogo with an attempt at a traceback. 247 // The special entry 248 parseProfile(t, prof.Bytes(), func(count uintptr, stk []uintptr) { 249 // An entry with two frames with 'System' in its top frame 250 // exists to record a PC without a traceback. Those are okay. 251 if len(stk) == 2 { 252 f := runtime.FuncForPC(stk[1]) 253 if f != nil && (f.Name() == "System" || f.Name() == "ExternalCode" || f.Name() == "GC") { 254 return 255 } 256 } 257 258 // Otherwise, should not see runtime.gogo. 259 // The place we'd see it would be the inner most frame. 260 f := runtime.FuncForPC(stk[0]) 261 if f != nil && f.Name() == "runtime.gogo" { 262 var buf bytes.Buffer 263 for _, pc := range stk { 264 f := runtime.FuncForPC(pc) 265 if f == nil { 266 fmt.Fprintf(&buf, "%#x ?:0\n", pc) 267 } else { 268 file, line := f.FileLine(pc) 269 fmt.Fprintf(&buf, "%#x %s:%d\n", pc, file, line) 270 } 271 } 272 t.Fatalf("found profile entry for runtime.gogo:\n%s", buf.String()) 273 } 274 }) 275 } 276 } 277 278 // Test that profiling of division operations is okay, especially on ARM. See issue 6681. 279 func TestMathBigDivide(t *testing.T) { 280 testCPUProfile(t, nil, func() { 281 t := time.After(5 * time.Second) 282 pi := new(big.Int) 283 for { 284 for i := 0; i < 100; i++ { 285 n := big.NewInt(2646693125139304345) 286 d := big.NewInt(842468587426513207) 287 pi.Div(n, d) 288 } 289 select { 290 case <-t: 291 return 292 default: 293 } 294 } 295 }) 296 } 297 298 // Operating systems that are expected to fail the tests. See issue 6047. 299 var badOS = map[string]bool{ 300 "darwin": true, 301 "netbsd": true, 302 "plan9": true, 303 } 304 305 func TestBlockProfile(t *testing.T) { 306 t.Skip("lots of details are different for gccgo; FIXME") 307 type TestCase struct { 308 name string 309 f func() 310 re string 311 } 312 tests := [...]TestCase{ 313 {"chan recv", blockChanRecv, ` 314 [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]+ 315 # 0x[0-9,a-f]+ runtime\.chanrecv1\+0x[0-9,a-f]+ .*/src/runtime/chan.go:[0-9]+ 316 # 0x[0-9,a-f]+ runtime/pprof_test\.blockChanRecv\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 317 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 318 `}, 319 {"chan send", blockChanSend, ` 320 [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]+ 321 # 0x[0-9,a-f]+ runtime\.chansend1\+0x[0-9,a-f]+ .*/src/runtime/chan.go:[0-9]+ 322 # 0x[0-9,a-f]+ runtime/pprof_test\.blockChanSend\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 323 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 324 `}, 325 {"chan close", blockChanClose, ` 326 [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]+ 327 # 0x[0-9,a-f]+ runtime\.chanrecv1\+0x[0-9,a-f]+ .*/src/runtime/chan.go:[0-9]+ 328 # 0x[0-9,a-f]+ runtime/pprof_test\.blockChanClose\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 329 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 330 `}, 331 {"select recv async", blockSelectRecvAsync, ` 332 [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]+ 333 # 0x[0-9,a-f]+ runtime\.selectgo\+0x[0-9,a-f]+ .*/src/runtime/select.go:[0-9]+ 334 # 0x[0-9,a-f]+ runtime/pprof_test\.blockSelectRecvAsync\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 335 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 336 `}, 337 {"select send sync", blockSelectSendSync, ` 338 [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]+ 339 # 0x[0-9,a-f]+ runtime\.selectgo\+0x[0-9,a-f]+ .*/src/runtime/select.go:[0-9]+ 340 # 0x[0-9,a-f]+ runtime/pprof_test\.blockSelectSendSync\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 341 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 342 `}, 343 {"mutex", blockMutex, ` 344 [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]+ 345 # 0x[0-9,a-f]+ sync\.\(\*Mutex\)\.Lock\+0x[0-9,a-f]+ .*/src/sync/mutex\.go:[0-9]+ 346 # 0x[0-9,a-f]+ runtime/pprof_test\.blockMutex\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 347 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 348 `}, 349 {"cond", blockCond, ` 350 [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]+ 351 # 0x[0-9,a-f]+ sync\.\(\*Cond\)\.Wait\+0x[0-9,a-f]+ .*/src/sync/cond\.go:[0-9]+ 352 # 0x[0-9,a-f]+ runtime/pprof_test\.blockCond\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 353 # 0x[0-9,a-f]+ runtime/pprof_test\.TestBlockProfile\+0x[0-9,a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 354 `}, 355 } 356 357 runtime.SetBlockProfileRate(1) 358 defer runtime.SetBlockProfileRate(0) 359 for _, test := range tests { 360 test.f() 361 } 362 var w bytes.Buffer 363 Lookup("block").WriteTo(&w, 1) 364 prof := w.String() 365 366 if !strings.HasPrefix(prof, "--- contention:\ncycles/second=") { 367 t.Fatalf("Bad profile header:\n%v", prof) 368 } 369 370 for _, test := range tests { 371 if !regexp.MustCompile(test.re).MatchString(prof) { 372 t.Fatalf("Bad %v entry, expect:\n%v\ngot:\n%v", test.name, test.re, prof) 373 } 374 } 375 } 376 377 const blockDelay = 10 * time.Millisecond 378 379 func blockChanRecv() { 380 c := make(chan bool) 381 go func() { 382 time.Sleep(blockDelay) 383 c <- true 384 }() 385 <-c 386 } 387 388 func blockChanSend() { 389 c := make(chan bool) 390 go func() { 391 time.Sleep(blockDelay) 392 <-c 393 }() 394 c <- true 395 } 396 397 func blockChanClose() { 398 c := make(chan bool) 399 go func() { 400 time.Sleep(blockDelay) 401 close(c) 402 }() 403 <-c 404 } 405 406 func blockSelectRecvAsync() { 407 c := make(chan bool, 1) 408 c2 := make(chan bool, 1) 409 go func() { 410 time.Sleep(blockDelay) 411 c <- true 412 }() 413 select { 414 case <-c: 415 case <-c2: 416 } 417 } 418 419 func blockSelectSendSync() { 420 c := make(chan bool) 421 c2 := make(chan bool) 422 go func() { 423 time.Sleep(blockDelay) 424 <-c 425 }() 426 select { 427 case c <- true: 428 case c2 <- true: 429 } 430 } 431 432 func blockMutex() { 433 var mu sync.Mutex 434 mu.Lock() 435 go func() { 436 time.Sleep(blockDelay) 437 mu.Unlock() 438 }() 439 mu.Lock() 440 } 441 442 func blockCond() { 443 var mu sync.Mutex 444 c := sync.NewCond(&mu) 445 mu.Lock() 446 go func() { 447 time.Sleep(blockDelay) 448 mu.Lock() 449 c.Signal() 450 mu.Unlock() 451 }() 452 c.Wait() 453 mu.Unlock() 454 }