diff --git a/etcdctl/go.sum b/etcdctl/go.sum index aa3be394d76e..37435c093e20 100644 --- a/etcdctl/go.sum +++ b/etcdctl/go.sum @@ -88,10 +88,10 @@ go.opentelemetry.io/auto/sdk v1.1.0 h1:cH53jehLUN6UFLY71z+NDOiNJqDdPRaXzTel0sJyS go.opentelemetry.io/auto/sdk v1.1.0/go.mod h1:3wSPjt5PWp2RhlCcmmOial7AvC4DQqZb7a7wCow3W8A= go.opentelemetry.io/otel v1.38.0 h1:RkfdswUDRimDg0m2Az18RKOsnI8UDzppJAtj01/Ymk8= go.opentelemetry.io/otel v1.38.0/go.mod h1:zcmtmQ1+YmQM9wrNsTGV/q/uyusom3P8RxwExxkZhjM= -go.opentelemetry.io/otel/metric v1.37.0 h1:mvwbQS5m0tbmqML4NqK+e3aDiO02vsf/WgbsdpcPoZE= -go.opentelemetry.io/otel/metric v1.37.0/go.mod h1:04wGrZurHYKOc+RKeye86GwKiTb9FKm1WHtO+4EVr2E= -go.opentelemetry.io/otel/sdk v1.37.0 h1:ItB0QUqnjesGRvNcmAcU0LyvkVyGJ2xftD29bWdDvKI= -go.opentelemetry.io/otel/sdk v1.37.0/go.mod h1:VredYzxUvuo2q3WRcDnKDjbdvmO0sCzOvVAiY+yUkAg= +go.opentelemetry.io/otel/metric v1.38.0 h1:Kl6lzIYGAh5M159u9NgiRkmoMKjvbsKtYRwgfrA6WpA= +go.opentelemetry.io/otel/metric v1.38.0/go.mod h1:kB5n/QoRM8YwmUahxvI3bO34eVtQf2i4utNVLr9gEmI= +go.opentelemetry.io/otel/sdk v1.38.0 h1:l48sr5YbNf2hpCUj/FoGhW9yDkl+Ma+LrVl8qaM5b+E= +go.opentelemetry.io/otel/sdk v1.38.0/go.mod h1:ghmNdGlVemJI3+ZB5iDEuk4bWA3GkTpW+DOoZMYBVVg= go.opentelemetry.io/otel/sdk/metric v1.37.0 h1:90lI228XrB9jCMuSdA0673aubgRobVZFhbjxHHspCPc= go.opentelemetry.io/otel/sdk/metric v1.37.0/go.mod h1:cNen4ZWfiD37l5NhS+Keb5RXVWZWpRE+9WyVCpbo5ps= go.opentelemetry.io/otel/trace v1.38.0 h1:Fxk5bKrDZJUH+AMyyIXGcFAPah0oRcT+LuNtJrmcNLE= diff --git a/pkg/go.mod b/pkg/go.mod index 3459fcb7265f..a53b76445c29 100644 --- a/pkg/go.mod +++ b/pkg/go.mod @@ -11,6 +11,8 @@ require ( github.com/spf13/pflag v1.0.10 github.com/stretchr/testify v1.11.1 go.etcd.io/etcd/client/pkg/v3 v3.6.0-alpha.0 + go.opentelemetry.io/otel v1.38.0 + go.opentelemetry.io/otel/sdk v1.38.0 go.opentelemetry.io/otel/trace v1.38.0 go.uber.org/zap v1.27.0 golang.org/x/sys v0.36.0 @@ -20,9 +22,13 @@ require ( require ( github.com/coreos/go-systemd/v22 v22.6.0 // indirect github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc // indirect + github.com/go-logr/logr v1.4.3 // indirect + github.com/go-logr/stdr v1.2.2 // indirect + github.com/google/uuid v1.6.0 // indirect github.com/inconshreveable/mousetrap v1.1.0 // indirect github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect - go.opentelemetry.io/otel v1.38.0 // indirect + go.opentelemetry.io/auto/sdk v1.1.0 // indirect + go.opentelemetry.io/otel/metric v1.38.0 // indirect go.uber.org/multierr v1.11.0 // indirect golang.org/x/net v0.44.0 // indirect golang.org/x/text v0.29.0 // indirect diff --git a/pkg/go.sum b/pkg/go.sum index dd04253d415e..c590ae38511e 100644 --- a/pkg/go.sum +++ b/pkg/go.sum @@ -7,6 +7,7 @@ github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc h1:U9qPSI2PIWSS1 github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/dustin/go-humanize v1.0.1 h1:GzkhY7T5VNhEkwH0PVJgjz+fX1rhBrR7pRT3mDkpeCY= github.com/dustin/go-humanize v1.0.1/go.mod h1:Mu1zIs6XwVuF/gI1OepvI0qD18qycQx+mFykh5fBlto= +github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/logr v1.4.3 h1:CjnDlHq8ikf6E492q6eKboGOC0T8CDaOvkHCIg8idEI= github.com/go-logr/logr v1.4.3/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= @@ -41,10 +42,10 @@ go.opentelemetry.io/otel v1.38.0 h1:RkfdswUDRimDg0m2Az18RKOsnI8UDzppJAtj01/Ymk8= go.opentelemetry.io/otel v1.38.0/go.mod h1:zcmtmQ1+YmQM9wrNsTGV/q/uyusom3P8RxwExxkZhjM= go.opentelemetry.io/otel/metric v1.38.0 h1:Kl6lzIYGAh5M159u9NgiRkmoMKjvbsKtYRwgfrA6WpA= go.opentelemetry.io/otel/metric v1.38.0/go.mod h1:kB5n/QoRM8YwmUahxvI3bO34eVtQf2i4utNVLr9gEmI= -go.opentelemetry.io/otel/sdk v1.37.0 h1:ItB0QUqnjesGRvNcmAcU0LyvkVyGJ2xftD29bWdDvKI= -go.opentelemetry.io/otel/sdk v1.37.0/go.mod h1:VredYzxUvuo2q3WRcDnKDjbdvmO0sCzOvVAiY+yUkAg= -go.opentelemetry.io/otel/sdk/metric v1.37.0 h1:90lI228XrB9jCMuSdA0673aubgRobVZFhbjxHHspCPc= -go.opentelemetry.io/otel/sdk/metric v1.37.0/go.mod h1:cNen4ZWfiD37l5NhS+Keb5RXVWZWpRE+9WyVCpbo5ps= +go.opentelemetry.io/otel/sdk v1.38.0 h1:l48sr5YbNf2hpCUj/FoGhW9yDkl+Ma+LrVl8qaM5b+E= +go.opentelemetry.io/otel/sdk v1.38.0/go.mod h1:ghmNdGlVemJI3+ZB5iDEuk4bWA3GkTpW+DOoZMYBVVg= +go.opentelemetry.io/otel/sdk/metric v1.38.0 h1:aSH66iL0aZqo//xXzQLYozmWrXxyFkBJ6qT5wthqPoM= +go.opentelemetry.io/otel/sdk/metric v1.38.0/go.mod h1:dg9PBnW9XdQ1Hd6ZnRz689CbtrUp0wMMs9iPcgT9EZA= go.opentelemetry.io/otel/trace v1.38.0 h1:Fxk5bKrDZJUH+AMyyIXGcFAPah0oRcT+LuNtJrmcNLE= go.opentelemetry.io/otel/trace v1.38.0/go.mod h1:j1P9ivuFsTceSWe1oY+EeW3sc+Pp42sO++GHkg4wwhs= go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= diff --git a/pkg/traceutil/exporter.go b/pkg/traceutil/exporter.go new file mode 100644 index 000000000000..d8a926650a98 --- /dev/null +++ b/pkg/traceutil/exporter.go @@ -0,0 +1,96 @@ +// Copyright 2025 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package traceutil + +import ( + "context" + "fmt" + "slices" + "strings" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/sdk/trace" + "go.uber.org/zap" +) + +// LogExporter writes Span to specified Logger. +type LogExporter struct { + // Log is usually zap.Logger.Info. + Log func(msg string, fields ...zap.Field) +} + +var _ trace.SpanExporter = (*LogExporter)(nil) + +// NewLogExporter creates a new LogExporter which will write Spans as Log messages. +func NewLogExporter(logger *zap.Logger) *LogExporter { + if logger == nil { + logger = zap.NewNop() + } + return &LogExporter{Log: logger.Info} +} + +func (e *LogExporter) ExportSpans(ctx context.Context, spans []trace.ReadOnlySpan) error { + for _, span := range spans { + msg, fields := logSpan(span) + e.Log(msg, fields...) + } + return nil +} + +func (e *LogExporter) Shutdown(ctx context.Context) error { + return nil +} + +func logSpan(s trace.ReadOnlySpan) (string, []zap.Field) { + start := s.StartTime() + end := s.EndTime() + duration := end.Sub(start) + events := s.Events() + steps := make([]string, 0, len(events)) + slices.SortFunc(events, func(a, b trace.Event) int { + return a.Time.Compare(b.Time) + }) + for _, event := range events { + step := fmt.Sprintf("%s %s [+%.3fms]", + event.Name, writeAttrs(event.Attributes), float64(event.Time.Sub(start).Microseconds())/1_000) + steps = append(steps, step) + } + msg := fmt.Sprintf("trace[%s] %s", s.SpanContext().SpanID().String(), s.Name()) + + return msg, []zap.Field{ + zap.String("detail", writeAttrs(s.Attributes())), + zap.Duration("duration", duration), + zap.Time("start", s.StartTime()), + zap.Time("end", s.EndTime()), + zap.Strings("steps", steps), + zap.Int("step_count", len(steps)), + } +} + +func writeAttrs(attrs []attribute.KeyValue) string { + if len(attrs) == 0 { + return "" + } + var buf strings.Builder + buf.WriteString("{") + for _, attr := range attrs { + buf.WriteString(string(attr.Key)) + buf.WriteString(":") + buf.WriteString(attr.Value.Emit()) + buf.WriteString("; ") + } + buf.WriteString("}") + return buf.String() +} diff --git a/pkg/traceutil/exporter_test.go b/pkg/traceutil/exporter_test.go new file mode 100644 index 000000000000..acc770732491 --- /dev/null +++ b/pkg/traceutil/exporter_test.go @@ -0,0 +1,86 @@ +// Copyright 2025 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package traceutil_test + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + "go.uber.org/zap" + + "go.etcd.io/etcd/pkg/v3/traceutil" +) + +func TestLogSpan(t *testing.T) { + duration := 123 * time.Second + + startTime, _ := time.Parse("2006-01-02 15:04:05", "2025-01-01 00:00:00") + endTime := startTime.Add(duration) + + tests := []struct { + span trace.ReadOnlySpan + wantMsg string + wantFields []zap.Field + }{ + { + span: tracetest.SpanStub{ + Name: "span_with_two_events", + StartTime: startTime, + EndTime: endTime, + Attributes: []attribute.KeyValue{ + attribute.String("key1", "value1"), + attribute.String("key2", "value2"), + }, + Events: []trace.Event{ + { + Time: startTime.Add(1 * time.Second), + Name: "event1", + Attributes: []attribute.KeyValue{attribute.String("key3", "value3")}, + }, + { + Time: startTime.Add(2 * time.Second), + Name: "event2", + Attributes: []attribute.KeyValue{attribute.String("key4", "value4")}, + }, + }, + }.Snapshot(), + wantMsg: "trace[0000000000000000] span_with_two_events", + wantFields: []zap.Field{ + zap.String("detail", "{key1:value1; key2:value2; }"), + zap.Duration("duration", duration), + zap.Time("start", startTime), + zap.Time("end", endTime), + zap.Strings("steps", []string{"event1 {key3:value3; } [+1000.000ms]", "event2 {key4:value4; } [+2000.000ms]"}), + zap.Int("step_count", 2), + }, + }, + } + + for _, tt := range tests { + t.Run(tt.span.Name(), func(t *testing.T) { + exporter := traceutil.LogExporter{ + Log: func(msg string, fields ...zap.Field) { + assert.Equal(t, tt.wantMsg, msg) + assert.Equal(t, tt.wantFields, fields) + }, + } + exporter.ExportSpans(t.Context(), []trace.ReadOnlySpan{tt.span}) + }) + } +} diff --git a/pkg/traceutil/processor.go b/pkg/traceutil/processor.go new file mode 100644 index 000000000000..d7491b4154cf --- /dev/null +++ b/pkg/traceutil/processor.go @@ -0,0 +1,65 @@ +// Copyright 2025 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package traceutil + +import ( + "context" + "time" + + "go.opentelemetry.io/otel/sdk/trace" +) + +// LongSpanProcessor is a SpanProcessor that passes to SpanExporter only Spans +// with a duration longer than Threshold and operation in Allowlist. +type LongSpanProcessor struct { + trace.SpanExporter + // Threshold is the duration under which spans are not logged. + Threshold time.Duration + // Allowlist specifies operations for which a log may be emitted. + Allowlist map[string]bool +} + +var _ trace.SpanProcessor = (*LongSpanProcessor)(nil) + +// NewLongSpanProcessor creates a new LongSpanProcessor which will pass to +// SpanExporter all Spans with duration longer than Threshold and operation in +// Allowlist. +func NewLongSpanProcessor(exporter trace.SpanExporter, threshold time.Duration) *LongSpanProcessor { + return &LongSpanProcessor{ + SpanExporter: exporter, + Threshold: threshold, + Allowlist: map[string]bool{ + "txn": true, + "range": true, + "put": true, + "delete_range": true, + "compact": true, + "lease_grant": true, + "lease_revoke": true, + }, + } +} + +func (f LongSpanProcessor) OnStart(parent context.Context, s trace.ReadWriteSpan) {} +func (f LongSpanProcessor) ForceFlush(ctx context.Context) error { return nil } +func (f LongSpanProcessor) OnEnd(s trace.ReadOnlySpan) { + if f.Threshold > 0 && s.EndTime().Sub(s.StartTime()) < f.Threshold { + return + } + if f.Allowlist != nil && !f.Allowlist[s.Name()] { + return + } + f.ExportSpans(context.Background(), []trace.ReadOnlySpan{s}) +} diff --git a/pkg/traceutil/processor_test.go b/pkg/traceutil/processor_test.go new file mode 100644 index 000000000000..577a3c4e3c05 --- /dev/null +++ b/pkg/traceutil/processor_test.go @@ -0,0 +1,107 @@ +// Copyright 2025 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package traceutil_test + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + + "go.etcd.io/etcd/pkg/v3/traceutil" +) + +func TestLogSpanThreshold(t *testing.T) { + startTime, _ := time.Parse("2006-01-02 15:04:05", "2025-01-01 00:00:00") + threshold := 60 * time.Second + + tests := []struct { + span trace.ReadOnlySpan + called bool + }{ + { + span: tracetest.SpanStub{ + Name: "above_threshold", + StartTime: startTime, + EndTime: startTime.Add(61 * time.Second), + }.Snapshot(), + called: true, + }, + { + span: tracetest.SpanStub{ + Name: "on_threshold", + StartTime: startTime, + EndTime: startTime.Add(60 * time.Second), + }.Snapshot(), + called: true, + }, + { + span: tracetest.SpanStub{ + Name: "above_threshold", + StartTime: startTime, + EndTime: startTime.Add(59 * time.Second), + }.Snapshot(), + called: false, + }, + } + for _, tt := range tests { + t.Run(tt.span.Name(), func(t *testing.T) { + exporter := tracetest.NewInMemoryExporter() + l := traceutil.LongSpanProcessor{ + SpanExporter: exporter, + Threshold: threshold, + } + l.OnEnd(tt.span) + got := exporter.GetSpans() + assert.Equal(t, tt.called, len(got) == 1) + }) + } +} + +func TestLogSpanAllowlist(t *testing.T) { + tests := []struct { + span trace.ReadOnlySpan + called bool + }{ + { + span: tracetest.SpanStub{ + Name: "allowed", + }.Snapshot(), + called: true, + }, + { + span: tracetest.SpanStub{ + Name: "not_allowed", + }.Snapshot(), + }, + } + + for _, tt := range tests { + t.Run(tt.span.Name(), func(t *testing.T) { + exporter := tracetest.NewInMemoryExporter() + l := traceutil.LongSpanProcessor{ + SpanExporter: exporter, + Allowlist: map[string]bool{ + "allowed": true, + }, + } + l.OnEnd(tt.span) + got := exporter.GetSpans() + assert.Equal(t, tt.called, len(got) == 1) + }) + } +} diff --git a/pkg/traceutil/trace_test.go b/pkg/traceutil/trace_test.go index 395a1e0bb02d..6629551f142b 100644 --- a/pkg/traceutil/trace_test.go +++ b/pkg/traceutil/trace_test.go @@ -25,6 +25,9 @@ import ( "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" "go.etcd.io/etcd/client/pkg/v3/logutil" ) @@ -188,31 +191,73 @@ func TestLog(t *testing.T) { }, } - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - logPath := filepath.Join(os.TempDir(), fmt.Sprintf("test-log-%d", time.Now().UnixNano())) - defer os.RemoveAll(logPath) + for _, converted := range []bool{false, true} { + t.Run(fmt.Sprintf("converted=%v", converted), func(t *testing.T) { + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + logPath := filepath.Join(os.TempDir(), fmt.Sprintf("test-log-%d", time.Now().UnixNano())) + defer os.RemoveAll(logPath) - lcfg := logutil.DefaultZapLoggerConfig - lcfg.OutputPaths = []string{logPath} - lcfg.ErrorOutputPaths = []string{logPath} - lg, _ := lcfg.Build() + lcfg := logutil.DefaultZapLoggerConfig + lcfg.OutputPaths = []string{logPath} + lcfg.ErrorOutputPaths = []string{logPath} + lg, _ := lcfg.Build() - for _, f := range tt.fields { - tt.trace.AddField(f) - } - tt.trace.lg = lg - tt.trace.Log() - data, err := os.ReadFile(logPath) - require.NoError(t, err) + for _, f := range tt.fields { + tt.trace.AddField(f) + } + if converted { + span := traceToSpan(tt.trace) + spanLogger := LongSpanProcessor{ + SpanExporter: &LogExporter{Log: lg.Info}, + } + spanLogger.OnEnd(span) + } else { + tt.trace.lg = lg + tt.trace.Log() + } + data, err := os.ReadFile(logPath) + require.NoError(t, err) + + t.Logf("log: %s", data) - for _, msg := range tt.expectedMsg { - assert.Truef(t, bytes.Contains(data, []byte(msg)), "Expected to find %v in log", msg) + for _, msg := range tt.expectedMsg { + assert.Truef(t, bytes.Contains(data, []byte(msg)), "Expected to find %v in log", msg) + } + }) } }) } } +func traceToSpan(t *Trace) trace.ReadOnlySpan { + span := tracetest.SpanStub{ + Name: t.operation, + StartTime: t.startTime, + EndTime: time.Now(), + Attributes: fieldsToAttrs(t.fields), + } + for _, step := range t.steps { + if step.isSubTraceStart || step.isSubTraceEnd { + continue + } + span.Events = append(span.Events, trace.Event{ + Time: step.time, + Name: step.msg, + Attributes: fieldsToAttrs(step.fields), + }) + } + return span.Snapshot() +} + +func fieldsToAttrs(fields []Field) []attribute.KeyValue { + attrs := make([]attribute.KeyValue, 0, len(fields)) + for _, f := range fields { + attrs = append(attrs, attribute.String(f.Key, fmt.Sprintf("%v", f.Value))) + } + return attrs +} + func TestLogIfLong(t *testing.T) { tests := []struct { name string @@ -265,22 +310,38 @@ func TestLogIfLong(t *testing.T) { }, } - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - logPath := filepath.Join(os.TempDir(), fmt.Sprintf("test-log-%d", time.Now().UnixNano())) - defer os.RemoveAll(logPath) + for _, converted := range []bool{false, true} { + t.Run(fmt.Sprintf("converted=%v", converted), func(t *testing.T) { + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + logPath := filepath.Join(os.TempDir(), fmt.Sprintf("test-log-%d", time.Now().UnixNano())) + defer os.RemoveAll(logPath) + + lcfg := logutil.DefaultZapLoggerConfig + lcfg.OutputPaths = []string{logPath} + lcfg.ErrorOutputPaths = []string{logPath} + lg, _ := lcfg.Build() - lcfg := logutil.DefaultZapLoggerConfig - lcfg.OutputPaths = []string{logPath} - lcfg.ErrorOutputPaths = []string{logPath} - lg, _ := lcfg.Build() + if converted { + span := traceToSpan(tt.trace) + spanLogger := LongSpanProcessor{ + SpanExporter: &LogExporter{ + Log: lg.Info, + }, + Threshold: tt.threshold, + } + spanLogger.OnEnd(span) + } else { + tt.trace.lg = lg + tt.trace.LogIfLong(tt.threshold) + } - tt.trace.lg = lg - tt.trace.LogIfLong(tt.threshold) - data, err := os.ReadFile(logPath) - require.NoError(t, err) - for _, msg := range tt.expectedMsg { - assert.Truef(t, bytes.Contains(data, []byte(msg)), "Expected to find %v in log", msg) + data, err := os.ReadFile(logPath) + require.NoError(t, err) + for _, msg := range tt.expectedMsg { + assert.Truef(t, bytes.Contains(data, []byte(msg)), "Expected to find %v in log", msg) + } + }) } }) }