| author | Alberto Bertogli
<albertito@blitiri.com.ar> 2025-11-30 11:18:52 UTC |
| committer | Alberto Bertogli
<albertito@blitiri.com.ar> 2025-11-30 11:20:13 UTC |
| parent | d91ca418c232a26e311a4a4557a86c097491c473 |
| nettrace/bench_test.go | +9 | -0 |
| nettrace/disable.go | +37 | -0 |
| nettrace/disable_test.go | +50 | -0 |
| nettrace/log.go | +6 | -0 |
| nettrace/log_test.go | +25 | -0 |
| nettrace/test_server.go | +12 | -12 |
| nettrace/trace.go | +30 | -9 |
| nettrace/trace_test.go | +19 | -0 |
diff --git a/nettrace/bench_test.go b/nettrace/bench_test.go index a58fdbb..e78da13 100644 --- a/nettrace/bench_test.go +++ b/nettrace/bench_test.go @@ -55,3 +55,12 @@ func BenchmarkPrintf(b *testing.B) { tr.Printf("this is printf") } } + +func BenchmarkPrint(b *testing.B) { + tr := New("bench", "test") + defer tr.Finish() + b.ResetTimer() + for i := 0; i < b.N; i++ { + tr.Print("this is print") + } +} diff --git a/nettrace/disable.go b/nettrace/disable.go new file mode 100644 index 0000000..d866f1c --- /dev/null +++ b/nettrace/disable.go @@ -0,0 +1,37 @@ +package nettrace + +import "fmt" + +// Disable is a flag to disable all tracing functions. It can be used to +// minimize the performance impact of the tracing functions when they are not +// needed (e.g. no debug server or logging). +var Disable = false + +type disabledTrace struct{} + +func (disabledTrace) NewChild(family, title string) Trace { + return disabledTrace{} +} + +func (disabledTrace) Link(other Trace, msg string) {} + +func (disabledTrace) SetMaxEvents(n int) {} + +func (disabledTrace) SetError() {} + +func (disabledTrace) Print(s string) {} + +func (disabledTrace) Printf(format string, a ...interface{}) {} + +func (disabledTrace) Error(err error) error { + return err +} + +func (disabledTrace) Errorf(format string, a ...interface{}) error { + return fmt.Errorf(format, a...) +} + +func (disabledTrace) Finish() {} + +// Static check that disabledTrace implements Trace. +var _ Trace = disabledTrace{} diff --git a/nettrace/disable_test.go b/nettrace/disable_test.go new file mode 100644 index 0000000..a442923 --- /dev/null +++ b/nettrace/disable_test.go @@ -0,0 +1,50 @@ +package nettrace + +import ( + "errors" + "os" + "testing" +) + +func TestDisabledTrace(t *testing.T) { + // Disable all tracing functions for the duration of this test. + // Re-enable them afterwards. + Disable = true + defer func() { Disable = false }() + + // Check that New(), when Disable is true, returns a disabledTrace and + // doesn't update the intenral structures. + tr := New("family", "title") + if _, ok := tr.(disabledTrace); !ok { + t.Errorf("New() = %T, want disabledTrace", tr) + } + + if ft, ok := families["family"]; ok { + t.Errorf("families['family'] = %v, expected it to be empty", ft) + } + + // Call the methods of disabledTrace to ensure they don't panic or, when + // they have potential side-effects that we can check, that they don't. + ctr := tr.NewChild("family-2", "title") + if _, ok := ctr.(disabledTrace); !ok { + t.Errorf("NewChild() = %T, want disabledTrace", ctr) + } + tr.Link(ctr, "msg") + tr.SetMaxEvents(10) + tr.SetError() + tr.Printf("hola") + + err := tr.Errorf("this is an error: %w", os.ErrNotExist) + if !errors.Is(err, os.ErrNotExist) { + t.Errorf("error = %v, want wrapped os.ErrNotExist", err) + } + + tr.Print("this is a string") + + err = tr.Error(os.ErrNotExist) + if err != os.ErrNotExist { + t.Errorf("error = %v, want os.ErrNotExist", err) + } + + tr.Finish() +} diff --git a/nettrace/log.go b/nettrace/log.go new file mode 100644 index 0000000..d2e8f8a --- /dev/null +++ b/nettrace/log.go @@ -0,0 +1,6 @@ +package nettrace + +// To allow users to log the trace data, we provide a simple logging interface. +// This is global and not lock-protected, so if used, it must be set before any +// tracing is done. +var Log func(family, title, id, msg string, err bool) = nil diff --git a/nettrace/log_test.go b/nettrace/log_test.go new file mode 100644 index 0000000..5e862d8 --- /dev/null +++ b/nettrace/log_test.go @@ -0,0 +1,25 @@ +package nettrace + +import ( + "fmt" + "regexp" + "testing" +) + +func TestLog(t *testing.T) { + log := "" + Log = func(f, t, id, msg string, isErr bool) { + log += fmt.Sprintf("%s %s %s %s %v\n", f, t, id, msg, isErr) + } + defer func() { Log = nil }() + + var tr Trace = New("TLFamily", "TLTitle") + tr.Printf("hola marola") + tr.Finish() + + expectRe := regexp.MustCompile( + `^TLFamily TLTitle [\w\d!]+ hola marola false\n$`) + if !expectRe.MatchString(log) { + t.Errorf("log does not match expected: %q", log) + } +} diff --git a/nettrace/test_server.go b/nettrace/test_server.go index 20341b9..f98945a 100644 --- a/nettrace/test_server.go +++ b/nettrace/test_server.go @@ -5,7 +5,7 @@ package main import ( "flag" "fmt" - "math/rand" + "math/rand/v2" "net/http" "time" @@ -48,23 +48,23 @@ func RandomEvents(family string) { func randomTrace(family string, tr nettrace.Trace) { tr.Printf("this is a random event") tr.Printf("and it has a random delay") - delay := time.Duration(rand.Intn(1000)) * time.Millisecond + delay := rand.N(1000 * time.Millisecond) tr.Printf("sleeping %v", delay) time.Sleep(delay) - if rand.Intn(100) < 1 { + if rand.IntN(100) < 1 { tr.Printf("this unlucky one is an error") tr.SetError() } - if rand.Intn(100) < 10 { + if rand.IntN(100) < 10 { tr.Printf("this one got super verbose!") for j := 0; j < 100; j++ { tr.Printf("message %d", j) } } - if rand.Intn(100) < 30 { + if rand.IntN(100) < 30 { tr.Printf("this one had a child") c := tr.NewChild(family, "achild") go randomTrace(family, c) @@ -78,7 +78,7 @@ func RandomLongEvent(family, title string) { tr := nettrace.New(family, title) tr.Printf("this is a random long event") for i := 0; ; i++ { - delay := time.Duration(rand.Intn(100)) * time.Millisecond + delay := rand.N(100 * time.Millisecond) time.Sleep(delay) tr.Printf("message %d, slept %v", i, delay) } @@ -90,16 +90,16 @@ func RandomBunny(family, title string) { tr.SetMaxEvents(100) tr.Printf("this is the top 🐇") for i := 0; ; i++ { - delay := time.Duration(rand.Intn(100)) * time.Millisecond + delay := rand.N(100 * time.Millisecond) time.Sleep(delay) tr.Printf("message %d, slept %v", i, delay) - if rand.Intn(100) < 40 { + if rand.IntN(100) < 40 { c := tr.NewChild(family, fmt.Sprintf("child-%d", i)) go randomTrace(family, c) } - if rand.Intn(100) < 40 { + if rand.IntN(100) < 40 { n := nettrace.New(family, fmt.Sprintf("linked-%d", i)) go randomTrace(family, n) tr.Link(n, "linking with this guy") @@ -114,7 +114,7 @@ func randomNested(family string, depth int, parent nettrace.Trace) { tr.Printf("I am a spoiled child") - delay := time.Duration(rand.Intn(100)) * time.Millisecond + delay := rand.N(100 * time.Millisecond) time.Sleep(delay) tr.Printf("slept %v", delay) @@ -124,12 +124,12 @@ func randomNested(family string, depth int, parent nettrace.Trace) { } // If we make this < 50, then it grows forever. - if rand.Intn(100) < 75 { + if rand.IntN(100) < 75 { tr.Printf("I sang really well") return } - max := rand.Intn(5) + max := rand.IntN(5) for i := 0; i < max; i++ { tr.Printf("spawning %d", i) go randomNested(family, depth+1, tr) diff --git a/nettrace/trace.go b/nettrace/trace.go index 700d6ff..42d1809 100644 --- a/nettrace/trace.go +++ b/nettrace/trace.go @@ -1,11 +1,11 @@ // Package nettrace implements tracing of requests. Traces are created by // nettrace.New, and can then be viewed over HTTP on /debug/traces. -package nettrace +package nettrace // import "blitiri.com.ar/go/gofer/nettrace" import ( "container/ring" "fmt" - "math/rand" + "math/rand/v2" "sort" "strconv" "strings" @@ -50,9 +50,16 @@ type Trace interface { // SetError marks that the trace was for an error event. SetError() - // Printf adds a message to the trace. + // Print adds a message to the trace. + Print(s string) + + // Printf adds a formatted message to the trace. Printf(format string, a ...interface{}) + // Error logs an error to the trace, and returns it unchanged (for + // convenience). + Error(err error) error + // Errorf adds a message to the trace, marks it as an error, and returns // an error for it. Errorf(format string, a ...interface{}) error @@ -151,6 +158,9 @@ func newTrace(family, title string) *trace { // New creates a new trace with the given family and title. func New(family, title string) Trace { + if Disable { + return disabledTrace{} + } return newTrace(family, title) } @@ -220,23 +230,34 @@ func (tr *trace) SetError() { tr.mu.Unlock() } -func (tr *trace) Printf(format string, a ...interface{}) { +func (tr *trace) Print(s string) { evt := &event{ When: time.Now(), Type: evtLOG, - Msg: fmt.Sprintf(format, a...), + Msg: s, } tr.append(evt) + + if Log != nil { + Log(tr.Family, tr.Title, string(tr.ID), evt.Msg, tr.isError) + } } -func (tr *trace) Errorf(format string, a ...interface{}) error { +func (tr *trace) Printf(format string, a ...interface{}) { + tr.Print(fmt.Sprintf(format, a...)) +} + +func (tr *trace) Error(err error) error { tr.SetError() - err := fmt.Errorf(format, a...) - tr.Printf(err.Error()) + tr.Print(err.Error()) return err } +func (tr *trace) Errorf(format string, a ...interface{}) error { + return tr.Error(fmt.Errorf(format, a...)) +} + func (tr *trace) Finish() { tr.mu.Lock() tr.end = time.Now() @@ -301,7 +322,7 @@ func (tr *trace) IsError() bool { // We keep this many buckets of finished traces. const nBuckets = 8 -// Buckets to use. Length must match nBuckets. +// Buckets to use. Lenght must match nBuckets. // "Traces with a latency >= $duration". var buckets = []time.Duration{ time.Duration(0), diff --git a/nettrace/trace_test.go b/nettrace/trace_test.go index ebdb5c5..5f7fa91 100644 --- a/nettrace/trace_test.go +++ b/nettrace/trace_test.go @@ -1,7 +1,9 @@ package nettrace import ( + "errors" "fmt" + "os" "strings" "testing" "time" @@ -76,6 +78,23 @@ func TestIsError(t *testing.T) { } } +func TestErrorFormatting(t *testing.T) { + tr := New("TestErrorFormatting", "") + defer tr.Finish() + + err := tr.Errorf("this is an error: %w", os.ErrNotExist) + if !errors.Is(err, os.ErrNotExist) { + t.Errorf("error = %v, want wrapped os.ErrNotExist", err) + } + + err = tr.Error(os.ErrNotExist) + if err != os.ErrNotExist { + t.Errorf("error = %v, want os.ErrNotExist", err) + } + + expectEvents(t, tr, 2) +} + func TestFindViaRef(t *testing.T) { parent := New("TestFindViaRef", "parent") parentID := parent.(*trace).ID