@@ -630,6 +630,149 @@ func (s *loggingPayloadSuite) assertPayloadLogLinesForMessage(lines LogLines, me
630630 }
631631}
632632
633+ type loggingCustomGrpcLogFieldsSuite struct {
634+ * baseLoggingSuite
635+ }
636+
637+ func TestCustomGrpcLogFieldsSuite (t * testing.T ) {
638+ if strings .HasPrefix (runtime .Version (), "go1.7" ) {
639+ t .Skipf ("Skipping due to json.RawMessage incompatibility with go1.7" )
640+ return
641+ }
642+ s := & loggingCustomGrpcLogFieldsSuite {
643+ baseLoggingSuite : & baseLoggingSuite {
644+ logger : newMockLogger (),
645+ InterceptorTestSuite : & testpb.InterceptorTestSuite {
646+ TestService : & testpb.TestPingService {},
647+ },
648+ },
649+ }
650+ s .InterceptorTestSuite .ClientOpts = []grpc.DialOption {
651+ grpc .WithUnaryInterceptor (logging .UnaryClientInterceptor (s .logger , logging .WithDisableLoggingFields (logging .ComponentFieldKey , logging .MethodTypeFieldKey , logging .SystemTag [0 ], "custom-field-should-be-ignored" ))),
652+ grpc .WithStreamInterceptor (logging .StreamClientInterceptor (s .logger , logging .WithDisableLoggingFields (logging .ComponentFieldKey , logging .MethodTypeFieldKey , logging .SystemTag [0 ], "custom-field-should-be-ignored" ))),
653+ }
654+ s .InterceptorTestSuite .ServerOpts = []grpc.ServerOption {
655+ grpc .StreamInterceptor (logging .StreamServerInterceptor (s .logger , logging .WithDisableLoggingFields (logging .ComponentFieldKey , logging .MethodTypeFieldKey , logging .SystemTag [0 ], "custom-field-should-be-ignored" ))),
656+ grpc .UnaryInterceptor (logging .UnaryServerInterceptor (s .logger , logging .WithDisableLoggingFields (logging .ComponentFieldKey , logging .MethodTypeFieldKey , logging .SystemTag [0 ], "custom-field-should-be-ignore" ))),
657+ }
658+ suite .Run (t , s )
659+ }
660+
661+ // Test that fields are added to logs using withGrpcLogFields.
662+ func (s * loggingCustomGrpcLogFieldsSuite ) TestCustomGrpcLogFieldsWithPing () {
663+ _ , err := s .Client .Ping (s .SimpleCtx (), testpb .GoodPing )
664+ assert .NoError (s .T (), err , "there must be not be an on a successful call" )
665+
666+ lines := s .logger .o .Lines ()
667+ sort .Sort (lines )
668+ require .Len (s .T (), lines , 4 )
669+
670+ clientStartCallLogLine := lines [2 ]
671+ assert .Equal (s .T (), logging .LevelDebug , clientStartCallLogLine .lvl )
672+ assert .Equal (s .T (), "started call" , clientStartCallLogLine .msg )
673+ clientStartCallFields := clientStartCallLogLine .fields
674+ clientStartCallFields .AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
675+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
676+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
677+ AssertField (s .T (), logging .MethodFieldKey , "Ping" ).
678+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
679+
680+ serverStartCallLogLine := lines [3 ]
681+ assert .Equal (s .T (), logging .LevelInfo , serverStartCallLogLine .lvl )
682+ assert .Equal (s .T (), "started call" , serverStartCallLogLine .msg )
683+ serverStartCallFields := serverStartCallLogLine .fields
684+ serverStartCallFields .AssertFieldNotEmpty (s .T (), "peer.address" ).
685+ AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
686+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
687+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
688+ AssertField (s .T (), logging .MethodFieldKey , "Ping" ).
689+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
690+
691+ serverFinishCallLogLine := lines [0 ]
692+ assert .Equal (s .T (), logging .LevelInfo , serverFinishCallLogLine .lvl )
693+ assert .Equal (s .T (), "finished call" , serverFinishCallLogLine .msg )
694+ serverFinishCallFields := serverFinishCallLogLine .fields
695+ serverFinishCallFields .AssertFieldNotEmpty (s .T (), "peer.address" ).
696+ AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
697+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
698+ AssertField (s .T (), "grpc.code" , "OK" ).
699+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
700+ AssertField (s .T (), logging .MethodFieldKey , "Ping" ).
701+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
702+
703+ clientFinishCallLogLine := lines [1 ]
704+ assert .Equal (s .T (), logging .LevelDebug , clientFinishCallLogLine .lvl )
705+ assert .Equal (s .T (), "finished call" , clientFinishCallLogLine .msg )
706+
707+ clientFinishCallFields := clientFinishCallLogLine .fields
708+ clientFinishCallFields .AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
709+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
710+ AssertField (s .T (), "grpc.code" , "OK" ).
711+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
712+ AssertField (s .T (), logging .MethodFieldKey , "Ping" ).
713+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
714+ }
715+
716+ func (s * loggingCustomGrpcLogFieldsSuite ) TestCustomGrpcLogFieldsWithPingList () {
717+ stream , err := s .Client .PingList (s .SimpleCtx (), testpb .GoodPingList )
718+ require .NoError (s .T (), err , "should not fail on establishing the stream" )
719+ for {
720+ _ , err := stream .Recv ()
721+ if err == io .EOF {
722+ break
723+ }
724+ require .NoError (s .T (), err , "reading stream should not fail" )
725+ }
726+ lines := s .logger .o .Lines ()
727+ sort .Sort (lines )
728+ require .Len (s .T (), lines , 4 )
729+
730+ clientStartCallLogLine := lines [2 ]
731+ assert .Equal (s .T (), logging .LevelDebug , clientStartCallLogLine .lvl )
732+ assert .Equal (s .T (), "started call" , clientStartCallLogLine .msg )
733+ clientStartCallFields := clientStartCallLogLine .fields
734+ clientStartCallFields .AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
735+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
736+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
737+ AssertField (s .T (), logging .MethodFieldKey , "PingList" ).
738+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
739+
740+ serverStartCallLogLine := lines [3 ]
741+ assert .Equal (s .T (), logging .LevelInfo , serverStartCallLogLine .lvl )
742+ assert .Equal (s .T (), "started call" , serverStartCallLogLine .msg )
743+ serverStartCallFields := serverStartCallLogLine .fields
744+ serverStartCallFields .AssertFieldNotEmpty (s .T (), "peer.address" ).
745+ AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
746+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
747+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
748+ AssertField (s .T (), logging .MethodFieldKey , "PingList" ).
749+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
750+
751+ serverFinishCallLogLine := lines [0 ]
752+ assert .Equal (s .T (), logging .LevelInfo , serverFinishCallLogLine .lvl )
753+ assert .Equal (s .T (), "finished call" , serverFinishCallLogLine .msg )
754+ serverFinishCallFields := serverFinishCallLogLine .fields
755+ serverFinishCallFields .AssertFieldNotEmpty (s .T (), "peer.address" ).
756+ AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
757+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
758+ AssertField (s .T (), "grpc.code" , "OK" ).
759+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
760+ AssertField (s .T (), logging .MethodFieldKey , "PingList" ).
761+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
762+
763+ clientFinishCallLogLine := lines [1 ]
764+ assert .Equal (s .T (), logging .LevelDebug , clientFinishCallLogLine .lvl )
765+ assert .Equal (s .T (), "finished call" , clientFinishCallLogLine .msg )
766+
767+ clientFinishCallFields := clientFinishCallLogLine .fields
768+ clientFinishCallFields .AssertFieldNotEmpty (s .T (), "grpc.start_time" ).
769+ AssertFieldNotEmpty (s .T (), "grpc.request.deadline" ).
770+ AssertField (s .T (), "grpc.code" , "OK" ).
771+ AssertFieldNotEmpty (s .T (), "grpc.time_ms" ).
772+ AssertField (s .T (), logging .MethodFieldKey , "PingList" ).
773+ AssertField (s .T (), logging .ServiceFieldKey , testpb .TestServiceFullName ).AssertNoMoreTags (s .T ())
774+ }
775+
633776// waitUntil executes f every interval seconds until timeout or no error is returned from f.
634777func waitUntil (interval time.Duration , stopc <- chan struct {}, f func () error ) error {
635778 tick := time .NewTicker (interval )
0 commit comments