diff --git a/Makefile b/Makefile index 35fc189961b..2cedd200d3c 100644 --- a/Makefile +++ b/Makefile @@ -315,4 +315,4 @@ add-tags: | $(MULTIMOD) .PHONY: lint-markdown lint-markdown: - docker run -v "$(CURDIR):$(WORKDIR)" docker://avtodev/markdown-lint:v1 -c $(WORKDIR)/.markdownlint.yaml $(WORKDIR)/**/*.md + docker run -v "$(CURDIR):$(WORKDIR)" avtodev/markdown-lint:v1 -c $(WORKDIR)/.markdownlint.yaml $(WORKDIR)/**/*.md diff --git a/log/DESIGN.md b/log/DESIGN.md index 1c5cc031b13..584672f2328 100644 --- a/log/DESIGN.md +++ b/log/DESIGN.md @@ -43,16 +43,9 @@ is defined as an interface in [logger.go](logger.go). The [`LogRecord` abstraction](https://opentelemetry.io/docs/specs/otel/logs/bridge-api/#logger) is defined as a struct in [record.go](record.go). -`Record` has `WalkAttributes` and `AddAttributes` methods, -like [`slog.Record.Attrs`](https://pkg.go.dev/log/slog#Record.Attrs) -and [`slog.Record.AddAttrs`](https://pkg.go.dev/log/slog#Record.AddAttrs), -in order to achieve high-performance when accessing and setting attributes efficiently. - -`Record` has a `AttributesLen` method that returns -the number of attributes to allow slice preallocation -when converting records to a different representation. +## Usage examples -### Usage Example: Log Bridge implementation +### Log Bridge implementation A naive implementation of the [slog.Handler](https://pkg.go.dev/log/slog#Handler) interface @@ -62,7 +55,10 @@ A naive implementation of the [logr.LogSink](https://pkg.go.dev/github.com/go-logr/logr#LogSink) interface is in [benchmark/logr_test.go](benchmark/slog_test.go). -### Usage Example: Direct API usage +The log bridges can use [`sync.Pool`](https://pkg.go.dev/sync#Pool) +for reducing the number of allocations when mapping attributes. + +### Direct API usage The users may also chose to use the API directly. @@ -75,7 +71,7 @@ var logger = otel.Logger("my-service") logger.Emit(ctx, Record{Severity: log.SeverityInfo, Body: "Application started."}) ``` -### Usage Example: API implementation +### API implementation Excerpt of how SDK can implement the `Logger` interface. @@ -99,6 +95,10 @@ func (l *Logger) Emit(ctx context.Context, r log.Record) { A test implementation of the the `Logger` interface is in [benchmark/writer_logger_test.go](benchmark/writer_logger_test.go). +If the record is processed asynchronously, +then the processor has to copy record attributes, +in order to avoid use after free bugs and race condition. + Canceling the context should not affect record processing. Among other things, log messages may be necessary to debug a cancellation-related problem. @@ -110,7 +110,7 @@ The backwards compatibility is achieved using the `embedded` design pattern that is already used in Trace API and Metrics API. Additionally, the `Logger.Emit` functionality can be extended by -adding new exported fields and methods to the `Record` struct. +adding new exported fields to the `Record` struct. ## Benchmarking @@ -118,9 +118,9 @@ The benchmarks takes inspiration from [`slog`](https://pkg.go.dev/log/slog), because for the Go team it was also critical to create API that would be fast and interoperable with existing logging packages.[^1][^2] -## Rationale +## Rejected Alternatives -### Rejected Alternative: Reuse slog +### Reuse slog The API must not be coupled to [`slog`](https://pkg.go.dev/log/slog), nor any other logging library. @@ -134,7 +134,7 @@ The interoperabilty can be achieved using [a log bridge](https://opentelemetry.i You can read more about OpenTelemetry Logs design on [opentelemetry.io](https://opentelemetry.io/docs/concepts/signals/logs/). -### Rejected Alternative: Record as interface +### Record as interface `Record` is defined as a `struct` because of the following reasons. @@ -149,7 +149,7 @@ usage of interfaces tend to increase heap allocations.[^2] The `Record` design is inspired by [`slog.Record`](https://pkg.go.dev/log/slog#Record). -### Rejected Alternative: Options as parameter to Logger.Emit +### Options as parameter to Logger.Emit One of the initial ideas was to have: @@ -173,7 +173,7 @@ which would be used by the SDK and not by the users. At last, the definition would be similar to [`slog.Handler.Handle`](https://pkg.go.dev/log/slog#Handler) that was designed to provide optimization opportunities.[^1] -### Rejected Alternative: Passing record as pointer to Logger.Emit +### Passing record as pointer to Logger.Emit So far the benchmarks do not show differences that would favor passing the record via pointer (and vice versa). @@ -187,7 +187,7 @@ It should reduce the possibility of a heap allocation. The user would not be able to pass `nil`. Therefore, it reduces the possiblity to have a nil pointer dereference. -### Rejected Alternative: Passing struct as parameter to LoggerProvider.Logger +### Passing struct as parameter to LoggerProvider.Logger Similarly to `Logger.Emit`, we could have something like: @@ -207,57 +207,67 @@ HTTP/RPC handler could write hundreds of logs, it should not create a new logger for each log entry. The application should reuse loggers whenever possible. -### Rejected Proposal: Export attributesInlineCount - -There was a proposal to export `attributesInlineCount` -so the bridge implementation could use it -to reduce the number of heap allocations -when the record has more attribute than 5 -(the value of `attributesInlineCount`). - -However, according to [^1], only ~5% of code emits log records -with more than 5 attributes. -Moreover, according to -[the benchmarks](https://github.com/open-telemetry/opentelemetry-go/pull/4725#discussion_r1413884476), -it would only save a few allocations -when the number of attributes is greater than 5 -and the time execution tend to be slower for 5 attributes or less. - -At last, nothing prevents us to export this constant in future -if it will occur that it could be helpful in some scenarios. -However, without a strong reason, we prefer to hide the implementation detail -and have smaller API surface. +### Logger.WithAttributes -### Rejected Alternative: Record with exported fields - -There was a proposal that the timestamp, -observed timestamp, severity number, severity text, -body properties of the [Emit](https://opentelemetry.io/docs/specs/otel/logs/bridge-api/#emit-a-logrecord) -are exposed as exported fields of `Record` type. -This was inspired by [`slog.Record`](https://pkg.go.dev/log/slog#Record) -design. - -We find that exposing all properties via methods is be more consistent. -Having access to attributes via methods -and access to other properities via fields -could be more confusing for the users. - -### Rejected Alternative: Logger.WithAttributes - -The was to add `WithAttributes` to the `Logger` interface. +We could add `WithAttributes` to the `Logger` interface. Then `Record` could be a simple struct with only exported fields. The idea was that the SDK would implement the performance improvements instead of doing it in the API. This would allow having different optimisation strategies. -The main problem of this proposal was that the variadic slice passed to -an interface method is always heap allocated. +During the analysis[^4], it occurred that the main problem of this proposal +is that the variadic slice passed to an interface method is always heap allocated. Moreover, the logger returned by `WithAttribute` was allocated on the heap. At last, the proposal was not specification compliant. -The proposal analysis was done [here](https://github.com/pellared/opentelemetry-go/pull/3). +### Record attributes like in slog.Record + +To reduce the number of allocations of the attributes, +the `Record` could be modeled similarly to [`slog.Record`](https://pkg.go.dev/log/slog#Record). +`Record` could have `WalkAttributes` and `AddAttributes` methods, +like [`slog.Record.Attrs`](https://pkg.go.dev/log/slog#Record.Attrs) +and [`slog.Record.AddAttrs`](https://pkg.go.dev/log/slog#Record.AddAttrs), +in order to achieve high-performance when accessing and setting attributes efficiently. +`Record` would have a `AttributesLen` method that returns +the number of attributes to allow slice preallocation +when converting records to a different representation. + +However, during the analysis[^5] we decided that having +a simple slice in `Record` is more flexible. + +It is possible to achieve better performance, by using [`sync.Pool`](https://pkg.go.dev/sync#Pool). + +Having a simple `Record` without any logic makes it possible +that the optimisations can be done in API implementation +and bridge implementations. +For instance, in order to reduce the heap allocations of attributes, +the bridge implementation can use a `sync.Pool`. +In such case, the API implementation (SDK) would need to copy the attributes +when the records are processed asynchrounsly, +in order to avoid use after free bugs and race conditions. + +For reference, here is the reason why `slog` does not use `sync.Pool`[^2]: + +> We can use a sync pool for records though we decided not to. +You can but it's a bad idea for us. Why? +Because users have control of Records. +Handler writers can get their hands on a record +and we'd have to ask them to free it +or try to free it magically at some some point. +But either way, they could get themselves in trouble by freeing it twice +or holding on to one after they free it. +That's a use after free bug and that's why `zerolog` was problematic for us. +`zerolog` as as part of its speed exposes a pool allocated value to users +if you use `zerolog` the normal way, that you'll see in all the examples, +you will never encounter a problem. +But if you do something a little out of the ordinary you can get +use after free bugs and we just didn't want to put that in the standard library. + +We took a different decision, because the key difference is that `slog` +is a logging library and Logs Bridge API is only a logging abstraction. +We want to provide more flexibility and offer better speed. ## Open issues (if applicable) @@ -267,3 +277,5 @@ know the solution. This section may be omitted if there are none. --> [^1]: Jonathan Amsterdam, [The Go Blog: Structured Logging with slog](https://go.dev/blog/slog) [^2]: Jonathan Amsterdam, [GopherCon Europe 2023: A Fast Structured Logging Package](https://www.youtube.com/watch?v=tC4Jt3i62ns) [^3]: [Emit definition discussion with benchmarks](https://github.com/open-telemetry/opentelemetry-go/pull/4725#discussion_r1400869566) +[^4]: [Logger.WithAttributes analysis](https://github.com/pellared/opentelemetry-go/pull/3) +[^5]: [Record attributes as field and use sync.Pool for reducing allocations analysis](https://github.com/pellared/opentelemetry-go/pull/4) diff --git a/log/benchmark/bench_test.go b/log/benchmark/bench_test.go index c3713c036cc..c6c297f0d22 100644 --- a/log/benchmark/bench_test.go +++ b/log/benchmark/bench_test.go @@ -14,6 +14,7 @@ package benchmark import ( "context" "io" + "sync" "testing" "time" @@ -43,6 +44,13 @@ var ( // slow logger implementation is skewing the results. The writerLogger // allocates memory only when using strconv. func BenchmarkEmit(b *testing.B) { + attrPool := sync.Pool{ + New: func() interface{} { + attr := make([]attribute.KeyValue, 0, 5) + return &attr + }, + } + for _, tc := range []struct { name string logger log.Logger @@ -58,25 +66,34 @@ func BenchmarkEmit(b *testing.B) { { "no attrs", func() { - r := log.Record{} - r.SetTimestamp(testTimestamp) - r.SetSeverity(testSeverity) - r.SetBody(testBody) + r := log.Record{ + Timestamp: testTimestamp, + Severity: testSeverity, + Body: testBody, + } tc.logger.Emit(ctx, r) }, }, { "3 attrs", func() { - r := log.Record{} - r.SetTimestamp(testTimestamp) - r.SetSeverity(testSeverity) - r.SetBody(testBody) - r.AddAttributes( + ptr := attrPool.Get().(*[]attribute.KeyValue) + attrs := *ptr + defer func() { + *ptr = attrs[:0] + attrPool.Put(ptr) + }() + attrs = append(attrs, attribute.String("string", testString), attribute.Float64("float", testFloat), attribute.Int("int", testInt), ) + r := log.Record{ + Timestamp: testTimestamp, + Severity: testSeverity, + Body: testBody, + Attributes: attrs, + } tc.logger.Emit(ctx, r) }, }, @@ -87,28 +104,38 @@ func BenchmarkEmit(b *testing.B) { // should only be from strconv used in writerLogger. "5 attrs", func() { - r := log.Record{} - r.SetTimestamp(testTimestamp) - r.SetSeverity(testSeverity) - r.SetBody(testBody) - r.AddAttributes( + ptr := attrPool.Get().(*[]attribute.KeyValue) + attrs := *ptr + defer func() { + *ptr = attrs[:0] + attrPool.Put(ptr) + }() + attrs = append(attrs, attribute.String("string", testString), attribute.Float64("float", testFloat), attribute.Int("int", testInt), attribute.Bool("bool", testBool), attribute.String("string", testString), ) + r := log.Record{ + Timestamp: testTimestamp, + Severity: testSeverity, + Body: testBody, + Attributes: attrs, + } tc.logger.Emit(ctx, r) }, }, { "10 attrs", func() { - r := log.Record{} - r.SetTimestamp(testTimestamp) - r.SetSeverity(testSeverity) - r.SetBody(testBody) - r.AddAttributes( + ptr := attrPool.Get().(*[]attribute.KeyValue) + attrs := *ptr + defer func() { + *ptr = attrs[:0] + attrPool.Put(ptr) + }() + attrs = append(attrs, attribute.String("string", testString), attribute.Float64("float", testFloat), attribute.Int("int", testInt), @@ -120,17 +147,25 @@ func BenchmarkEmit(b *testing.B) { attribute.Bool("bool", testBool), attribute.String("string", testString), ) + r := log.Record{ + Timestamp: testTimestamp, + Severity: testSeverity, + Body: testBody, + Attributes: attrs, + } tc.logger.Emit(ctx, r) }, }, { "40 attrs", func() { - r := log.Record{} - r.SetTimestamp(testTimestamp) - r.SetSeverity(testSeverity) - r.SetBody(testBody) - r.AddAttributes( + ptr := attrPool.Get().(*[]attribute.KeyValue) + attrs := *ptr + defer func() { + *ptr = attrs[:0] + attrPool.Put(ptr) + }() + attrs = append(attrs, attribute.String("string", testString), attribute.Float64("float", testFloat), attribute.Int("int", testInt), @@ -172,6 +207,12 @@ func BenchmarkEmit(b *testing.B) { attribute.Bool("bool", testBool), attribute.String("string", testString), ) + r := log.Record{ + Timestamp: testTimestamp, + Severity: testSeverity, + Body: testBody, + Attributes: attrs, + } tc.logger.Emit(ctx, r) }, }, diff --git a/log/benchmark/go.mod b/log/benchmark/go.mod index 293569e0cf6..e389e5dc55c 100644 --- a/log/benchmark/go.mod +++ b/log/benchmark/go.mod @@ -12,17 +12,14 @@ require ( require ( github.com/davecgh/go-spew v1.1.1 // indirect - github.com/go-logr/stdr v1.2.2 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect - go.opentelemetry.io/otel/metric v1.21.0 // indirect - go.opentelemetry.io/otel/trace v1.21.0 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) -replace go.opentelemetry.io/otel/trace => ../../trace - -replace go.opentelemetry.io/otel/metric => ../../metric - replace go.opentelemetry.io/otel/log => ../ replace go.opentelemetry.io/otel => ../.. + +replace go.opentelemetry.io/otel/trace => ../../trace + +replace go.opentelemetry.io/otel/metric => ../../metric diff --git a/log/benchmark/go.sum b/log/benchmark/go.sum index 5b5bdfca2d9..df42623c7b1 100644 --- a/log/benchmark/go.sum +++ b/log/benchmark/go.sum @@ -1,10 +1,7 @@ github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= -github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/logr v1.3.0 h1:2y3SDp0ZXuc6/cjLSZ+Q3ir+QB9T/iG5yYRXqsagWSY= github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= -github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= -github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= diff --git a/log/benchmark/logr_test.go b/log/benchmark/logr_test.go index 2ee9c494f58..37f31a9125f 100644 --- a/log/benchmark/logr_test.go +++ b/log/benchmark/logr_test.go @@ -5,6 +5,7 @@ package benchmark import ( "fmt" + "sync" "testing" "github.com/go-logr/logr" @@ -21,20 +22,28 @@ func TestLogrSink(t *testing.T) { l.Info(testBody, "string", testString) - assert.Equal(t, testBody, spy.Record.Body()) - assert.Equal(t, log.SeverityInfo, spy.Record.Severity()) - assert.Equal(t, 1, spy.Record.AttributesLen()) - spy.Record.WalkAttributes(func(kv attribute.KeyValue) bool { - assert.Equal(t, "string", string(kv.Key)) - assert.Equal(t, testString, kv.Value.AsString()) - return true - }) + want := log.Record{ + Body: testBody, + Severity: log.SeverityInfo, + Attributes: []attribute.KeyValue{ + attribute.String("string", testString), + }, + } + + assert.Equal(t, want, spy.Record) } type logrSink struct { Logger log.Logger } +var logrAttrPool = sync.Pool{ + New: func() interface{} { + attr := make([]attribute.KeyValue, 0, 5) + return &attr + }, +} + // Init is implementated as a dummy. func (s *logrSink) Init(info logr.RuntimeInfo) { } @@ -49,23 +58,30 @@ func (s *logrSink) Enabled(level int) bool { func (s *logrSink) Info(level int, msg string, keysAndValues ...any) { record := log.Record{} - record.SetBody(msg) + record.Body = msg lvl := log.Severity(9 - level) - record.SetSeverity(lvl) + record.Severity = lvl if len(keysAndValues)%2 == 1 { panic("key without a value") } kvCount := len(keysAndValues) / 2 + ptr := logrAttrPool.Get().(*[]attribute.KeyValue) + attrs := *ptr + defer func() { + *ptr = attrs[:0] + logrAttrPool.Put(ptr) + }() for i := 0; i < kvCount; i++ { k, ok := keysAndValues[i*2].(string) if !ok { panic("key is not a string") } kv := convertKV(k, keysAndValues[i*2+1]) - record.AddAttributes(kv) + attrs = append(attrs, kv) } + record.Attributes = attrs s.Logger.Emit(ctx, record) } diff --git a/log/benchmark/slog_test.go b/log/benchmark/slog_test.go index c076ae2ce81..5e5d796f223 100644 --- a/log/benchmark/slog_test.go +++ b/log/benchmark/slog_test.go @@ -6,7 +6,9 @@ package benchmark import ( "context" "fmt" + "sync" "testing" + "time" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/log" @@ -21,36 +23,53 @@ func TestSlogHandler(t *testing.T) { l.Info(testBody, "string", testString) - assert.Equal(t, testBody, spy.Record.Body()) - assert.Equal(t, log.SeverityInfo, spy.Record.Severity()) - assert.Equal(t, 1, spy.Record.AttributesLen()) - spy.Record.WalkAttributes(func(kv attribute.KeyValue) bool { - assert.Equal(t, "string", string(kv.Key)) - assert.Equal(t, testString, kv.Value.AsString()) - return true - }) + want := log.Record{ + Body: testBody, + Severity: log.SeverityInfo, + Attributes: []attribute.KeyValue{ + attribute.String("string", testString), + }, + } + + assert.NotZero(t, spy.Record.Timestamp, "should set a timestamp") + spy.Record.Timestamp = time.Time{} + assert.Equal(t, want, spy.Record) } type slogHandler struct { Logger log.Logger } +var slogAttrPool = sync.Pool{ + New: func() interface{} { + attr := make([]attribute.KeyValue, 0, 5) + return &attr + }, +} + // Handle handles the Record. // It should avoid memory allocations whenever possible. func (h *slogHandler) Handle(_ context.Context, r slog.Record) error { record := log.Record{} - record.SetTimestamp(r.Time) + record.Timestamp = r.Time - record.SetBody(r.Message) + record.Body = r.Message lvl := convertLevel(r.Level) - record.SetSeverity(lvl) - + record.Severity = lvl + + ptr := slogAttrPool.Get().(*[]attribute.KeyValue) + attrs := *ptr + defer func() { + *ptr = attrs[:0] + slogAttrPool.Put(ptr) + }() r.Attrs(func(a slog.Attr) bool { - record.AddAttributes(convertAttr(a)) + attrs = append(attrs, convertAttr(a)) return true }) + record.Attributes = attrs h.Logger.Emit(context.Background(), record) return nil diff --git a/log/benchmark/writer_logger_test.go b/log/benchmark/writer_logger_test.go index b1043cc25fb..a0eb4d2bbe6 100644 --- a/log/benchmark/writer_logger_test.go +++ b/log/benchmark/writer_logger_test.go @@ -22,16 +22,17 @@ func TestWriterLogger(t *testing.T) { sb := &strings.Builder{} l := &writerLogger{w: sb} - r := log.Record{} - r.SetTimestamp(testTimestamp) - r.SetSeverity(testSeverity) - r.SetBody(testBody) - r.AddAttributes( - attribute.String("string", testString), - attribute.Float64("float", testFloat), - attribute.Int("int", testInt), - attribute.Bool("bool", testBool), - ) + r := log.Record{ + Timestamp: testTimestamp, + Severity: testSeverity, + Body: testBody, + Attributes: []attribute.KeyValue{ + attribute.String("string", testString), + attribute.Float64("float", testFloat), + attribute.Int("int", testInt), + attribute.Bool("bool", testBool), + }, + } l.Emit(ctx, r) want := "timestamp=595728000 severity=9 body=log message string=7e3b3b2aaeff56a7108fe11e154200dd/7819479873059528190 float=1.2345 int=32768 bool=true\n" @@ -47,23 +48,22 @@ type writerLogger struct { } func (l *writerLogger) Emit(_ context.Context, r log.Record) { - if !r.Timestamp().IsZero() { + if !r.Timestamp.IsZero() { l.write("timestamp=") - l.write(strconv.FormatInt(r.Timestamp().Unix(), 10)) + l.write(strconv.FormatInt(r.Timestamp.Unix(), 10)) l.write(" ") } l.write("severity=") - l.write(strconv.FormatInt(int64(r.Severity()), 10)) + l.write(strconv.FormatInt(int64(r.Severity), 10)) l.write(" ") l.write("body=") - l.write(r.Body()) - r.WalkAttributes(func(kv attribute.KeyValue) bool { + l.write(r.Body) + for _, kv := range r.Attributes { l.write(" ") l.write(string(kv.Key)) l.write("=") l.appendValue(kv.Value) - return true - }) + } l.write("\n") } diff --git a/log/go.mod b/log/go.mod index e073bbf54c4..abb4f8c45eb 100644 --- a/log/go.mod +++ b/log/go.mod @@ -4,15 +4,8 @@ go 1.20 require go.opentelemetry.io/otel v1.21.0 -require ( - github.com/go-logr/logr v1.3.0 // indirect - github.com/go-logr/stdr v1.2.2 // indirect - go.opentelemetry.io/otel/metric v1.21.0 // indirect - go.opentelemetry.io/otel/trace v1.21.0 // indirect -) +replace go.opentelemetry.io/otel => ../ replace go.opentelemetry.io/otel/trace => ../trace replace go.opentelemetry.io/otel/metric => ../metric - -replace go.opentelemetry.io/otel => ../ diff --git a/log/go.sum b/log/go.sum index a90f90be690..2d8ac4840ed 100644 --- a/log/go.sum +++ b/log/go.sum @@ -1,9 +1,4 @@ github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= -github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= -github.com/go-logr/logr v1.3.0 h1:2y3SDp0ZXuc6/cjLSZ+Q3ir+QB9T/iG5yYRXqsagWSY= -github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= -github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= -github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk= diff --git a/log/record.go b/log/record.go index 70cd95cd853..d4e3d60c064 100644 --- a/log/record.go +++ b/log/record.go @@ -8,44 +8,21 @@ package log // import "go.opentelemetry.io/otel/log" import ( - "errors" "time" - "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" ) -var errUnsafeAddAttrs = errors.New("unsafely called AddAttrs on copy of Record made without using Record.Clone") - // Record TODO: comment. -// TODO: Add unit tests. type Record struct { - timestamp time.Time - observedTimestamp time.Time - severity Severity - severityText string - body string - - // The fields below are for optimizing the implementation of - // Attributes and AddAttributes. - - // Allocation optimization: an inline array sized to hold - // the majority of log calls (based on examination of open-source - // code). It holds the start of the list of attributes. - front [attributesInlineCount]attribute.KeyValue - - // The number of attributes in front. - nFront int - - // The list of attributes except for those in front. - // Invariants: - // - len(back) > 0 if nFront == len(front) - // - Unused array elements are zero. Used to detect mistakes. - back []attribute.KeyValue + Timestamp time.Time + ObservedTimestamp time.Time + Severity Severity + SeverityText string + Body string + Attributes []attribute.KeyValue } -const attributesInlineCount = 5 - // Severity TODO: comment. type Severity int @@ -77,146 +54,3 @@ const ( SeverityFatal3 SeverityFatal4 ) - -// Timestamp TODO: comment. -func (r Record) Timestamp() time.Time { - return r.timestamp -} - -// SetTimestamp TODO: comment. -func (r *Record) SetTimestamp(t time.Time) { - r.timestamp = t -} - -// ObservedTimestamp TODO: comment. -func (r Record) ObservedTimestamp() time.Time { - return r.observedTimestamp -} - -// SetObservedTimestamp TODO: comment. -func (r *Record) SetObservedTimestamp(t time.Time) { - r.observedTimestamp = t -} - -// Severity TODO: comment. -func (r Record) Severity() Severity { - return r.severity -} - -// SetSeverity TODO: comment. -func (r *Record) SetSeverity(s Severity) { - r.severity = s -} - -// SeverityText TODO: comment. -func (r Record) SeverityText() string { - return r.severityText -} - -// SetSeverityText TODO: comment. -func (r *Record) SetSeverityText(s string) { - r.severityText = s -} - -// Body TODO: comment. -func (r Record) Body() string { - return r.body -} - -// SetBody TODO: comment. -func (r *Record) SetBody(s string) { - r.body = s -} - -// WalkAttributes calls f on each [attribute.KeyValue] in the [Record]. -// Iteration stops if f returns false. -func (r Record) WalkAttributes(f func(attribute.KeyValue) bool) { - for i := 0; i < r.nFront; i++ { - if !f(r.front[i]) { - return - } - } - for _, a := range r.back { - if !f(a) { - return - } - } -} - -// AddAttributes appends the given [attribute.KeyValue] to the [Record]'s list of [attribute.KeyValue]. -// It omits invalid attributes. -func (r *Record) AddAttributes(attrs ...attribute.KeyValue) { - var i int - for i = 0; i < len(attrs) && r.nFront < len(r.front); i++ { - a := attrs[i] - if !a.Valid() { - continue - } - r.front[r.nFront] = a - r.nFront++ - } - // Check if a copy was modified by slicing past the end - // and seeing if the Attr there is non-zero. - if cap(r.back) > len(r.back) { - end := r.back[:len(r.back)+1][len(r.back)] - if end.Valid() { - // Don't panic; copy and muddle through. - r.back = sliceClip(r.back) - otel.Handle(errUnsafeAddAttrs) - } - } - ne := countInvalidAttrs(attrs[i:]) - r.back = sliceGrow(r.back, len(attrs[i:])-ne) - for _, a := range attrs[i:] { - if a.Valid() { - r.back = append(r.back, a) - } - } -} - -// Clone returns a copy of the record with no shared state. -// The original record and the clone can both be modified -// without interfering with each other. -func (r Record) Clone() Record { - r.back = sliceClip(r.back) // prevent append from mutating shared array - return r -} - -// AttributesLen returns the number of attributes in the Record. -func (r Record) AttributesLen() int { - return r.nFront + len(r.back) -} - -// countInvalidAttrs returns the number of invalid attributes. -func countInvalidAttrs(as []attribute.KeyValue) int { - n := 0 - for _, a := range as { - if !a.Valid() { - n++ - } - } - return n -} - -// sliceGrow increases the slice's capacity, if necessary, to guarantee space for -// another n elements. After Grow(n), at least n elements can be appended -// to the slice without another allocation. If n is negative or too large to -// allocate the memory, Grow panics. -// -// This is a copy from https://pkg.go.dev/slices as it is not available in Go 1.20. -func sliceGrow[S ~[]E, E any](s S, n int) S { - if n < 0 { - panic("cannot be negative") - } - if n -= cap(s) - len(s); n > 0 { - s = append(s[:cap(s)], make([]E, n)...)[:len(s)] - } - return s -} - -// sliceClip removes unused capacity from the slice, returning s[:len(s):len(s)]. -// -// This is a copy from https://pkg.go.dev/slices as it is not available in Go 1.20. -func sliceClip[S ~[]E, E any](s S) S { - return s[:len(s):len(s)] -}