1 package grpc_logrus_test
2
3 import (
4 "io"
5 "testing"
6
7 grpc_logrus "github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
8 "github.com/sirupsen/logrus"
9 "github.com/stretchr/testify/assert"
10 "github.com/stretchr/testify/require"
11 "github.com/stretchr/testify/suite"
12 "google.golang.org/grpc"
13 "google.golang.org/grpc/codes"
14
15 pb_testproto "github.com/grpc-ecosystem/go-grpc-middleware/testing/testproto"
16 )
17
18 func customClientCodeToLevel(c codes.Code) logrus.Level {
19 if c == codes.Unauthenticated {
20
21 return logrus.ErrorLevel
22 }
23 level := grpc_logrus.DefaultClientCodeToLevel(c)
24 return level
25 }
26
27 func TestLogrusClientSuite(t *testing.T) {
28 opts := []grpc_logrus.Option{
29 grpc_logrus.WithLevels(customClientCodeToLevel),
30 }
31 b := newLogrusBaseSuite(t)
32 b.logger.Level = logrus.DebugLevel
33 b.InterceptorTestSuite.ClientOpts = []grpc.DialOption{
34 grpc.WithUnaryInterceptor(grpc_logrus.UnaryClientInterceptor(logrus.NewEntry(b.logger), opts...)),
35 grpc.WithStreamInterceptor(grpc_logrus.StreamClientInterceptor(logrus.NewEntry(b.logger), opts...)),
36 }
37 suite.Run(t, &logrusClientSuite{b})
38 }
39
40 type logrusClientSuite struct {
41 *logrusBaseSuite
42 }
43
44 func (s *logrusClientSuite) TestPing() {
45 _, err := s.Client.Ping(s.SimpleCtx(), goodPing)
46 assert.NoError(s.T(), err, "there must be not be an on a successful call")
47
48 msgs := s.getOutputJSONs()
49 require.Len(s.T(), msgs, 1, "one log statement should be logged")
50
51 assert.Equal(s.T(), msgs[0]["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
52 assert.Equal(s.T(), msgs[0]["grpc.method"], "Ping", "all lines must contain the correct method name")
53 assert.Equal(s.T(), msgs[0]["msg"], "finished client unary call", "handler's message must contain the correct message")
54 assert.Equal(s.T(), msgs[0]["span.kind"], "client", "all lines must contain the kind of call (client)")
55 assert.Equal(s.T(), msgs[0]["level"], "debug", "OK codes must be logged on debug level.")
56
57 assert.Contains(s.T(), msgs[0], "grpc.time_ms", "interceptor log statement should contain execution time (duration in ms)")
58 }
59
60 func (s *logrusClientSuite) TestPingList() {
61 stream, err := s.Client.PingList(s.SimpleCtx(), goodPing)
62 require.NoError(s.T(), err, "should not fail on establishing the stream")
63 for {
64 _, err := stream.Recv()
65 if err == io.EOF {
66 break
67 }
68 require.NoError(s.T(), err, "reading stream should not fail")
69 }
70
71 msgs := s.getOutputJSONs()
72 require.Len(s.T(), msgs, 1, "one log statement should be logged")
73
74 assert.Equal(s.T(), msgs[0]["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
75 assert.Equal(s.T(), msgs[0]["grpc.method"], "PingList", "all lines must contain the correct method name")
76 assert.Equal(s.T(), msgs[0]["msg"], "finished client streaming call", "handler's message must contain the correct message")
77 assert.Equal(s.T(), msgs[0]["span.kind"], "client", "all lines must contain the kind of call (client)")
78 assert.Equal(s.T(), msgs[0]["level"], "debug", "OK codes must be logged on debug level.")
79 assert.Contains(s.T(), msgs[0], "grpc.time_ms", "interceptor log statement should contain execution time (duration in ms)")
80 }
81
82 func (s *logrusClientSuite) TestPingError_WithCustomLevels() {
83 for _, tcase := range []struct {
84 code codes.Code
85 level logrus.Level
86 msg string
87 }{
88 {
89 code: codes.Internal,
90 level: logrus.WarnLevel,
91 msg: "Internal must remap to ErrorLevel in DefaultClientCodeToLevel",
92 },
93 {
94 code: codes.NotFound,
95 level: logrus.DebugLevel,
96 msg: "NotFound must remap to InfoLevel in DefaultClientCodeToLevel",
97 },
98 {
99 code: codes.FailedPrecondition,
100 level: logrus.DebugLevel,
101 msg: "FailedPrecondition must remap to WarnLevel in DefaultClientCodeToLevel",
102 },
103 {
104 code: codes.Unauthenticated,
105 level: logrus.ErrorLevel,
106 msg: "Unauthenticated is overwritten to ErrorLevel with customClientCodeToLevel override, which probably didn't work",
107 },
108 } {
109 s.SetupTest()
110 _, err := s.Client.PingError(
111 s.SimpleCtx(),
112 &pb_testproto.PingRequest{Value: "something", ErrorCodeReturned: uint32(tcase.code)})
113
114 assert.Error(s.T(), err, "each call here must return an error")
115
116 msgs := s.getOutputJSONs()
117 require.Len(s.T(), msgs, 1, "only a single log message is printed")
118
119 assert.Equal(s.T(), msgs[0]["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
120 assert.Equal(s.T(), msgs[0]["grpc.method"], "PingError", "all lines must contain the correct method name")
121 assert.Equal(s.T(), msgs[0]["grpc.code"], tcase.code.String(), "all lines must contain a grpc code")
122 assert.Equal(s.T(), msgs[0]["level"], tcase.level.String(), tcase.msg)
123 }
124 }
125
126 func TestLogrusClientOverrideSuite(t *testing.T) {
127 opts := []grpc_logrus.Option{
128 grpc_logrus.WithDurationField(grpc_logrus.DurationToDurationField),
129 }
130 b := newLogrusBaseSuite(t)
131 b.logger.Level = logrus.DebugLevel
132 b.InterceptorTestSuite.ClientOpts = []grpc.DialOption{
133 grpc.WithUnaryInterceptor(grpc_logrus.UnaryClientInterceptor(logrus.NewEntry(b.logger), opts...)),
134 grpc.WithStreamInterceptor(grpc_logrus.StreamClientInterceptor(logrus.NewEntry(b.logger), opts...)),
135 }
136 suite.Run(t, &logrusClientOverrideSuite{b})
137 }
138
139 type logrusClientOverrideSuite struct {
140 *logrusBaseSuite
141 }
142
143 func (s *logrusClientOverrideSuite) TestPing_HasOverrides() {
144 _, err := s.Client.Ping(s.SimpleCtx(), goodPing)
145 assert.NoError(s.T(), err, "there must be not be an on a successful call")
146
147 msgs := s.getOutputJSONs()
148 require.Len(s.T(), msgs, 1, "one log statement should be logged")
149 assert.Equal(s.T(), msgs[0]["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
150 assert.Equal(s.T(), msgs[0]["grpc.method"], "Ping", "all lines must contain the correct method name")
151 assert.Equal(s.T(), msgs[0]["msg"], "finished client unary call", "handler's message must contain the correct message")
152
153 assert.NotContains(s.T(), msgs[0], "grpc.time_ms", "message must not contain default duration")
154 assert.Contains(s.T(), msgs[0], "grpc.duration", "message must contain overridden duration")
155 }
156
157 func (s *logrusClientOverrideSuite) TestPingList_HasOverrides() {
158 stream, err := s.Client.PingList(s.SimpleCtx(), goodPing)
159 require.NoError(s.T(), err, "should not fail on establishing the stream")
160 for {
161 _, err := stream.Recv()
162 if err == io.EOF {
163 break
164 }
165 require.NoError(s.T(), err, "reading stream should not fail")
166 }
167
168 msgs := s.getOutputJSONs()
169 require.Len(s.T(), msgs, 1, "one log statement should be logged")
170
171 assert.Equal(s.T(), msgs[0]["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
172 assert.Equal(s.T(), msgs[0]["grpc.method"], "PingList", "all lines must contain the correct method name")
173 assert.Equal(s.T(), msgs[0]["msg"], "finished client streaming call", "log message must be correct")
174 assert.Equal(s.T(), msgs[0]["span.kind"], "client", "all lines must contain the kind of call (client)")
175 assert.Equal(s.T(), msgs[0]["level"], "debug", "OK codes must be logged on debug level.")
176
177 assert.NotContains(s.T(), msgs[0], "grpc.time_ms", "message must not contain default duration")
178 assert.Contains(s.T(), msgs[0], "grpc.duration", "message must contain overridden duration")
179 }
180
181 func TestZapLoggingClientMessageProducerSuite(t *testing.T) {
182 opts := []grpc_logrus.Option{
183 grpc_logrus.WithMessageProducer(StubMessageProducer),
184 }
185 b := newLogrusBaseSuite(t)
186 b.logger.Level = logrus.DebugLevel
187 b.InterceptorTestSuite.ClientOpts = []grpc.DialOption{
188 grpc.WithUnaryInterceptor(grpc_logrus.UnaryClientInterceptor(logrus.NewEntry(b.logger), opts...)),
189 grpc.WithStreamInterceptor(grpc_logrus.StreamClientInterceptor(logrus.NewEntry(b.logger), opts...)),
190 }
191 suite.Run(t, &logrusClientMessageProducerSuite{b})
192 }
193
194 type logrusClientMessageProducerSuite struct {
195 *logrusBaseSuite
196 }
197
198 func (s *logrusClientMessageProducerSuite) TestPing_HasOverriddenMessageProducer() {
199 _, err := s.Client.Ping(s.SimpleCtx(), goodPing)
200 assert.NoError(s.T(), err, "there must be not be an on a successful call")
201
202 msgs := s.getOutputJSONs()
203 require.Len(s.T(), msgs, 1, "one log statement should be logged")
204
205 assert.Equal(s.T(), msgs[0]["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
206 assert.Equal(s.T(), msgs[0]["grpc.method"], "Ping", "all lines must contain the correct method name")
207 assert.Equal(s.T(), msgs[0]["msg"], "custom message", "handler's message must contain the correct message")
208 assert.Equal(s.T(), msgs[0]["span.kind"], "client", "all lines must contain the kind of call (client)")
209 assert.Equal(s.T(), msgs[0]["level"], "debug", "OK codes must be logged on debug level.")
210
211 assert.Contains(s.T(), msgs[0], "grpc.time_ms", "interceptor log statement should contain execution time (duration in ms)")
212 }
213
View as plain text