Skip to content

Commit f8a288c

Browse files
Amy TobeyKrzysztof Sinica
andauthored
Merge pull request #53 from ksinica/context-embedding
Actually authored by @ksinica, I'm just committing to work around permissions things. This pull request adds two features: context.Context embedding of the logger instance workaround for protobuf messages being flattened to strings when embedded as a fields * Add context embedding and protobuf workaround. * Increase test coverage. --------- Co-authored-by: Krzysztof Sinica <krzysztof.sinica@codilime.com>
2 parents 3874146 + 36d5f93 commit f8a288c

6 files changed

Lines changed: 306 additions & 3 deletions

File tree

go.mod

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,8 +22,10 @@ require (
2222
golang.org/x/net v0.0.0-20211015210444-4f30a5c0130f // indirect
2323
golang.org/x/sys v0.0.0-20211015200801-69063c4bb744 // indirect
2424
golang.org/x/text v0.3.7 // indirect
25+
golang.org/x/tools v0.1.5
2526
google.golang.org/genproto v0.0.0-20211018162055-cf77aa76bad2 // indirect
2627
google.golang.org/grpc v1.41.0
2728
google.golang.org/grpc/examples v0.0.0-20210728214646-ad0a2a847cdf
29+
google.golang.org/protobuf v1.27.1
2830
mvdan.cc/gofumpt v0.1.1
2931
)

go.sum

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -210,6 +210,7 @@ github.com/prometheus/procfs v0.7.3 h1:4jVXhlkAyzOScmCkXBTOLRLTz8EeU+eyjrwB/EPq0
210210
github.com/prometheus/procfs v0.7.3/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1xBZuNvfVA=
211211
github.com/rogpeppe/fastuuid v1.2.0/go.mod h1:jVj6XXZzXRy/MSR5jhDC/2q6DgLz+nrA6LYCDYWNEvQ=
212212
github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4=
213+
github.com/rogpeppe/go-internal v1.6.2 h1:aIihoIOHCiLZHxyoNQ+ABL4NKhFTgKLBdMLyEAh98m0=
213214
github.com/rogpeppe/go-internal v1.6.2/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTEfhy4qGm1nDQc=
214215
github.com/rollbar/rollbar-go v1.4.2 h1:UzxjFgg9CFE0Vb3grGPpZHCnbKzNd8RYFtFHEKovauU=
215216
github.com/rollbar/rollbar-go v1.4.2/go.mod h1:kLQ9gP3WCRGrvJmF0ueO3wK9xWocej8GRX98D8sa39w=
@@ -226,8 +227,6 @@ github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UV
226227
github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4=
227228
github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA=
228229
github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY=
229-
github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY=
230-
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
231230
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
232231
github.com/tinkerbell/lint-install v0.0.0-20211012174934-5ee5ab01db76 h1:XFtCcjMWRMVO1rzZYPHR3OZ4aUOOtqu0H3v0KtNkURE=
233232
github.com/tinkerbell/lint-install v0.0.0-20211012174934-5ee5ab01db76/go.mod h1:0h2KsALaQLNkoVeV+G+HjBWWCnp0COFYhJdRd5WCQPM=
@@ -250,7 +249,6 @@ go.opentelemetry.io/otel/trace v1.0.1/go.mod h1:5g4i4fKLaX2BQpSBsxw8YYcgKpMMSW3x
250249
go.opentelemetry.io/proto/otlp v0.7.0/go.mod h1:PqfVotwruBrMGOCsRd/89rSnXhoiJIqeYNgFYFoEGnI=
251250
go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE=
252251
go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
253-
go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
254252
go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE=
255253
go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
256254
go.uber.org/goleak v1.1.11-0.20210813005559-691160354723 h1:sHOAIxRGBp443oHZIPB+HsUGaksVCXVQENPxwTfQdH4=
@@ -551,6 +549,7 @@ gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8
551549
gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
552550
gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 h1:YR8cESwS4TdDjEe65xsg0ogRM/Nc3DYOhEAlW+xobZo=
553551
gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
552+
gopkg.in/errgo.v2 v2.1.0 h1:0vLT13EuvQ0hNvakwLuFZ/jYrLp5F3kcWHXdRggjCE8=
554553
gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI=
555554
gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
556555
gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=

