From d63a359a04bd0ffb82f47e7a8014190d1c310b49 Mon Sep 17 00:00:00 2001 From: Peter Weinberger Date: Wed, 7 Jun 2023 13:27:11 -0400 Subject: [PATCH] x/telemetry/counter: fix stack computation The line number computation in stack counters was wrong (thank you Russ), and has been changed. There is no longer a special case for 386s. Part of the issue for 386s is https://github.com/golang/go/issues/60673 but it is not relevant for this. Change-Id: Iccc9a43ac05d94df2aa7915bfc3d4d74e4d2ff6a Reviewed-on: https://go-review.googlesource.com/c/telemetry/+/501596 Run-TryBot: Peter Weinberger Reviewed-by: Jamal Carvalho TryBot-Result: Gopher Robot --- counter/counter_test.go | 118 ++++++++-------------------------------- counter/doc.go | 2 +- counter/stackcounter.go | 36 +++++++----- 3 files changed, 48 insertions(+), 108 deletions(-) diff --git a/counter/counter_test.go b/counter/counter_test.go index 654c786..6382f8c 100644 --- a/counter/counter_test.go +++ b/counter/counter_test.go @@ -6,13 +6,12 @@ package counter -// Missing any tests of concurrent uses of a counter. -// This is a TODO. +// Builders at +// https://build.golang.org/?repo=golang.org%2fx%2ftelemetry import ( "encoding/hex" "fmt" - "log" "os" "path/filepath" "reflect" @@ -26,9 +25,10 @@ import ( ) func TestBasic(t *testing.T) { - if runtime.GOOS == "openbsd" { - t.Skip("broken for openbsd") + if runtime.GOOS == "openbsd" || runtime.GOOS == "js" || runtime.GOOS == "wasip1" { + t.Skip("broken for openbsd etc") } + t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) setup(t) defer restore() var f file @@ -66,14 +66,19 @@ func TestBasic(t *testing.T) { // this is needed in Windows so that the generated testing.go file // can clean up the temporary test directory func close(f *file) { + if f == nil { + // telemetry might have been off + return + } f.current.Load().f.Close() mmap.Munmap(f.current.Load().mapping) } func TestLarge(t *testing.T) { - if runtime.GOOS == "openbsd" { - t.Skip("broken for openbsd") + if runtime.GOOS == "openbsd" || runtime.GOOS == "js" || runtime.GOOS == "wasip1" { + t.Skip("broken for openbsd etc") } + t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) setup(t) defer restore() var f file @@ -118,6 +123,7 @@ func TestLarge(t *testing.T) { } func TestRepeatedNew(t *testing.T) { + t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) setup(t) defer restore() var f file @@ -155,6 +161,7 @@ func hexDump(data []byte) string { } func TestNewFile(t *testing.T) { + t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) setup(t) defer restore() year, month, day := time.Now().Date() @@ -209,7 +216,8 @@ func TestNewFile(t *testing.T) { } days := (then.Sub(now)) / (24 * time.Hour) if days <= 7 || days > 14 { - t.Errorf("days = %d, want 7 < days <= 14", days) + // this fails on Solaris, but only once, so print i. + t.Errorf("%d: days = %d, want 7 < days <= 14", i, days) } close(&f) // remove the file for the next iteration of the loop @@ -218,6 +226,7 @@ func TestNewFile(t *testing.T) { } func TestRotate(t *testing.T) { + t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) year, month, day := time.Now().Date() now := time.Date(year, month, day, 0, 0, 0, 0, time.UTC) setup(t) @@ -272,9 +281,6 @@ func TestRotate(t *testing.T) { } func TestStack(t *testing.T) { - if runtime.GOARCH == "386" && runtime.GOOS == "linux" { - t.Skip("some bad line numbers for linux-386") - } t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) setup(t) defer restore() @@ -287,20 +293,19 @@ func TestStack(t *testing.T) { if len(names) != 2 { t.Fatalf("got %d names, want 2", len(names)) } - // each name should be 6 lines, and the two names should - // differ only in the second line. The last few lines should - // be blank. + // each name should be 4 lines, and the two names should + // differ only in the second line. n0 := strings.Split(names[0], "\n") n1 := strings.Split(names[1], "\n") - if len(n0) != 6 || len(n1) != 6 { - t.Fatalf("got %d and %d lines, want 6 (%q,%q)", len(n0), len(n1), n0, n1) + if len(n0) != 4 || len(n1) != 4 { + t.Errorf("got %d and %d lines, want 4 (%q,%q)", len(n0), len(n1), n0, n1) } - for i := 0; i < 6; i++ { // loop generated by copilot (from comment?) + for i := 0; i < 4 && i < len(n0) && i < len(n1); i++ { if i == 1 { continue } if n0[i] != n1[i] { - t.Fatalf("line %d differs:\n%s\n%s", i, n0[i], n1[i]) + t.Errorf("line %d differs:\n%s\n%s", i, n0[i], n1[i]) } } oldnames := make(map[string]bool) @@ -318,7 +323,7 @@ func TestStack(t *testing.T) { } // expect 5 new names, one for each level of recursion if len(newnames) != 5 { - t.Fatalf("got %d new names, want 5", len(newnames)) + t.Errorf("got %d new names, want 5", len(newnames)) } // look inside. old names should have a count of 1, new ones 2 for _, ct := range c.Counters() { @@ -362,78 +367,3 @@ func restore() { func (f *file) New(name string) *Counter { return &Counter{name: name, file: f} } - -// This checks the computation of of line numbers for creating -// stack counters. It is named after the strangest system, -// but will provide a timely warning if the runtime changes how it -// computes line numbers. -func TestLinux386(t *testing.T) { - t.Logf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) - x := infoFromHere(0) - if msg, wanted := check(0, x); msg != "" { - t.Errorf("got %q, wanted %s", msg, wanted) - } - x = deeper() - if msg, wanted := check(1, x); msg != "" { - t.Errorf("got %q, wanted %s", msg, wanted) - } -} - -var ans = []string{ - "GOOS freebsd GARCH amd64: 3 7", - "GOOS linux GARCH amd64: 3 7", - "GOOS linux GARCH arm64: 3 7", - "GOOS linux GARCH 386: 2 6", - "GOOS openbsd GARCH amd64: 3 7", - "GOOS windows GARCH amd64: 3 7", - "GOOS darwin GARCH amd64: 3 7", - "GOOS darwin GARCH arm64: 3 7", -} - -func check(n int, got string) (string, string) { - const prefix = "golang.org/x/telemetry/counter.TestLinux386:" - start := fmt.Sprintf("GOOS %s GARCH %s", runtime.GOOS, runtime.GOARCH) - if !strings.HasPrefix(got, prefix) { - return got, "doesn't start with " + prefix - } - for _, a := range ans { - before, after, ok := strings.Cut(a, ":") - if !ok { - return got, "bad ans, no colon" - } - if before == start { - flds := strings.Fields(after) - if prefix+flds[n] == got { - return "", "" - } - return got, flds[n] - } - } - return got, fmt.Sprintf("%s not found", start) -} - -func deeper() string { - log.SetFlags(log.Lshortfile) - x := infoFromHere(1) - return x -} - -// the code from file.go that creates stack counter names -func infoFromHere(w int) string { - pcs := make([]uintptr, 4) - n := runtime.Callers(2, pcs) - pcs = pcs[:n] - locs := make([]string, n) - frs := runtime.CallersFrames(pcs) - for i := 0; i < n; i++ { - fr, more := frs.Next() - _, pcline := fr.Func.FileLine(pcs[i]) - entryptr := fr.Func.Entry() - _, entryline := fr.Func.FileLine(entryptr) - locs[i] = fmt.Sprintf("%s:%d", fr.Function, pcline-entryline) - if !more { - break - } - } - return locs[w] -} diff --git a/counter/doc.go b/counter/doc.go index 727985f..ebf074c 100644 --- a/counter/doc.go +++ b/counter/doc.go @@ -18,7 +18,7 @@ // are implemented as a set of regular counters whose names // are the concatenation of the name and the stack trace. There is an upper // limit on the size of this name, about 256 bytes. If the name is too long -// the counter will be silently ignored.) +// the stack will be truncated and "truncated" appended.) // // Counter files are turned into reports by the upload package. // This happens weekly, except for the first time a counter file is diff --git a/counter/stackcounter.go b/counter/stackcounter.go index af8c13b..7a7f511 100644 --- a/counter/stackcounter.go +++ b/counter/stackcounter.go @@ -6,7 +6,6 @@ package counter import ( "fmt" - "log" "runtime" "strings" "sync" @@ -53,24 +52,33 @@ func (c *StackCounter) Inc() { defer c.mu.Unlock() for _, s := range c.stacks { if eq(s.pcs, pcs) { - s.counter.Inc() + if s.counter != nil { + s.counter.Inc() + } return } } // have to create the new counter's name, and the new counter itself - locs := make([]string, c.depth) + locs := make([]string, 0, c.depth) frs := runtime.CallersFrames(pcs) - for i := 0; i < n; i++ { + for i := 0; ; i++ { fr, more := frs.Next() - _, pcline := fr.Func.FileLine(pcs[i]) - entryptr := fr.Func.Entry() - _, entryline := fr.Func.FileLine(entryptr) - locs[i] = fmt.Sprintf("%s:%d", fr.Function, pcline-entryline) - if pcline-entryline < 0 { - // should never happen, remove before production TODO(pjw) - log.Printf("i=%d, f=%s, pcline=%d entryLine=%d", i, fr.Function, pcline, entryline) - log.Printf("pcs[i]=%x, entryptr=%x", pcs[i], entryptr) + pcline := fr.Line + entryptr := fr.Entry + var locline string + if fr.Func != nil { + _, entryline := fr.Func.FileLine(entryptr) + if pcline >= entryline { + // anything else is unexpected + locline = fmt.Sprintf("%s:%d", fr.Function, pcline-entryline) + } else { + locline = fmt.Sprintf("%s:??%d", fr.Function, pcline) + } + } else { + // might happen if the function is non-Go code or is fully inlined. + locline = fmt.Sprintf("%s:?%d", fr.Function, pcline) } + locs = append(locs, locline) if !more { break } @@ -78,7 +86,9 @@ func (c *StackCounter) Inc() { name := c.name + "\n" + strings.Join(locs, "\n") if len(name) > maxNameLen { - return // fails silently, every time + const bad = "\ntruncated\n" + name = name[:maxNameLen-len(bad)] + bad + } ctr := New(name) c.stacks = append(c.stacks, stack{pcs: pcs, counter: ctr})