1 package grpc_logrus_test
2
3 import (
4 "context"
5 "io"
6 "io/ioutil"
7 "runtime"
8 "strings"
9 "testing"
10
11 "github.com/grpc-ecosystem/go-grpc-middleware"
12 "github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
13 "github.com/grpc-ecosystem/go-grpc-middleware/tags"
14 pb_testproto "github.com/grpc-ecosystem/go-grpc-middleware/testing/testproto"
15 "github.com/sirupsen/logrus"
16 "github.com/stretchr/testify/assert"
17 "github.com/stretchr/testify/require"
18 "github.com/stretchr/testify/suite"
19 "google.golang.org/grpc"
20 )
21
22 var (
23 nullLogger = &logrus.Logger{
24 Out: ioutil.Discard,
25 Formatter: new(logrus.TextFormatter),
26 Hooks: make(logrus.LevelHooks),
27 Level: logrus.PanicLevel,
28 }
29 )
30
31 func TestLogrusPayloadSuite(t *testing.T) {
32 if strings.HasPrefix(runtime.Version(), "go1.7") {
33 t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7")
34 return
35 }
36 alwaysLoggingDeciderServer := func(ctx context.Context, fullMethodName string, servingObject interface{}) bool { return true }
37 alwaysLoggingDeciderClient := func(ctx context.Context, fullMethodName string) bool { return true }
38 b := newLogrusBaseSuite(t)
39 b.InterceptorTestSuite.ClientOpts = []grpc.DialOption{
40 grpc.WithUnaryInterceptor(grpc_logrus.PayloadUnaryClientInterceptor(logrus.NewEntry(b.logger), alwaysLoggingDeciderClient)),
41 grpc.WithStreamInterceptor(grpc_logrus.PayloadStreamClientInterceptor(logrus.NewEntry(b.logger), alwaysLoggingDeciderClient)),
42 }
43 b.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{
44 grpc_middleware.WithStreamServerChain(
45 grpc_ctxtags.StreamServerInterceptor(grpc_ctxtags.WithFieldExtractor(grpc_ctxtags.CodeGenRequestFieldExtractor)),
46 grpc_logrus.StreamServerInterceptor(logrus.NewEntry(nullLogger)),
47 grpc_logrus.PayloadStreamServerInterceptor(logrus.NewEntry(b.logger), alwaysLoggingDeciderServer)),
48 grpc_middleware.WithUnaryServerChain(
49 grpc_ctxtags.UnaryServerInterceptor(grpc_ctxtags.WithFieldExtractor(grpc_ctxtags.CodeGenRequestFieldExtractor)),
50 grpc_logrus.UnaryServerInterceptor(logrus.NewEntry(nullLogger)),
51 grpc_logrus.PayloadUnaryServerInterceptor(logrus.NewEntry(b.logger), alwaysLoggingDeciderServer)),
52 }
53 suite.Run(t, &logrusPayloadSuite{b})
54 }
55
56 type logrusPayloadSuite struct {
57 *logrusBaseSuite
58 }
59
60 func (s *logrusPayloadSuite) getServerAndClientMessages(expectedServer int, expectedClient int) (serverMsgs []map[string]interface{}, clientMsgs []map[string]interface{}) {
61 msgs := s.getOutputJSONs()
62 for _, m := range msgs {
63 if m["span.kind"] == "server" {
64 serverMsgs = append(serverMsgs, m)
65 } else if m["span.kind"] == "client" {
66 clientMsgs = append(clientMsgs, m)
67 }
68 }
69
70 require.Len(s.T(), serverMsgs, expectedServer, "must match expected number of server log messages")
71 require.Len(s.T(), clientMsgs, expectedClient, "must match expected number of client log messages")
72 return serverMsgs, clientMsgs
73 }
74
75 func (s *logrusPayloadSuite) TestPing_LogsBothRequestAndResponse() {
76 _, err := s.Client.Ping(s.SimpleCtx(), goodPing)
77 require.NoError(s.T(), err, "there must be not be an on a successful call")
78 serverMsgs, clientMsgs := s.getServerAndClientMessages(2, 2)
79
80 for _, m := range append(serverMsgs, clientMsgs...) {
81 assert.Equal(s.T(), m["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
82 assert.Equal(s.T(), m["grpc.method"], "Ping", "all lines must contain the correct method name")
83 assert.Equal(s.T(), m["level"], "info", "all lines must contain method name")
84 }
85
86 serverReq, serverResp := serverMsgs[0], serverMsgs[1]
87 clientReq, clientResp := clientMsgs[0], clientMsgs[1]
88 assert.Contains(s.T(), clientReq, "grpc.request.content", "request payload must be logged in a structured way")
89 assert.Contains(s.T(), serverReq, "grpc.request.content", "request payload must be logged in a structured way")
90 assert.Contains(s.T(), clientResp, "grpc.response.content", "response payload must be logged in a structured way")
91 assert.Contains(s.T(), serverResp, "grpc.response.content", "response payload must be logged in a structured way")
92 }
93
94 func (s *logrusPayloadSuite) TestPingError_LogsOnlyRequestsOnError() {
95 _, err := s.Client.PingError(s.SimpleCtx(), &pb_testproto.PingRequest{Value: "something", ErrorCodeReturned: uint32(4)})
96 require.Error(s.T(), err, "there must be not be an error on a successful call")
97
98 serverMsgs, clientMsgs := s.getServerAndClientMessages(1, 1)
99 for _, m := range append(serverMsgs, clientMsgs...) {
100 assert.Equal(s.T(), m["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
101 assert.Equal(s.T(), m["grpc.method"], "PingError", "all lines must contain the correct method name")
102 assert.Equal(s.T(), m["level"], "info", "all lines must be logged at info level")
103 }
104
105 assert.Contains(s.T(), clientMsgs[0], "grpc.request.content", "request payload must be logged by the client")
106 assert.Contains(s.T(), serverMsgs[0], "grpc.request.content", "request payload must be logged by the server")
107 }
108
109 func (s *logrusPayloadSuite) TestPingStream_LogsAllRequestsAndResponses() {
110 messagesExpected := 20
111 stream, err := s.Client.PingStream(s.SimpleCtx())
112 require.NoError(s.T(), err, "no error on stream creation")
113 for i := 0; i < messagesExpected; i++ {
114 require.NoError(s.T(), stream.Send(goodPing), "sending must succeed")
115 }
116 require.NoError(s.T(), stream.CloseSend(), "no error on close of stream")
117
118 for {
119 pong := &pb_testproto.PingResponse{}
120 err := stream.RecvMsg(pong)
121 if err == io.EOF {
122 break
123 }
124 require.NoError(s.T(), err, "no error on receive")
125 }
126 serverMsgs, clientMsgs := s.getServerAndClientMessages(2*messagesExpected, 2*messagesExpected)
127 for _, m := range append(serverMsgs, clientMsgs...) {
128 assert.Equal(s.T(), m["grpc.service"], "mwitkow.testproto.TestService", "all lines must contain the correct service name")
129 assert.Equal(s.T(), m["grpc.method"], "PingStream", "all lines must contain the correct method name")
130 assert.Equal(s.T(), m["level"], "info", "all lines must be at info log level")
131
132 content := m["grpc.request.content"] != nil || m["grpc.response.content"] != nil
133 assert.True(s.T(), content, "all messages must contain a payload")
134 }
135 }
136
View as plain text