log/context.go

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,23 @@
1+
package log
2+
3+
import (
4+
"context"
5+
6+
"go.uber.org/zap"
7+
)
8+
9+
type ctxLogger struct{}
10+
11+
// ContextWithLogger returns a copy of parent in which the logger is embedded.
12+
func ContextWithLogger(ctx context.Context, logger Logger) context.Context {
13+
return context.WithValue(ctx, ctxLogger{}, logger)
14+
}
15+
16+
// GetLogger returns the logger associated with this context, or no-op logger
17+
// if no logger is embedded with key.
18+
func GetLogger(ctx context.Context) Logger {
19+
if logger, ok := ctx.Value(ctxLogger{}).(Logger); ok {
20+
return logger
21+
}
22+
return Logger{s: zap.NewNop().Sugar()}
23+
}

log/context_test.go

Lines changed: 75 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,75 @@
1+
package log
2+
3+
import (
4+
"context"
5+
"reflect"
6+
"testing"
7+
8+
"go.uber.org/zap"
9+
"go.uber.org/zap/zapcore"
10+
"go.uber.org/zap/zaptest/observer"
11+
)
12+
13+
func TestGetLoggerNoop(t *testing.T) {
14+
ctx := context.Background()
15+
16+
GetLogger(ctx).Info("this message should not be visible")
17+
}
18+
19+
func TestContextEmbedding(t *testing.T) {
20+
bar := func(ctx context.Context) {
21+
GetLogger(ctx).Info("bar called")
22+
}
23+
24+
foo := func(ctx context.Context) {
25+
logger := GetLogger(ctx)
26+
27+
logger.Info("foo called")
28+
29+
ctx = ContextWithLogger(ctx, logger.With("baz", "quux"))
30+
bar(ctx)
31+
}
32+
33+
enabler := zap.NewAtomicLevelAt(zap.InfoLevel)
34+
core, logs := observer.New(enabler)
35+
36+
logger, err := configureLogger(zap.New(core), "test")
37+
if err != nil {
38+
t.Fatal(err)
39+
}
40+
defer logger.Close()
41+
42+
foo(ContextWithLogger(context.Background(), logger))
43+
44+
if logs.Len() != 2 {
45+
t.Errorf("unexpected entry count: %d", logs.Len())
46+
t.FailNow()
47+
}
48+
49+
entries := logs.TakeAll()
50+
51+
for i, expected := range []struct {
52+
fields []zapcore.Field
53+
message string
54+
}{
55+
{
56+
fields: []zapcore.Field{zap.String("service", "test")},
57+
message: "foo called",
58+
},
59+
{
60+
fields: []zapcore.Field{
61+
zap.String("service", "test"),
62+
zap.String("baz", "quux"),
63+
},
64+
message: "bar called",
65+
},
66+
} {
67+
if !reflect.DeepEqual(expected.fields, entries[i].Context) {
68+
t.Errorf("fields don't match, expected: %v, got: %v", expected.fields, entries[i].Context)
69+
}
70+
71+
if expected.message != entries[i].Message {
72+
t.Errorf("messages don't match, expected: %s, got: %s", expected.message, entries[i].Message)
73+
}
74+
}
75+
}

