From 649484ef38e9f0c605432d2d68eb80e53f8023ce Mon Sep 17 00:00:00 2001 From: Damien Mathieu Date: Thu, 27 Jun 2024 13:17:09 +0200 Subject: [PATCH 1/6] Split the set and add attributes benchmarks (#5546) This benchmark currently tests two rather different methods within the same loop, which makes it hard to see what could be causing a performance degradation. Related: #5054. ``` BenchmarkSetAddAttributes/SetAttributes-10 14066331 82.80 ns/op 48 B/op 1 allocs/op BenchmarkSetAddAttributes/AddAttributes-10 19333711 114.7 ns/op 0 B/op 0 allocs/op ``` --- sdk/log/record_test.go | 26 +++++++++++++++++++------- 1 file changed, 19 insertions(+), 7 deletions(-) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index cbbd8942420..e53cf3410d6 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -642,12 +642,24 @@ func TestTruncate(t *testing.T) { func BenchmarkSetAddAttributes(b *testing.B) { kv := log.String("key", "value") - records := make([]Record, b.N) - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - records[i].SetAttributes(kv) - records[i].AddAttributes(kv) - } + b.Run("SetAttributes", func(b *testing.B) { + records := make([]Record, b.N) + + b.ResetTimer() + b.ReportAllocs() + for i := 0; i < b.N; i++ { + records[i].SetAttributes(kv) + } + }) + + b.Run("AddAttributes", func(b *testing.B) { + records := make([]Record, b.N) + + b.ResetTimer() + b.ReportAllocs() + for i := 0; i < b.N; i++ { + records[i].AddAttributes(kv) + } + }) } From 12f0db5215ae5c9ab7fffcb073251e25bb705605 Mon Sep 17 00:00:00 2001 From: Damien Mathieu Date: Thu, 27 Jun 2024 13:29:38 +0200 Subject: [PATCH 2/6] Add walk attributes benchmark (#5547) This adds a benchmark for `record.WalkAttributes`. Part of #5054. ``` BenchmarkWalkAttributes/1_attributes-10 346989372 3.449 ns/op 0 B/op 0 allocs/op BenchmarkWalkAttributes/10_attributes-10 345712522 3.459 ns/op 0 B/op 0 allocs/op BenchmarkWalkAttributes/100_attributes-10 349380534 3.455 ns/op 0 B/op 0 allocs/op BenchmarkWalkAttributes/1000_attributes-10 342041373 3.484 ns/op 0 B/op 0 allocs/op ``` --- sdk/log/record_test.go | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index e53cf3410d6..5a16267b8b3 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -640,6 +640,35 @@ func TestTruncate(t *testing.T) { } } +func BenchmarkWalkAttributes(b *testing.B) { + for _, tt := range []struct { + attrCount int + }{ + {attrCount: 1}, + {attrCount: 10}, + {attrCount: 100}, + {attrCount: 1000}, + } { + b.Run(fmt.Sprintf("%d attributes", tt.attrCount), func(b *testing.B) { + record := &Record{} + for i := 0; i < tt.attrCount; i++ { + record.SetAttributes( + log.String(fmt.Sprintf("key-%d", tt.attrCount), "value"), + ) + } + + b.ReportAllocs() + b.ResetTimer() + + for i := 0; i < b.N; i++ { + record.WalkAttributes(func(log.KeyValue) bool { + return true + }) + } + }) + } +} + func BenchmarkSetAddAttributes(b *testing.B) { kv := log.String("key", "value") From acb2471488f2ccf5c59a454d849af962fe43f0c2 Mon Sep 17 00:00:00 2001 From: Damien Mathieu Date: Thu, 27 Jun 2024 13:39:58 +0200 Subject: [PATCH 3/6] Add benchmark retrieving a new logger (#5548) This adds a benchmark to create a logger from a logger provider. Related: #5054. ``` BenchmarkLoggerProviderLogger-10 3145390 548.8 ns/op 330 B/op 1 allocs/op ``` --- sdk/log/provider_test.go | 21 +++++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/sdk/log/provider_test.go b/sdk/log/provider_test.go index bfa8afcda1d..55dc516a7b1 100644 --- a/sdk/log/provider_test.go +++ b/sdk/log/provider_test.go @@ -5,6 +5,7 @@ package log // import "go.opentelemetry.io/otel/sdk/log" import ( "context" + "fmt" "strconv" "sync" "testing" @@ -17,6 +18,7 @@ import ( "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/internal/global" + "go.opentelemetry.io/otel/log" "go.opentelemetry.io/otel/log/noop" "go.opentelemetry.io/otel/sdk/resource" ) @@ -287,3 +289,22 @@ func TestLoggerProviderForceFlush(t *testing.T) { assert.ErrorIs(t, p.ForceFlush(ctx), assert.AnError, "processor error not returned") }) } + +func BenchmarkLoggerProviderLogger(b *testing.B) { + p := NewLoggerProvider() + names := make([]string, b.N) + for i := 0; i < b.N; i++ { + names[i] = fmt.Sprintf("%d logger", i) + } + + b.ResetTimer() + b.ReportAllocs() + + loggers := make([]log.Logger, b.N) + for i := 0; i < b.N; i++ { + loggers[i] = p.Logger(names[i]) + } + + b.StopTimer() + loggers[0].Enabled(context.Background(), log.Record{}) +} From 47941435277a9ba222e664e54d9a7f6d97cf6a03 Mon Sep 17 00:00:00 2001 From: "renovate[bot]" <29139614+renovate[bot]@users.noreply.github.com> Date: Thu, 27 Jun 2024 07:49:41 -0700 Subject: [PATCH 4/6] chore(deps): update jaegertracing/all-in-one docker tag to v1.54 (#5555) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit [![Mend Renovate](https://app.renovatebot.com/images/banner.svg)](https://renovatebot.com) This PR contains the following updates: | Package | Update | Change | |---|---|---| | jaegertracing/all-in-one | patch | `1.58` -> `1.54` | --- ### Configuration 📅 **Schedule**: Branch creation - At any time (no schedule defined), Automerge - At any time (no schedule defined). 🚦 **Automerge**: Disabled by config. Please merge this manually once you are satisfied. ♻ **Rebasing**: Whenever PR becomes conflicted, or you tick the rebase/retry checkbox. 🔕 **Ignore**: Close this PR and you won't be reminded about this update again. --- - [ ] If you want to rebase/retry this PR, check this box --- This PR has been generated by [Mend Renovate](https://www.mend.io/free-developer-tools/renovate/). View repository job log [here](https://developer.mend.io/github/open-telemetry/opentelemetry-go). Co-authored-by: renovate[bot] <29139614+renovate[bot]@users.noreply.github.com> --- example/otel-collector/docker-compose.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/example/otel-collector/docker-compose.yaml b/example/otel-collector/docker-compose.yaml index 9b6f12ae3a7..5723db3db28 100644 --- a/example/otel-collector/docker-compose.yaml +++ b/example/otel-collector/docker-compose.yaml @@ -18,6 +18,6 @@ services: - 9090:9090 jaeger: - image: jaegertracing/all-in-one:1.58 + image: jaegertracing/all-in-one:1.54 ports: - 16686:16686 From 1d783e14f7a2c100d29a508dcd617b5cdb5bce5f Mon Sep 17 00:00:00 2001 From: "renovate[bot]" <29139614+renovate[bot]@users.noreply.github.com> Date: Thu, 27 Jun 2024 08:03:51 -0700 Subject: [PATCH 5/6] chore(deps): update jaegertracing/all-in-one docker tag to v1.58 (#5556) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit [![Mend Renovate](https://app.renovatebot.com/images/banner.svg)](https://renovatebot.com) This PR contains the following updates: | Package | Update | Change | |---|---|---| | jaegertracing/all-in-one | minor | `1.54` -> `1.58` | --- ### Configuration 📅 **Schedule**: Branch creation - At any time (no schedule defined), Automerge - At any time (no schedule defined). 🚦 **Automerge**: Disabled by config. Please merge this manually once you are satisfied. ♻ **Rebasing**: Whenever PR becomes conflicted, or you tick the rebase/retry checkbox. 🔕 **Ignore**: Close this PR and you won't be reminded about this update again. --- - [ ] If you want to rebase/retry this PR, check this box --- This PR has been generated by [Mend Renovate](https://www.mend.io/free-developer-tools/renovate/). View repository job log [here](https://developer.mend.io/github/open-telemetry/opentelemetry-go). Co-authored-by: renovate[bot] <29139614+renovate[bot]@users.noreply.github.com> --- example/otel-collector/docker-compose.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/example/otel-collector/docker-compose.yaml b/example/otel-collector/docker-compose.yaml index 5723db3db28..9b6f12ae3a7 100644 --- a/example/otel-collector/docker-compose.yaml +++ b/example/otel-collector/docker-compose.yaml @@ -18,6 +18,6 @@ services: - 9090:9090 jaeger: - image: jaegertracing/all-in-one:1.54 + image: jaegertracing/all-in-one:1.58 ports: - 16686:16686 From f3a2d96022c01a07fa6f8f67dab30fd2dae61419 Mon Sep 17 00:00:00 2001 From: Fabrice Vaillant Date: Thu, 27 Jun 2024 19:27:48 +0200 Subject: [PATCH 6/6] Reduces allocation in attributes (#5549) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Remove one allocation in all SliceValue function (going from 3 to 2). Here is benchstat results ``` goos: linux goarch: amd64 pkg: go.opentelemetry.io/otel/internal/attribute cpu: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz │ old.txt │ new.txt │ │ sec/op │ sec/op vs base │ BoolSliceValue-8 128.4n ± 22% 103.8n ± 25% -19.12% (p=0.007 n=10) Int64SliceValue-8 167.9n ± 7% 130.8n ± 5% -22.13% (p=0.000 n=10) Float64SliceValue-8 133.8n ± 14% 122.6n ± 4% -8.33% (p=0.000 n=10) StringSliceValue-8 166.4n ± 9% 158.5n ± 10% -4.75% (p=0.037 n=10) geomean 148.0n 127.5n -13.88% │ old.txt │ new.txt │ │ B/op │ B/op vs base │ BoolSliceValue-8 32.000 ± 0% 8.000 ± 0% -75.00% (p=0.000 n=10) Int64SliceValue-8 88.00 ± 0% 64.00 ± 0% -27.27% (p=0.000 n=10) Float64SliceValue-8 88.00 ± 0% 64.00 ± 0% -27.27% (p=0.000 n=10) StringSliceValue-8 152.0 ± 0% 128.0 ± 0% -15.79% (p=0.000 n=10) geomean 78.34 45.25 -42.23% │ old.txt │ new.txt │ │ allocs/op │ allocs/op vs base │ BoolSliceValue-8 3.000 ± 0% 2.000 ± 0% -33.33% (p=0.000 n=10) Int64SliceValue-8 3.000 ± 0% 2.000 ± 0% -33.33% (p=0.000 n=10) Float64SliceValue-8 3.000 ± 0% 2.000 ± 0% -33.33% (p=0.000 n=10) StringSliceValue-8 3.000 ± 0% 2.000 ± 0% -33.33% (p=0.000 n=10) geomean 3.000 2.000 -33.33% ``` --- CHANGELOG.md | 1 + internal/attribute/attribute.go | 24 ++++++++--------- internal/attribute/attribute_test.go | 39 ++++++++++++++++++++++++++++ 3 files changed, 52 insertions(+), 12 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index dbb24146fa8..6d287e9f25c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -33,6 +33,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ### Fixed +- Improved performance in all `{Bool,Int64,Float64,String}SliceValue` function of `go.opentelemetry.io/attributes` by reducing the number of allocations. (#5549) - Retry trace and span ID generation if it generated an invalid one in `go.opentelemetry.io/otel/sdk/trace`. (#5514) - Log a warning to the OpenTelemetry internal logger when a `Record` in `go.opentelemetry.io/otel/sdk/log` drops an attribute due to a limit being reached. (#5376) - Identify the `Tracer` returned from the global `TracerProvider` in `go.opentelemetry.io/otel/global` with its schema URL. (#5426) diff --git a/internal/attribute/attribute.go b/internal/attribute/attribute.go index f32766e57f6..822d8479474 100644 --- a/internal/attribute/attribute.go +++ b/internal/attribute/attribute.go @@ -14,33 +14,33 @@ import ( // BoolSliceValue converts a bool slice into an array with same elements as slice. func BoolSliceValue(v []bool) interface{} { var zero bool - cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))) - copy(cp.Elem().Slice(0, len(v)).Interface().([]bool), v) - return cp.Elem().Interface() + cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))).Elem() + reflect.Copy(cp, reflect.ValueOf(v)) + return cp.Interface() } // Int64SliceValue converts an int64 slice into an array with same elements as slice. func Int64SliceValue(v []int64) interface{} { var zero int64 - cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))) - copy(cp.Elem().Slice(0, len(v)).Interface().([]int64), v) - return cp.Elem().Interface() + cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))).Elem() + reflect.Copy(cp, reflect.ValueOf(v)) + return cp.Interface() } // Float64SliceValue converts a float64 slice into an array with same elements as slice. func Float64SliceValue(v []float64) interface{} { var zero float64 - cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))) - copy(cp.Elem().Slice(0, len(v)).Interface().([]float64), v) - return cp.Elem().Interface() + cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))).Elem() + reflect.Copy(cp, reflect.ValueOf(v)) + return cp.Interface() } // StringSliceValue converts a string slice into an array with same elements as slice. func StringSliceValue(v []string) interface{} { var zero string - cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))) - copy(cp.Elem().Slice(0, len(v)).Interface().([]string), v) - return cp.Elem().Interface() + cp := reflect.New(reflect.ArrayOf(len(v), reflect.TypeOf(zero))).Elem() + reflect.Copy(cp, reflect.ValueOf(v)) + return cp.Interface() } // AsBoolSlice converts a bool array into a slice into with same elements as array. diff --git a/internal/attribute/attribute_test.go b/internal/attribute/attribute_test.go index 7202700cac1..113b644c80e 100644 --- a/internal/attribute/attribute_test.go +++ b/internal/attribute/attribute_test.go @@ -94,3 +94,42 @@ func TestSliceValue(t *testing.T) { }) } } + +// sync is a global used to ensure the benchmark are not optimized away. +var sync any + +func BenchmarkBoolSliceValue(b *testing.B) { + b.ReportAllocs() + s := []bool{true, false, true, false} + b.ResetTimer() + for n := 0; n < b.N; n++ { + sync = BoolSliceValue(s) + } +} + +func BenchmarkInt64SliceValue(b *testing.B) { + b.ReportAllocs() + s := []int64{1, 2, 3, 4} + b.ResetTimer() + for n := 0; n < b.N; n++ { + sync = Int64SliceValue(s) + } +} + +func BenchmarkFloat64SliceValue(b *testing.B) { + b.ReportAllocs() + s := []float64{1.2, 3.4, 5.6, 7.8} + b.ResetTimer() + for n := 0; n < b.N; n++ { + sync = Float64SliceValue(s) + } +} + +func BenchmarkStringSliceValue(b *testing.B) { + b.ReportAllocs() + s := []string{"a", "b", "c", "d"} + b.ResetTimer() + for n := 0; n < b.N; n++ { + sync = StringSliceValue(s) + } +}