libgo/go/runtime/debuglog_test.go

   1 // Copyright 2019 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 // TODO(austin): All of these tests are skipped if the debuglog build
   6 // tag isn't provided. That means we basically never test debuglog.
   7 // There are two potential ways around this:
   8 //
   9 // 1. Make these tests re-build the runtime test with the debuglog
  10 // build tag and re-invoke themselves.
  11 //
  12 // 2. Always build the whole debuglog infrastructure and depend on
  13 // linker dead-code elimination to drop it. This is easy for dlog()
  14 // since there won't be any calls to it. For printDebugLog, we can
  15 // make panic call a wrapper that is call printDebugLog if the
  16 // debuglog build tag is set, or otherwise do nothing. Then tests
  17 // could call printDebugLog directly. This is the right answer in
  18 // principle, but currently our linker reads in all symbols
  19 // regardless, so this would slow down and bloat all links. If the
  20 // linker gets more efficient about this, we should revisit this
  21 // approach.
  22
  23 package runtime_test
  24
  25 import (
  26         "bytes"
  27         "fmt"
  28         "regexp"
  29         "runtime"
  30         "strings"
  31         "sync"
  32         "sync/atomic"
  33         "testing"
  34 )
  35
  36 func skipDebugLog(t *testing.T) {
  37         if !runtime.DlogEnabled {
  38                 t.Skip("debug log disabled (rebuild with -tags debuglog)")
  39         }
  40 }
  41
  42 func dlogCanonicalize(x string) string {
  43         begin := regexp.MustCompile(`(?m)^>> begin log \d+ <<\n`)
  44         x = begin.ReplaceAllString(x, "")
  45         prefix := regexp.MustCompile(`(?m)^\[[^]]+\]`)
  46         x = prefix.ReplaceAllString(x, "[]")
  47         return x
  48 }
  49
  50 func TestDebugLog(t *testing.T) {
  51         skipDebugLog(t)
  52         runtime.ResetDebugLog()
  53         runtime.Dlog().S("testing").End()
  54         got := dlogCanonicalize(runtime.DumpDebugLog())
  55         if want := "[] testing\n"; got != want {
  56                 t.Fatalf("want %q, got %q", want, got)
  57         }
  58 }
  59
  60 func TestDebugLogTypes(t *testing.T) {
  61         skipDebugLog(t)
  62         runtime.ResetDebugLog()
  63         var varString = strings.Repeat("a", 4)
  64         runtime.Dlog().B(true).B(false).I(-42).I16(0x7fff).U64(^uint64(0)).Hex(0xfff).P(nil).S(varString).S("const string").End()
  65         got := dlogCanonicalize(runtime.DumpDebugLog())
  66         if want := "[] true false -42 32767 18446744073709551615 0xfff 0x0 aaaa const string\n"; got != want {
  67                 t.Fatalf("want %q, got %q", want, got)
  68         }
  69 }
  70
  71 func TestDebugLogSym(t *testing.T) {
  72         skipDebugLog(t)
  73         runtime.ResetDebugLog()
  74         pc, _, _, _ := runtime.Caller(0)
  75         runtime.Dlog().PC(pc).End()
  76         got := dlogCanonicalize(runtime.DumpDebugLog())
  77         want := regexp.MustCompile(`\[\] 0x[0-9a-f]+ \[runtime_test\.TestDebugLogSym\+0x[0-9a-f]+ .*/debuglog_test\.go:[0-9]+\]\n`)
  78         if !want.MatchString(got) {
  79                 t.Fatalf("want matching %s, got %q", want, got)
  80         }
  81 }
  82
  83 func TestDebugLogInterleaving(t *testing.T) {
  84         skipDebugLog(t)
  85         runtime.ResetDebugLog()
  86         var wg sync.WaitGroup
  87         done := int32(0)
  88         wg.Add(1)
  89         go func() {
  90                 // Encourage main goroutine to move around to
  91                 // different Ms and Ps.
  92                 for atomic.LoadInt32(&done) == 0 {
  93                         runtime.Gosched()
  94                 }
  95                 wg.Done()
  96         }()
  97         var want bytes.Buffer
  98         for i := 0; i < 1000; i++ {
  99                 runtime.Dlog().I(i).End()
 100                 fmt.Fprintf(&want, "[] %d\n", i)
 101                 runtime.Gosched()
 102         }
 103         atomic.StoreInt32(&done, 1)
 104         wg.Wait()
 105
 106         gotFull := runtime.DumpDebugLog()
 107         got := dlogCanonicalize(gotFull)
 108         if got != want.String() {
 109                 // Since the timestamps are useful in understand
 110                 // failures of this test, we print the uncanonicalized
 111                 // output.
 112                 t.Fatalf("want %q, got (uncanonicalized) %q", want.String(), gotFull)
 113         }
 114 }
 115
 116 func TestDebugLogWraparound(t *testing.T) {
 117         skipDebugLog(t)
 118
 119         // Make sure we don't switch logs so it's easier to fill one up.
 120         runtime.LockOSThread()
 121         defer runtime.UnlockOSThread()
 122
 123         runtime.ResetDebugLog()
 124         var longString = strings.Repeat("a", 128)
 125         var want bytes.Buffer
 126         for i, j := 0, 0; j < 2*runtime.DebugLogBytes; i, j = i+1, j+len(longString) {
 127                 runtime.Dlog().I(i).S(longString).End()
 128                 fmt.Fprintf(&want, "[] %d %s\n", i, longString)
 129         }
 130         log := runtime.DumpDebugLog()
 131
 132         // Check for "lost" message.
 133         lost := regexp.MustCompile(`^>> begin log \d+; lost first \d+KB <<\n`)
 134         if !lost.MatchString(log) {
 135                 t.Fatalf("want matching %s, got %q", lost, log)
 136         }
 137         idx := lost.FindStringIndex(log)
 138         // Strip lost message.
 139         log = dlogCanonicalize(log[idx[1]:])
 140
 141         // Check log.
 142         if !strings.HasSuffix(want.String(), log) {
 143                 t.Fatalf("wrong suffix:\n%s", log)
 144         }
 145 }
 146
 147 func TestDebugLogLongString(t *testing.T) {
 148         skipDebugLog(t)
 149
 150         runtime.ResetDebugLog()
 151         var longString = strings.Repeat("a", runtime.DebugLogStringLimit+1)
 152         runtime.Dlog().S(longString).End()
 153         got := dlogCanonicalize(runtime.DumpDebugLog())
 154         want := "[] " + strings.Repeat("a", runtime.DebugLogStringLimit) + " ..(1 more bytes)..\n"
 155         if got != want {
 156                 t.Fatalf("want %q, got %q", want, got)
 157         }
 158 }