diff --git a/bridges/otellogr/convert.go b/bridges/otellogr/convert.go new file mode 100644 index 00000000000..35a79e5248f --- /dev/null +++ b/bridges/otellogr/convert.go @@ -0,0 +1,156 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package otellogr // import "go.opentelemetry.io/contrib/bridges/otellogr" + +import ( + "context" + "fmt" + "math" + "reflect" + "strconv" + "time" + + "go.opentelemetry.io/otel/log" +) + +// convertKVs converts a list of key-value pairs to a list of [log.KeyValue]. +// The last [context.Context] value is returned as the context. +// If no context is found, the original context is returned. +func convertKVs(ctx context.Context, keysAndValues ...any) (context.Context, []log.KeyValue) { + if len(keysAndValues) == 0 { + return ctx, nil + } + if len(keysAndValues)%2 != 0 { + // Ensure an odd number of items here does not corrupt the list. + keysAndValues = append(keysAndValues, nil) + } + + kvs := make([]log.KeyValue, 0, len(keysAndValues)/2) + for i := 0; i < len(keysAndValues); i += 2 { + k, ok := keysAndValues[i].(string) + if !ok { + // Ensure that the key is a string. + k = fmt.Sprintf("%v", keysAndValues[i]) + } + + v := keysAndValues[i+1] + if vCtx, ok := v.(context.Context); ok { + // Special case when a field is of context.Context type. + ctx = vCtx + continue + } + + kvs = append(kvs, log.KeyValue{ + Key: k, + Value: convertValue(v), + }) + } + + return ctx, kvs +} + +func convertValue(v any) log.Value { + // Handling the most common types without reflect is a small perf win. + switch val := v.(type) { + case bool: + return log.BoolValue(val) + case string: + return log.StringValue(val) + case int: + return log.Int64Value(int64(val)) + case int8: + return log.Int64Value(int64(val)) + case int16: + return log.Int64Value(int64(val)) + case int32: + return log.Int64Value(int64(val)) + case int64: + return log.Int64Value(val) + case uint: + return convertUintValue(uint64(val)) + case uint8: + return log.Int64Value(int64(val)) + case uint16: + return log.Int64Value(int64(val)) + case uint32: + return log.Int64Value(int64(val)) + case uint64: + return convertUintValue(val) + case uintptr: + return convertUintValue(uint64(val)) + case float32: + return log.Float64Value(float64(val)) + case float64: + return log.Float64Value(val) + case time.Duration: + return log.Int64Value(val.Nanoseconds()) + case complex64: + r := log.Float64("r", real(complex128(val))) + i := log.Float64("i", imag(complex128(val))) + return log.MapValue(r, i) + case complex128: + r := log.Float64("r", real(val)) + i := log.Float64("i", imag(val)) + return log.MapValue(r, i) + case time.Time: + return log.Int64Value(val.UnixNano()) + case []byte: + return log.BytesValue(val) + case error: + return log.StringValue(val.Error()) + } + + t := reflect.TypeOf(v) + if t == nil { + return log.Value{} + } + val := reflect.ValueOf(v) + switch t.Kind() { + case reflect.Struct: + return log.StringValue(fmt.Sprintf("%+v", v)) + case reflect.Slice, reflect.Array: + items := make([]log.Value, 0, val.Len()) + for i := 0; i < val.Len(); i++ { + items = append(items, convertValue(val.Index(i).Interface())) + } + return log.SliceValue(items...) + case reflect.Map: + kvs := make([]log.KeyValue, 0, val.Len()) + for _, k := range val.MapKeys() { + var key string + switch k.Kind() { + case reflect.String: + key = k.String() + default: + key = fmt.Sprintf("%+v", k.Interface()) + } + kvs = append(kvs, log.KeyValue{ + Key: key, + Value: convertValue(val.MapIndex(k).Interface()), + }) + } + return log.MapValue(kvs...) + case reflect.Ptr, reflect.Interface: + if val.IsNil() { + return log.Value{} + } + return convertValue(val.Elem().Interface()) + } + + // Try to handle this as gracefully as possible. + // + // Don't panic here. it is preferable to have user's open issue + // asking why their attributes have a "unhandled: " prefix than + // say that their code is panicking. + return log.StringValue(fmt.Sprintf("unhandled: (%s) %+v", t, v)) +} + +// convertUintValue converts a uint64 to a log.Value. +// If the value is too large to fit in an int64, it is converted to a string. +func convertUintValue(v uint64) log.Value { + if v > math.MaxInt64 { + return log.StringValue(strconv.FormatUint(v, 10)) + } + return log.Int64Value(int64(v)) +} diff --git a/bridges/otellogr/convert_test.go b/bridges/otellogr/convert_test.go new file mode 100644 index 00000000000..bec3f4c4405 --- /dev/null +++ b/bridges/otellogr/convert_test.go @@ -0,0 +1,313 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package otellogr + +import ( + "context" + "errors" + "fmt" + "testing" + "time" + + "github.com/stretchr/testify/assert" + + "go.opentelemetry.io/otel/log" +) + +func TestConvertKVs(t *testing.T) { + ctx := context.WithValue(context.Background(), "key", "value") // nolint: revive,staticcheck // test context + + for _, tt := range []struct { + name string + kvs []any + wantKVs []log.KeyValue + wantCtx context.Context + }{ + { + name: "empty", + kvs: []any{}, + }, + { + name: "single_value", + kvs: []any{"key", "value"}, + wantKVs: []log.KeyValue{ + log.String("key", "value"), + }, + }, + { + name: "multiple_values", + kvs: []any{"key1", "value1", "key2", "value2"}, + wantKVs: []log.KeyValue{ + log.String("key1", "value1"), + log.String("key2", "value2"), + }, + }, + { + name: "missing_value", + kvs: []any{"key1", "value1", "key2"}, + wantKVs: []log.KeyValue{ + log.String("key1", "value1"), + {Key: "key2", Value: log.Value{}}, + }, + }, + { + name: "key_not_string", + kvs: []any{42, "value"}, + wantKVs: []log.KeyValue{ + log.String("42", "value"), + }, + }, + { + name: "context", + kvs: []any{"ctx", ctx, "key", "value"}, + wantKVs: []log.KeyValue{log.String("key", "value")}, + wantCtx: ctx, + }, + { + name: "last_context", + kvs: []any{"key", context.Background(), "ctx", ctx}, + wantKVs: []log.KeyValue{}, + wantCtx: ctx, + }, + } { + t.Run(tt.name, func(t *testing.T) { + ctx, kvs := convertKVs(nil, tt.kvs...) // nolint: staticcheck // pass nil context + assert.Equal(t, tt.wantKVs, kvs) + assert.Equal(t, tt.wantCtx, ctx) + }) + } +} + +func TestConvertValue(t *testing.T) { + for _, tt := range []struct { + name string + value any + wantValue log.Value + }{ + { + name: "bool", + value: true, + wantValue: log.BoolValue(true), + }, + { + name: "string", + value: "value", + wantValue: log.StringValue("value"), + }, + { + name: "int", + value: 10, + wantValue: log.Int64Value(10), + }, + { + name: "int8", + value: int8(127), + wantValue: log.Int64Value(127), + }, + { + name: "int16", + value: int16(32767), + wantValue: log.Int64Value(32767), + }, + { + name: "int32", + value: int32(2147483647), + wantValue: log.Int64Value(2147483647), + }, + { + name: "int64", + value: int64(9223372036854775807), + wantValue: log.Int64Value(9223372036854775807), + }, + { + name: "uint", + value: uint(42), + wantValue: log.Int64Value(42), + }, + { + name: "uint8", + value: uint8(255), + wantValue: log.Int64Value(255), + }, + { + name: "uint16", + value: uint16(65535), + wantValue: log.Int64Value(65535), + }, + { + name: "uint32", + value: uint32(4294967295), + wantValue: log.Int64Value(4294967295), + }, + { + name: "uint64", + value: uint64(9223372036854775807), + wantValue: log.Int64Value(9223372036854775807), + }, + { + name: "uint64-max", + value: uint64(18446744073709551615), + wantValue: log.StringValue("18446744073709551615"), + }, + { + name: "uintptr", + value: uintptr(12345), + wantValue: log.Int64Value(12345), + }, + { + name: "float64", + value: float64(3.14159), + wantValue: log.Float64Value(3.14159), + }, + { + name: "time.Duration", + value: time.Second, + wantValue: log.Int64Value(1_000_000_000), + }, + { + name: "complex64", + value: complex64(complex(float32(1), float32(2))), + wantValue: log.MapValue(log.Float64("r", 1), log.Float64("i", 2)), + }, + { + name: "complex128", + value: complex(float64(3), float64(4)), + wantValue: log.MapValue(log.Float64("r", 3), log.Float64("i", 4)), + }, + { + name: "time.Time", + value: time.Unix(1000, 1000), + wantValue: log.Int64Value(time.Unix(1000, 1000).UnixNano()), + }, + { + name: "[]byte", + value: []byte("hello"), + wantValue: log.BytesValue([]byte("hello")), + }, + { + name: "error", + value: errors.New("test error"), + wantValue: log.StringValue("test error"), + }, + { + name: "error", + value: errors.New("test error"), + wantValue: log.StringValue("test error"), + }, + { + name: "error-nested", + value: fmt.Errorf("test error: %w", errors.New("nested error")), + wantValue: log.StringValue("test error: nested error"), + }, + { + name: "nil", + value: nil, + wantValue: log.Value{}, + }, + { + name: "nil_ptr", + value: (*int)(nil), + wantValue: log.Value{}, + }, + { + name: "int_ptr", + value: func() *int { i := 93; return &i }(), + wantValue: log.Int64Value(93), + }, + { + name: "string_ptr", + value: func() *string { s := "hello"; return &s }(), + wantValue: log.StringValue("hello"), + }, + { + name: "bool_ptr", + value: func() *bool { b := true; return &b }(), + wantValue: log.BoolValue(true), + }, + { + name: "int_empty_array", + value: []int{}, + wantValue: log.SliceValue([]log.Value{}...), + }, + { + name: "int_array", + value: []int{1, 2, 3}, + wantValue: log.SliceValue([]log.Value{ + log.Int64Value(1), + log.Int64Value(2), + log.Int64Value(3), + }...), + }, + { + name: "key_value_map", + value: map[string]int{"one": 1}, + wantValue: log.MapValue( + log.Int64("one", 1), + ), + }, + { + name: "int_string_map", + value: map[int]string{1: "one"}, + wantValue: log.MapValue( + log.String("1", "one"), + ), + }, + { + name: "nested_map", + value: map[string]map[string]int{"nested": {"one": 1}}, + wantValue: log.MapValue( + log.Map("nested", + log.Int64("one", 1), + ), + ), + }, + { + name: "struct_key_map", + value: map[struct{ Name string }]int{ + {Name: "John"}: 42, + }, + wantValue: log.MapValue( + log.Int64("{Name:John}", 42), + ), + }, + { + name: "struct", + value: struct { + Name string + Age int + }{ + Name: "John", + Age: 42, + }, + wantValue: log.StringValue("{Name:John Age:42}"), + }, + { + name: "struct_ptr", + value: &struct { + Name string + Age int + }{ + Name: "John", + Age: 42, + }, + wantValue: log.StringValue("{Name:John Age:42}"), + }, + { + name: "ctx", + value: context.Background(), + wantValue: log.StringValue("context.Background"), + }, + } { + t.Run(tt.name, func(t *testing.T) { + assert.Equal(t, convertValue(tt.value), tt.wantValue) + }) + } +} + +func TestConvertValueFloat32(t *testing.T) { + value := convertValue(float32(3.14)) + want := log.Float64Value(3.14) + + assert.InDelta(t, value.AsFloat64(), want.AsFloat64(), 0.0001) +} diff --git a/bridges/otellogr/logsink.go b/bridges/otellogr/logsink.go index 0a2270e4056..1acd6c55e56 100644 --- a/bridges/otellogr/logsink.go +++ b/bridges/otellogr/logsink.go @@ -4,10 +4,48 @@ // Package otellogr provides a [LogSink], a [logr.LogSink] implementation that // can be used to bridge between the [logr] API and [OpenTelemetry]. // +// # Record Conversion +// +// The logr records are converted to OpenTelemetry [log.Record] in the following +// way: +// +// - Message is set as the Body using a [log.StringValue]. +// - TODO: Level +// - KeyAndValues are transformed and set as Attributes. +// - The [context.Context] value in KeyAndValues is propagated to OpenTelemetry +// log record. All non-nested [context.Context] values are ignored and not +// added as attributes. If there are multiple [context.Context] the last one +// is used. +// +// KeysAndValues values are transformed based on their type. The following types are +// supported: +// +// - [bool] are transformed to [log.BoolValue]. +// - [string] are transformed to [log.StringValue]. +// - [int], [int8], [int16], [int32], [int64] are transformed to +// [log.Int64Value]. +// - [uint], [uint8], [uint16], [uint32], [uint64], [uintptr] are transformed +// to [log.Int64Value] or [log.StringValue] if the value is too large. +// - [float32], [float64] are transformed to [log.Float64Value]. +// - [time.Duration] are transformed to [log.Int64Value] with the nanoseconds. +// - [complex64], [complex128] are transformed to [log.MapValue] with the keys +// "r" and "i" for the real and imaginary parts. The values are +// [log.Float64Value]. +// - [time.Time] are transformed to [log.Int64Value] with the nanoseconds. +// - [[]byte] are transformed to [log.BytesValue]. +// - [error] are transformed to [log.StringValue] with the error message. +// - [nil] are transformed to an empty [log.Value]. +// - [struct] are transformed to [log.StringValue] with the struct fields. +// - [slice], [array] are transformed to [log.SliceValue] with the elements. +// - [map] are transformed to [log.MapValue] with the key-value pairs. +// - [pointer], [interface] are transformed to the dereferenced value. +// // [OpenTelemetry]: https://opentelemetry.io/docs/concepts/signals/logs/ package otellogr // import "go.opentelemetry.io/contrib/bridges/otellogr" import ( + "context" + "github.com/go-logr/logr" "go.opentelemetry.io/otel/log" @@ -33,17 +71,6 @@ func newConfig(options []Option) config { return c } -func (c config) logger(name string) log.Logger { - var opts []log.LoggerOption - if c.version != "" { - opts = append(opts, log.WithInstrumentationVersion(c.version)) - } - if c.schemaURL != "" { - opts = append(opts, log.WithSchemaURL(c.schemaURL)) - } - return c.provider.Logger(name, opts...) -} - // Option configures a [LogSink]. type Option interface { apply(config) config @@ -54,7 +81,7 @@ type optFunc func(config) config func (f optFunc) apply(c config) config { return f(c) } // WithVersion returns an [Option] that configures the version of the -// [log.Logger] used by a [Hook]. The version should be the version of the +// [log.Logger] used by a [LogSink]. The version should be the version of the // package that is being logged. func WithVersion(version string) Option { return optFunc(func(c config) config { @@ -64,7 +91,7 @@ func WithVersion(version string) Option { } // WithSchemaURL returns an [Option] that configures the semantic convention -// schema URL of the [log.Logger] used by a [Hook]. The schemaURL should be +// schema URL of the [log.Logger] used by a [LogSink]. The schemaURL should be // the schema URL for the semantic conventions used in log records. func WithSchemaURL(schemaURL string) Option { return optFunc(func(c config) config { @@ -87,13 +114,24 @@ func WithLoggerProvider(provider log.LoggerProvider) Option { // NewLogSink returns a new [LogSink] to be used as a [logr.LogSink]. // -// If [WithLoggerProvider] is not provided, the returned LogSink will use the +// If [WithLoggerProvider] is not provided, the returned [LogSink] will use the // global LoggerProvider. func NewLogSink(name string, options ...Option) *LogSink { c := newConfig(options) + + var opts []log.LoggerOption + if c.version != "" { + opts = append(opts, log.WithInstrumentationVersion(c.version)) + } + if c.schemaURL != "" { + opts = append(opts, log.WithSchemaURL(c.schemaURL)) + } + return &LogSink{ - name: name, - logger: c.logger(name), + name: name, + provider: c.provider, + logger: c.provider.Logger(name, opts...), + opts: opts, } } @@ -103,8 +141,12 @@ type LogSink struct { // Ensure forward compatibility by explicitly making this not comparable. noCmp [0]func() //nolint: unused // This is indeed used. - name string - logger log.Logger + name string + provider log.LoggerProvider + logger log.Logger + opts []log.LoggerOption + attr []log.KeyValue + ctx context.Context } // Compile-time check *Handler implements logr.LogSink. @@ -125,7 +167,16 @@ func (l *LogSink) Error(err error, msg string, keysAndValues ...any) { // Info logs a non-error message with the given key/value pairs. func (l *LogSink) Info(level int, msg string, keysAndValues ...any) { - // TODO + var record log.Record + record.SetBody(log.StringValue(msg)) + record.SetSeverity(log.SeverityInfo) // TODO: level + + record.AddAttributes(l.attr...) + + ctx, attr := convertKVs(l.ctx, keysAndValues...) + record.AddAttributes(attr...) + + l.logger.Emit(ctx, record) } // Init initializes the LogSink. @@ -135,12 +186,15 @@ func (l *LogSink) Init(info logr.RuntimeInfo) { // WithName returns a new LogSink with the specified name appended. func (l LogSink) WithName(name string) logr.LogSink { - // TODO + l.name = l.name + "/" + name + l.logger = l.provider.Logger(l.name, l.opts...) return &l } // WithValues returns a new LogSink with additional key/value pairs. func (l LogSink) WithValues(keysAndValues ...any) logr.LogSink { - // TODO + ctx, attr := convertKVs(l.ctx, keysAndValues...) + l.attr = append(l.attr, attr...) + l.ctx = ctx return &l } diff --git a/bridges/otellogr/logsink_test.go b/bridges/otellogr/logsink_test.go index 59fa5bc7589..8b47f871313 100644 --- a/bridges/otellogr/logsink_test.go +++ b/bridges/otellogr/logsink_test.go @@ -4,12 +4,16 @@ package otellogr import ( "testing" + "time" + "github.com/go-logr/logr" "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" "go.opentelemetry.io/otel/log" "go.opentelemetry.io/otel/log/embedded" "go.opentelemetry.io/otel/log/global" + "go.opentelemetry.io/otel/log/logtest" ) type mockLoggerProvider struct { @@ -65,17 +69,16 @@ func TestNewConfig(t *testing.T) { } func TestNewLogSink(t *testing.T) { - const name = "test_logsink" - provider := global.GetLoggerProvider() + const name = "name" for _, tt := range []struct { - name string - options []Option - wantLogger log.Logger + name string + options []Option + wantScopeRecords *logtest.ScopeRecords }{ { - name: "with default options", - wantLogger: provider.Logger(name), + name: "with default options", + wantScopeRecords: &logtest.ScopeRecords{Name: name}, }, { name: "with version and schema URL", @@ -83,16 +86,180 @@ func TestNewLogSink(t *testing.T) { WithVersion("1.0"), WithSchemaURL("https://example.com"), }, - wantLogger: provider.Logger(name, - log.WithInstrumentationVersion("1.0"), - log.WithSchemaURL("https://example.com"), - ), + wantScopeRecords: &logtest.ScopeRecords{ + Name: name, + Version: "1.0", + SchemaURL: "https://example.com", + }, }, } { t.Run(tt.name, func(t *testing.T) { - hook := NewLogSink(name, tt.options...) - assert.NotNil(t, hook) - assert.Equal(t, tt.wantLogger, hook.logger) + provider := logtest.NewRecorder() + + var l *LogSink + require.NotPanics(t, func() { + l = NewLogSink(name, append( + tt.options, + WithLoggerProvider(provider), + )...) + }) + require.NotNil(t, l) + require.Len(t, provider.Result(), 1) + + got := provider.Result()[0] + assert.Equal(t, tt.wantScopeRecords, got) }) } } + +func TestLogSink(t *testing.T) { + const name = "name" + + for _, tt := range []struct { + name string + f func(*logr.Logger) + wantRecords map[string][]log.Record + }{ + { + name: "no_log", + f: func(l *logr.Logger) {}, + wantRecords: map[string][]log.Record{ + name: {}, + }, + }, + { + name: "info", + f: func(l *logr.Logger) { + l.Info("msg") + }, + wantRecords: map[string][]log.Record{ + name: { + buildRecord(log.StringValue("msg"), time.Time{}, log.SeverityInfo, nil), + }, + }, + }, + { + name: "info_multi_attrs", + f: func(l *logr.Logger) { + l.Info("msg", + "struct", struct{ data int64 }{data: 1}, + "bool", true, + "duration", time.Minute, + "float64", 3.14159, + "int64", -2, + "string", "str", + "time", time.Unix(1000, 1000), + "uint64", uint64(3), + ) + }, + wantRecords: map[string][]log.Record{ + name: { + buildRecord(log.StringValue("msg"), time.Time{}, log.SeverityInfo, []log.KeyValue{ + log.String("struct", "{data:1}"), + log.Bool("bool", true), + log.Int64("duration", 60_000_000_000), + log.Float64("float64", 3.14159), + log.Int64("int64", -2), + log.String("string", "str"), + log.Int64("time", time.Unix(1000, 1000).UnixNano()), + log.Int64("uint64", 3), + }), + }, + }, + }, + { + name: "info_with_name", + f: func(l *logr.Logger) { + l.WithName("test").Info("info message with name") + }, + wantRecords: map[string][]log.Record{ + name + "/test": { + buildRecord(log.StringValue("info message with name"), time.Time{}, log.SeverityInfo, nil), + }, + }, + }, + { + name: "info_with_name_nested", + f: func(l *logr.Logger) { + l.WithName("test").WithName("test").Info("info message with name") + }, + wantRecords: map[string][]log.Record{ + name + "/test/test": { + buildRecord(log.StringValue("info message with name"), time.Time{}, log.SeverityInfo, nil), + }, + }, + }, + { + name: "info_with_attrs", + f: func(l *logr.Logger) { + l.WithValues("key", "value").Info("info message with attrs") + }, + wantRecords: map[string][]log.Record{ + name: { + buildRecord(log.StringValue("info message with attrs"), time.Time{}, log.SeverityInfo, []log.KeyValue{ + log.String("key", "value"), + }), + }, + }, + }, + { + name: "info_with_attrs_nested", + f: func(l *logr.Logger) { + l.WithValues("key1", "value1").Info("info message with attrs", "key2", "value2") + }, + wantRecords: map[string][]log.Record{ + name: { + buildRecord(log.StringValue("info message with attrs"), time.Time{}, log.SeverityInfo, []log.KeyValue{ + log.String("key1", "value1"), + log.String("key2", "value2"), + }), + }, + }, + }, + } { + t.Run(tt.name, func(t *testing.T) { + rec := logtest.NewRecorder() + ls := NewLogSink(name, WithLoggerProvider(rec)) + l := logr.New(ls) + tt.f(&l) + + for k, v := range tt.wantRecords { + found := false + + want := make([]logtest.EmittedRecord, len(v)) + for i := range want { + want[i] = logtest.EmittedRecord{Record: v[i]} + } + + for _, s := range rec.Result() { + if k == s.Name { + assertRecords(t, want, s.Records) + found = true + } + } + + assert.Truef(t, found, "want to find records with a scope named %q", k) + } + }) + } +} + +func buildRecord(body log.Value, timestamp time.Time, severity log.Severity, attrs []log.KeyValue) log.Record { + var record log.Record + record.SetBody(body) + record.SetTimestamp(timestamp) + record.SetSeverity(severity) + record.AddAttributes(attrs...) + + return record +} + +func assertRecords(t *testing.T, want, got []logtest.EmittedRecord) { + t.Helper() + + assert.Equal(t, len(want), len(got)) + + for i, j := range want { + logtest.AssertRecordEqual(t, j.Record, got[i].Record) + } +}