log/protobuf.go

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
package log
2+
3+
import (
4+
"encoding/json"
5+
6+
"google.golang.org/protobuf/encoding/protojson"
7+
"google.golang.org/protobuf/proto"
8+
)
9+
10+
type protoMessageWrapper struct {
11+
msg proto.Message
12+
}
13+
14+
func (p *protoMessageWrapper) MarshalJSON() ([]byte, error) {
15+
return protojson.Marshal(p.msg)
16+
}
17+
18+
// ProtoAsJSON performs a type erasure of proto.Message to be embedded into the log fields.
19+
//
20+
// This is a workaround for types generated by protobuf providing a String() method.
21+
// This makes them interpreted by the logger as fmt.Stringer interfaces,
22+
// and flattened to string, rather than, as one would expect, a JSON object.
23+
//
24+
// Example:
25+
//
26+
// logger = logger.With("my-proto-object", log.ProtoAsJSON(&myProto))
27+
func ProtoAsJSON(message proto.Message) json.Marshaler {
28+
return &protoMessageWrapper{msg: message}
29+
}

log/protobuf_test.go

Lines changed: 175 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,175 @@
1+
package log
2+
3+
import (
4+
"reflect"
5+
"sync"
6+
"testing"
7+
8+
"go.uber.org/zap"
9+
"go.uber.org/zap/zapcore"
10+
"go.uber.org/zap/zaptest/observer"
11+
"google.golang.org/protobuf/reflect/protoreflect"
12+
"google.golang.org/protobuf/runtime/protoimpl"
13+
)
14+
15+
const (
16+
// Verify that this generated code is sufficiently up-to-date.
17+
_ = protoimpl.EnforceVersion(20 - protoimpl.MinVersion)
18+
// Verify that runtime/protoimpl is sufficiently up-to-date.
19+
_ = protoimpl.EnforceVersion(protoimpl.MaxVersion - 20)
20+
)
21+
22+
type ProtoTest struct {
23+
state protoimpl.MessageState
24+
sizeCache protoimpl.SizeCache
25+
unknownFields protoimpl.UnknownFields
26+
27+
Foo string `protobuf:"bytes,1,opt,name=foo,proto3" json:"foo,omitempty"`
28+
}
29+
30+
func (x *ProtoTest) Reset() {
31+
*x = ProtoTest{}
32+
if protoimpl.UnsafeEnabled {
33+
mi := &file_p_proto_msgTypes[0]
34+
ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x))
35+
ms.StoreMessageInfo(mi)
36+
}
37+
}
38+
39+
func (x *ProtoTest) String() string {
40+
return protoimpl.X.MessageStringOf(x)
41+
}
42+
43+
func (*ProtoTest) ProtoMessage() {}
44+
45+
func (x *ProtoTest) ProtoReflect() protoreflect.Message {
46+
mi := &file_p_proto_msgTypes[0]
47+
if protoimpl.UnsafeEnabled && x != nil {
48+
ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x))
49+
if ms.LoadMessageInfo() == nil {
50+
ms.StoreMessageInfo(mi)
51+
}
52+
return ms
53+
}
54+
return mi.MessageOf(x)
55+
}
56+
57+
// Deprecated: Use ProtoTest.ProtoReflect.Descriptor instead.
58+
func (*ProtoTest) Descriptor() ([]byte, []int) {
59+
return file_p_proto_rawDescGZIP(), []int{0}
60+
}
61+
62+
func (x *ProtoTest) GetFoo() string {
63+
if x != nil {
64+
return x.Foo
65+
}
66+
return ""
67+
}
68+
69+
var File_p_proto protoreflect.FileDescriptor
70+
71+
var file_p_proto_rawDesc = []byte{
72+
0x0a, 0x07, 0x70, 0x2e, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x22, 0x1d, 0x0a, 0x09, 0x50, 0x72, 0x6f,
73+
0x74, 0x6f, 0x54, 0x65, 0x73, 0x74, 0x12, 0x10, 0x0a, 0x03, 0x66, 0x6f, 0x6f, 0x18, 0x01, 0x20,
74+
0x01, 0x28, 0x09, 0x52, 0x03, 0x66, 0x6f, 0x6f, 0x42, 0x0a, 0x5a, 0x08, 0x2e, 0x2f, 0x70, 0x72,
75+
0x6f, 0x74, 0x6f, 0x6c, 0x62, 0x06, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x33,
76+
}
77+
78+
var (
79+
file_p_proto_rawDescOnce sync.Once
80+
file_p_proto_rawDescData = file_p_proto_rawDesc
81+
)
82+
83+
func file_p_proto_rawDescGZIP() []byte {
84+
file_p_proto_rawDescOnce.Do(func() {
85+
file_p_proto_rawDescData = protoimpl.X.CompressGZIP(file_p_proto_rawDescData)
86+
})
87+
return file_p_proto_rawDescData
88+
}
89+
90+
var file_p_proto_msgTypes = make([]protoimpl.MessageInfo, 1)
91+
var file_p_proto_goTypes = []interface{}{
92+
(*ProtoTest)(nil), // 0: ProtoTest
93+
}
94+
var file_p_proto_depIdxs = []int32{
95+
0, // [0:0] is the sub-list for method output_type
96+
0, // [0:0] is the sub-list for method input_type
97+
0, // [0:0] is the sub-list for extension type_name
98+
0, // [0:0] is the sub-list for extension extendee
99+
0, // [0:0] is the sub-list for field type_name
100+
}
101+
102+
func init() { file_p_proto_init() }
103+
func file_p_proto_init() {
104+
if File_p_proto != nil {
105+
return
106+
}
107+
if !protoimpl.UnsafeEnabled {
108+
file_p_proto_msgTypes[0].Exporter = func(v interface{}, i int) interface{} {
109+
switch v := v.(*ProtoTest); i {
110+
case 0:
111+
return &v.state
112+
case 1:
113+
return &v.sizeCache
114+
case 2:
115+
return &v.unknownFields
116+
default:
117+
return nil
118+
}
119+
}
120+
}
121+
type x struct{}
122+
out := protoimpl.TypeBuilder{
123+
File: protoimpl.DescBuilder{
124+
GoPackagePath: reflect.TypeOf(x{}).PkgPath(),
125+
RawDescriptor: file_p_proto_rawDesc,
126+
NumEnums: 0,
127+
NumMessages: 1,
128+
NumExtensions: 0,
129+
NumServices: 0,
130+
},
131+
GoTypes: file_p_proto_goTypes,
132+
DependencyIndexes: file_p_proto_depIdxs,
133+
MessageInfos: file_p_proto_msgTypes,
134+
}.Build()
135+
File_p_proto = out.File
136+
file_p_proto_rawDesc = nil
137+
file_p_proto_goTypes = nil
138+
file_p_proto_depIdxs = nil
139+
}
140+
141+
func TestProtoAsJSON(t *testing.T) {
142+
enabler := zap.NewAtomicLevelAt(zap.InfoLevel)
143+
core, logs := observer.New(enabler)
144+
145+
logger, err := configureLogger(zap.New(core), "test")
146+
if err != nil {
147+
t.Fatal(err)
148+
}
149+
defer logger.Close()
150+
151+
var val ProtoTest
152+
val.Foo = "bar"
153+
154+
logger.With("proto_field", ProtoAsJSON(&val)).Info("ignore this message")
155+
156+
if cnt := logs.Len(); cnt != 1 {
157+
t.Errorf("unexpected entry count: %d", cnt)
158+
t.FailNow()
159+
}
160+
161+
entries := logs.TakeAll()
162+
163+
if cnt := len(entries[0].Context); cnt != 2 {
164+
t.Errorf("unexpected field count: %d", cnt)
165+
t.FailNow()
166+
}
167+
168+
if name := entries[0].Context[1].Key; name != "proto_field" {
169+
t.Errorf("unexpected field name: %s", name)
170+
}
171+
172+
if typ := entries[0].Context[1].Type; typ != zapcore.ReflectType {
173+
t.Errorf("unexpected field type: %v", typ)
174+
}
175+
}

0 commit comments

Comments
 (0)