-
Notifications
You must be signed in to change notification settings - Fork 10.2k
Add OpenTelemetry replacements for bespoke trace logging #20728
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| @@ -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 { | ||||||||||||||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Why implement own json serializer? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I wanted to keep it as close to the previous implementation as possible: https://github.com/etcd-io/etcd/blob/v3.6.5/pkg/traceutil/trace.go#L44-L55 |
||||||||||||||
| if len(attrs) == 0 { | ||||||||||||||
| return "" | ||||||||||||||
| } | ||||||||||||||
|
Comment on lines
+83
to
+85
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
Suggested change
|
||||||||||||||
| 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() | ||||||||||||||
| } | ||||||||||||||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -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}) | ||
| }) | ||
| } | ||
| } |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -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}) | ||
| } |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
How does it work with nesting?
Uh oh!
There was an error while loading. Please reload this page.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
From PR description:
so either printing
spanIDso it will be easy to search in logs/Otel collector or returning the span to use for copying like in #20307Please note that "applier span" is the only case when one trace is part of another