feat!: add trace-id to logs in guardian (#102)

- add trace-id to logs in guardian through the use of context for passing the trace-id through the function calls. - add support for multiple ctx keys in logger.
goto · Nov 8, 2023 · 7c4c54b · 7c4c54b
1 parent cfa2bb2
commit 7c4c54b
Show file tree

Hide file tree

Showing 82 changed files with 2,013 additions and 1,209 deletions.
diff --git a/api/handler/v1beta1/appeal_test.go b/api/handler/v1beta1/appeal_test.go
@@ -658,7 +658,7 @@ func (s *GrpcHandlersSuite) TestGetAppeal() {
 				UpdatedAt: timestamppb.New(timeNow),
 			},
 		}
-		s.appealService.EXPECT().GetByID(mock.AnythingOfType("*context.emptyCtx"), expectedID).Return(expectedAppeal, nil).Once()
+		s.appealService.EXPECT().GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), expectedID).Return(expectedAppeal, nil).Once()
 
 		req := &guardianv1beta1.GetAppealRequest{
 			Id: expectedID,
@@ -674,7 +674,7 @@ func (s *GrpcHandlersSuite) TestGetAppeal() {
 		s.setup()
 
 		expectedError := errors.New("random error")
-		s.appealService.EXPECT().GetByID(mock.AnythingOfType("*context.emptyCtx"), mock.Anything).
+		s.appealService.EXPECT().GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.Anything).
 			Return(nil, expectedError).Once()
 
 		req := &guardianv1beta1.GetAppealRequest{
@@ -690,7 +690,7 @@ func (s *GrpcHandlersSuite) TestGetAppeal() {
 	s.Run("should return not found error if appeal not found", func() {
 		s.setup()
 
-		s.appealService.EXPECT().GetByID(mock.AnythingOfType("*context.emptyCtx"), mock.Anything).
+		s.appealService.EXPECT().GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.Anything).
 			Return(nil, nil).Once()
 
 		req := &guardianv1beta1.GetAppealRequest{
@@ -711,7 +711,7 @@ func (s *GrpcHandlersSuite) TestGetAppeal() {
 				"foo": make(chan int),
 			},
 		}
-		s.appealService.EXPECT().GetByID(mock.AnythingOfType("*context.emptyCtx"), mock.Anything).
+		s.appealService.EXPECT().GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.Anything).
 			Return(invalidAppeal, nil).Once()
 
 		req := &guardianv1beta1.GetAppealRequest{
@@ -726,6 +726,7 @@ func (s *GrpcHandlersSuite) TestGetAppeal() {
 }
 
 func (s *GrpcHandlersSuite) TestCancelAppeal() {
+	mockCtx := mock.MatchedBy(func(ctx context.Context) bool { return true })
 	s.Run("should return appeal details on success", func() {
 		s.setup()
 		timeNow := time.Now()
@@ -809,7 +810,7 @@ func (s *GrpcHandlersSuite) TestCancelAppeal() {
 				UpdatedAt: timestamppb.New(timeNow),
 			},
 		}
-		s.appealService.EXPECT().Cancel(mock.AnythingOfType("*context.emptyCtx"), expectedID).Return(expectedAppeal, nil).Once()
+		s.appealService.EXPECT().Cancel(mockCtx, expectedID).Return(expectedAppeal, nil).Once()
 
 		req := &guardianv1beta1.CancelAppealRequest{
 			Id: expectedID,
@@ -863,7 +864,7 @@ func (s *GrpcHandlersSuite) TestCancelAppeal() {
 			s.Run(tc.name, func() {
 				s.setup()
 
-				s.appealService.EXPECT().Cancel(mock.AnythingOfType("*context.emptyCtx"), mock.Anything).
+				s.appealService.EXPECT().Cancel(mockCtx, mock.Anything).
 					Return(nil, tc.expectedError).Once()
 
 				req := &guardianv1beta1.CancelAppealRequest{
@@ -886,7 +887,7 @@ func (s *GrpcHandlersSuite) TestCancelAppeal() {
 				"foo": make(chan int),
 			},
 		}
-		s.appealService.EXPECT().Cancel(mock.AnythingOfType("*context.emptyCtx"), mock.Anything).
+		s.appealService.EXPECT().Cancel(mockCtx, mock.Anything).
 			Return(invalidAppeal, nil).Once()
 
 		req := &guardianv1beta1.CancelAppealRequest{

diff --git a/api/handler/v1beta1/approval_test.go b/api/handler/v1beta1/approval_test.go
@@ -635,7 +635,7 @@ func (s *GrpcHandlersSuite) TestAddApprover() {
 			CreatedAt: timeNow,
 			UpdatedAt: timeNow,
 		}
-		s.appealService.EXPECT().AddApprover(mock.AnythingOfType("*context.emptyCtx"), appealID, approvalID, email).Return(expectedAppeal, nil).Once()
+		s.appealService.EXPECT().AddApprover(mock.Anything, appealID, approvalID, email).Return(expectedAppeal, nil).Once()
 		expectedResponse := &guardianv1beta1.AddApproverResponse{
 			Appeal: &guardianv1beta1.Appeal{
 				Id:            expectedAppeal.ID,
@@ -760,7 +760,7 @@ func (s *GrpcHandlersSuite) TestDeleteApprover() {
 			CreatedAt: timeNow,
 			UpdatedAt: timeNow,
 		}
-		s.appealService.EXPECT().DeleteApprover(mock.AnythingOfType("*context.emptyCtx"), appealID, approvalID, email).Return(expectedAppeal, nil).Once()
+		s.appealService.EXPECT().DeleteApprover(mock.MatchedBy(func(ctx context.Context) bool { return true }), appealID, approvalID, email).Return(expectedAppeal, nil).Once()
 		expectedResponse := &guardianv1beta1.DeleteApproverResponse{
 			Appeal: &guardianv1beta1.Appeal{
 				Id:            expectedAppeal.ID,

diff --git a/api/handler/v1beta1/grant_test.go b/api/handler/v1beta1/grant_test.go
@@ -191,7 +191,7 @@ func (s *GrpcHandlersSuite) TestGetGrant() {
 			},
 		}
 		s.grantService.EXPECT().
-			GetByID(mock.AnythingOfType("*context.emptyCtx"), grantID).
+			GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), grantID).
 			Return(dummyGrant, nil).Once()
 
 		req := &guardianv1beta1.GetGrantRequest{Id: grantID}
@@ -225,7 +225,7 @@ func (s *GrpcHandlersSuite) TestGetGrant() {
 				s.setup()
 
 				s.grantService.EXPECT().
-					GetByID(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("string")).
+					GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("string")).
 					Return(nil, tc.expectedError).Once()
 
 				req := &guardianv1beta1.GetGrantRequest{Id: "test-id"}
@@ -249,7 +249,7 @@ func (s *GrpcHandlersSuite) TestGetGrant() {
 			},
 		}
 		s.grantService.EXPECT().
-			GetByID(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("string")).
+			GetByID(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("string")).
 			Return(expectedGrant, nil).Once()
 
 		req := &guardianv1beta1.GetGrantRequest{Id: "test-id"}
@@ -287,7 +287,7 @@ func (s *GrpcHandlersSuite) TestListUserRoles() {
 		s.setup()
 
 		s.grantService.EXPECT().
-			ListUserRoles(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("string")).
+			ListUserRoles(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("string")).
 			Return(nil, nil).Once()
 
 		req := &guardianv1beta1.ListUserRolesRequest{}
@@ -324,7 +324,7 @@ func (s *GrpcHandlersSuite) TestUpdateGrant() {
 		}
 		now := time.Now()
 		s.grantService.EXPECT().
-			Update(mock.AnythingOfType("*context.emptyCtx"), expectedGrant).
+			Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), expectedGrant).
 			Run(func(_a0 context.Context, g *domain.Grant) {
 				g.UpdatedAt = now
 			}).
@@ -370,7 +370,7 @@ func (s *GrpcHandlersSuite) TestUpdateGrant() {
 				s.setup()
 
 				s.grantService.EXPECT().
-					Update(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Grant")).
+					Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Grant")).
 					Return(tc.expectedError).Once()
 
 				req := &guardianv1beta1.UpdateGrantRequest{
@@ -443,7 +443,7 @@ func (s *GrpcHandlersSuite) TestImportFromProvider() {
 			},
 		}
 		s.grantService.EXPECT().
-			ImportFromProvider(mock.AnythingOfType("*context.emptyCtx"), grant.ImportFromProviderCriteria{
+			ImportFromProvider(mock.MatchedBy(func(ctx context.Context) bool { return true }), grant.ImportFromProviderCriteria{
 				ProviderID:    "test-provider-id",
 				ResourceIDs:   []string{"test-resource-id"},
 				ResourceTypes: []string{"test-resource-type"},

diff --git a/api/handler/v1beta1/grpc.go b/api/handler/v1beta1/grpc.go
@@ -4,6 +4,8 @@ import (
 	"context"
 	"strings"
 
+	"github.com/goto/guardian/pkg/log"
+
 	"github.com/goto/guardian/core/appeal"
 	"github.com/goto/guardian/core/grant"
 
@@ -124,6 +126,7 @@ type GRPCServer struct {
 	adapter         ProtoAdapter
 
 	authenticatedUserContextKey interface{}
+	logger                      log.Logger
 
 	guardianv1beta1.UnimplementedGuardianServiceServer
 }
@@ -138,6 +141,7 @@ func NewGRPCServer(
 	grantService grantService,
 	adapter ProtoAdapter,
 	authenticatedUserContextKey interface{},
+	logger log.Logger,
 ) *GRPCServer {
 	return &GRPCServer{
 		resourceService:             resourceService,
@@ -149,6 +153,7 @@ func NewGRPCServer(
 		grantService:                grantService,
 		adapter:                     adapter,
 		authenticatedUserContextKey: authenticatedUserContextKey,
+		logger:                      logger,
 	}
 }
 

diff --git a/api/handler/v1beta1/grpc_test.go b/api/handler/v1beta1/grpc_test.go
@@ -3,6 +3,8 @@ package v1beta1_test
 import (
 	"testing"
 
+	"github.com/goto/guardian/pkg/log"
+
 	"github.com/goto/guardian/api/handler/v1beta1"
 	"github.com/goto/guardian/api/handler/v1beta1/mocks"
 	"github.com/stretchr/testify/suite"
@@ -21,6 +23,7 @@ type GrpcHandlersSuite struct {
 	approvalService *mocks.ApprovalService
 	grantService    *mocks.GrantService
 	grpcServer      *v1beta1.GRPCServer
+	logger          log.Logger
 }
 
 func TestGrpcHandler(t *testing.T) {
@@ -35,6 +38,7 @@ func (s *GrpcHandlersSuite) setup() {
 	s.appealService = new(mocks.AppealService)
 	s.approvalService = new(mocks.ApprovalService)
 	s.grantService = new(mocks.GrantService)
+	s.logger = log.NewNoop()
 	s.grpcServer = v1beta1.NewGRPCServer(
 		s.resourceService,
 		s.activityService,
@@ -45,5 +49,6 @@ func (s *GrpcHandlersSuite) setup() {
 		s.grantService,
 		v1beta1.NewAdapter(),
 		authEmailTestContextKey{},
+		s.logger,
 	)
 }
diff --git a/api/handler/v1beta1/policy_test.go b/api/handler/v1beta1/policy_test.go
@@ -29,7 +29,7 @@ func (s *GrpcHandlersSuite) TestListPolicies() {
 		dummyPolicies := []*domain.Policy{
 			{ID: "test-policy"},
 		}
-		s.policyService.EXPECT().Find(mock.AnythingOfType("*context.emptyCtx")).Return(dummyPolicies, nil).Once()
+		s.policyService.EXPECT().Find(mock.MatchedBy(func(ctx context.Context) bool { return true })).Return(dummyPolicies, nil).Once()
 
 		req := &guardianv1beta1.ListPoliciesRequest{}
 		res, err := s.grpcServer.ListPolicies(context.Background(), req)
@@ -43,7 +43,7 @@ func (s *GrpcHandlersSuite) TestListPolicies() {
 		s.setup()
 
 		expectedError := errors.New("random error")
-		s.policyService.EXPECT().Find(mock.AnythingOfType("*context.emptyCtx")).Return(nil, expectedError).Once()
+		s.policyService.EXPECT().Find(mock.MatchedBy(func(ctx context.Context) bool { return true })).Return(nil, expectedError).Once()
 
 		req := &guardianv1beta1.ListPoliciesRequest{}
 		res, err := s.grpcServer.ListPolicies(context.Background(), req)
@@ -64,7 +64,7 @@ func (s *GrpcHandlersSuite) TestListPolicies() {
 				},
 			},
 		}
-		s.policyService.EXPECT().Find(mock.AnythingOfType("*context.emptyCtx")).Return(dummyPolicies, nil).Once()
+		s.policyService.EXPECT().Find(mock.MatchedBy(func(ctx context.Context) bool { return true })).Return(dummyPolicies, nil).Once()
 
 		req := &guardianv1beta1.ListPoliciesRequest{}
 		res, err := s.grpcServer.ListPolicies(context.Background(), req)
@@ -176,7 +176,7 @@ func (s *GrpcHandlersSuite) TestGetPolicy() {
 				UpdatedAt: timestamppb.New(timeNow),
 			},
 		}
-		s.policyService.EXPECT().GetOne(mock.AnythingOfType("*context.emptyCtx"), "test-policy", uint(1)).
+		s.policyService.EXPECT().GetOne(mock.MatchedBy(func(ctx context.Context) bool { return true }), "test-policy", uint(1)).
 			Return(dummyPolicy, nil).Once()
 
 		req := &guardianv1beta1.GetPolicyRequest{
@@ -193,7 +193,7 @@ func (s *GrpcHandlersSuite) TestGetPolicy() {
 	s.Run("should return not found error if policy not found", func() {
 		s.setup()
 
-		s.policyService.EXPECT().GetOne(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("string"), mock.AnythingOfType("uint")).
+		s.policyService.EXPECT().GetOne(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("string"), mock.AnythingOfType("uint")).
 			Return(nil, policy.ErrPolicyNotFound).Once()
 
 		req := &guardianv1beta1.GetPolicyRequest{}
@@ -208,7 +208,7 @@ func (s *GrpcHandlersSuite) TestGetPolicy() {
 		s.setup()
 
 		expectedError := errors.New("random error")
-		s.policyService.EXPECT().GetOne(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("string"), mock.AnythingOfType("uint")).
+		s.policyService.EXPECT().GetOne(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("string"), mock.AnythingOfType("uint")).
 			Return(nil, expectedError).Once()
 
 		req := &guardianv1beta1.GetPolicyRequest{}
@@ -229,7 +229,7 @@ func (s *GrpcHandlersSuite) TestGetPolicy() {
 				Config: make(chan int), // invalid json
 			},
 		}
-		s.policyService.EXPECT().GetOne(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("string"), mock.AnythingOfType("uint")).
+		s.policyService.EXPECT().GetOne(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("string"), mock.AnythingOfType("uint")).
 			Return(dummyPolicy, nil).Once()
 
 		req := &guardianv1beta1.GetPolicyRequest{}
@@ -366,7 +366,7 @@ func (s *GrpcHandlersSuite) TestCreatePolicy() {
 				UpdatedAt: timestamppb.New(timeNow),
 			},
 		}
-		s.policyService.EXPECT().Create(mock.AnythingOfType("*context.emptyCtx"), expectedPolicy).
+		s.policyService.EXPECT().Create(mock.MatchedBy(func(ctx context.Context) bool { return true }), expectedPolicy).
 			Run(func(_a0 context.Context, _a1 *domain.Policy) {
 				_a1.CreatedAt = timeNow
 				_a1.UpdatedAt = timeNow
@@ -442,7 +442,7 @@ func (s *GrpcHandlersSuite) TestCreatePolicy() {
 		s.setup()
 
 		expectedError := errors.New("random error")
-		s.policyService.EXPECT().Create(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
+		s.policyService.EXPECT().Create(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
 
 		req := &guardianv1beta1.CreatePolicyRequest{}
 		res, err := s.grpcServer.CreatePolicy(context.Background(), req)
@@ -460,7 +460,7 @@ func (s *GrpcHandlersSuite) TestCreatePolicy() {
 				Config: make(chan int), // invalid json
 			},
 		}
-		s.policyService.EXPECT().Create(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Policy")).Return(nil).
+		s.policyService.EXPECT().Create(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Policy")).Return(nil).
 			Run(func(_a0 context.Context, _a1 *domain.Policy) {
 				*_a1 = *invalidPolicy
 			}).Once()
@@ -573,7 +573,7 @@ func (s *GrpcHandlersSuite) TestUpdatePolicy() {
 				UpdatedAt: timestamppb.New(timeNow),
 			},
 		}
-		s.policyService.EXPECT().Update(mock.AnythingOfType("*context.emptyCtx"), expectedPolicy).
+		s.policyService.EXPECT().Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), expectedPolicy).
 			Run(func(_a0 context.Context, _a1 *domain.Policy) {
 				_a1.CreatedAt = timeNow
 				_a1.UpdatedAt = timeNow
@@ -636,7 +636,7 @@ func (s *GrpcHandlersSuite) TestUpdatePolicy() {
 		s.setup()
 
 		expectedError := policy.ErrPolicyNotFound
-		s.policyService.EXPECT().Update(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
+		s.policyService.EXPECT().Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
 
 		req := &guardianv1beta1.UpdatePolicyRequest{}
 		res, err := s.grpcServer.UpdatePolicy(context.Background(), req)
@@ -650,7 +650,7 @@ func (s *GrpcHandlersSuite) TestUpdatePolicy() {
 		s.setup()
 
 		expectedError := policy.ErrEmptyIDParam
-		s.policyService.EXPECT().Update(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
+		s.policyService.EXPECT().Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
 
 		req := &guardianv1beta1.UpdatePolicyRequest{}
 		res, err := s.grpcServer.UpdatePolicy(context.Background(), req)
@@ -664,7 +664,7 @@ func (s *GrpcHandlersSuite) TestUpdatePolicy() {
 		s.setup()
 
 		expectedError := errors.New("random error")
-		s.policyService.EXPECT().Update(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
+		s.policyService.EXPECT().Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Policy")).Return(expectedError).Once()
 
 		req := &guardianv1beta1.UpdatePolicyRequest{}
 		res, err := s.grpcServer.UpdatePolicy(context.Background(), req)
@@ -682,7 +682,7 @@ func (s *GrpcHandlersSuite) TestUpdatePolicy() {
 				Config: make(chan int), // invalid json
 			},
 		}
-		s.policyService.EXPECT().Update(mock.AnythingOfType("*context.emptyCtx"), mock.AnythingOfType("*domain.Policy")).Return(nil).
+		s.policyService.EXPECT().Update(mock.MatchedBy(func(ctx context.Context) bool { return true }), mock.AnythingOfType("*domain.Policy")).Return(nil).
 			Run(func(_a0 context.Context, _a1 *domain.Policy) {
 				*_a1 = *invalidPolicy
 			}).Once()

diff --git a/api/handler/v1beta1/provider.go b/api/handler/v1beta1/provider.go
@@ -82,6 +82,7 @@ func (s *GRPCServer) CreateProvider(ctx context.Context, req *guardianv1beta1.Cr
 	}
 
 	if err := s.providerService.Create(ctx, p); err != nil {
+		s.logger.Error(ctx, "failed to create provider", "provider_urn", p.URN, "type", p.Type, "error", err)
 		return nil, status.Errorf(codes.Internal, "failed to create provider: %v", err)
 	}
 
@@ -110,6 +111,7 @@ func (s *GRPCServer) UpdateProvider(ctx context.Context, req *guardianv1beta1.Up
 	}
 
 	if err := s.providerService.Update(ctx, p); err != nil {
+		s.logger.Error(ctx, "failed to update provider", "provider_id", id, "provider_urn", p.URN, "type", p.Type, "error", err)
 		return nil, status.Errorf(codes.Internal, "failed to update provider: %v", err)
 	}