Skip to content

fixed context propogation and logging inconsistencies #5637

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
sacrana0 wants to merge 1 commit into
base: main
Choose a base branch
from
+831 −559
Open

fixed context propogation and logging inconsistencies #5637

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 9 additions & 9 deletions backend/internal/actorprovider/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -127,13 +127,13 @@ func (p *actorProvider) AuthenticateActor(
}

// GetActor returns the backing entity record for the given actor ID.
func (p *actorProvider) GetActor(actorID string) (*providers.Entity, *tidcommon.ServiceError) {
entity, epErr := p.entityProvider.GetEntity(actorID)
func (p *actorProvider) GetActor(ctx context.Context, actorID string) (*providers.Entity, *tidcommon.ServiceError) {
entity, epErr := p.entityProvider.GetEntity(ctx, actorID)
if epErr != nil {
return nil, mapEntityProviderError(epErr)
}
if entity.Category == providers.EntityCategoryAgent {
ctx := security.WithRuntimeContext(context.Background())
ctx := security.WithRuntimeContext(ctx)
displayPaths := entitytype.ResolveDisplayAttributePaths(
ctx, entitytype.TypeCategoryAgent, []string{entity.Type}, p.entityTypeSvc, p.logger)
entity.Display = utils.ResolveDisplay(entity.ID, entity.Type, entity.Attributes, displayPaths)
Expand All @@ -143,9 +143,9 @@ func (p *actorProvider) GetActor(actorID string) (*providers.Entity, *tidcommon.

// GetActorGroups returns transitive group memberships for the given actor ID.
func (p *actorProvider) GetActorGroups(
actorID string,
ctx context.Context, actorID string,
) ([]providers.EntityGroup, *tidcommon.ServiceError) {
groups, epErr := p.entityProvider.GetTransitiveEntityGroups(actorID)
groups, epErr := p.entityProvider.GetTransitiveEntityGroups(ctx, actorID)
if epErr != nil {
if epErr.Code == entityprovider.ErrorCodeNotImplemented {
return nil, nil
Expand All @@ -157,9 +157,9 @@ func (p *actorProvider) GetActorGroups(

// GetTransitiveGroupAncestors returns the ancestor chain of a single group.
func (p *actorProvider) GetTransitiveGroupAncestors(
groupID string,
ctx context.Context, groupID string,
) ([]string, *tidcommon.ServiceError) {
ancestors, epErr := p.entityProvider.GetTransitiveGroupAncestors(groupID)
ancestors, epErr := p.entityProvider.GetTransitiveGroupAncestors(ctx, groupID)
if epErr != nil {
if epErr.Code == entityprovider.ErrorCodeNotImplemented {
return nil, nil
Expand All @@ -171,12 +171,12 @@ func (p *actorProvider) GetTransitiveGroupAncestors(

// GetActorRoles returns the roles assigned to the actor, directly and through the given groups.
func (p *actorProvider) GetActorRoles(
actorID string, groupIDs []string,
ctx context.Context, actorID string, groupIDs []string,
) ([]string, *tidcommon.ServiceError) {
if p.roleService == nil {
return nil, nil
}
return p.roleService.GetUserRoles(context.Background(), actorID, groupIDs)
return p.roleService.GetUserRoles(ctx, actorID, groupIDs)
}

func mapEntityProviderError(epErr *entityprovider.EntityProviderError) *tidcommon.ServiceError {
Expand Down
18 changes: 9 additions & 9 deletions backend/internal/actorprovider/service_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -167,9 +167,9 @@ func (s *ActorProviderTestSuite) TestAuthenticateActor_Delegates_Failure() {

func (s *ActorProviderTestSuite) TestGetActor_Delegates() {
expected := &providers.Entity{ID: "app-1"}
s.mockEntity.On("GetEntity", "app-1").Return(expected, (*entityprovider.EntityProviderError)(nil))
s.mockEntity.On("GetEntity", mock.Anything, "app-1").Return(expected, (*entityprovider.EntityProviderError)(nil))

entity, err := s.provider.GetActor("app-1")
entity, err := s.provider.GetActor(context.Background(), "app-1")

s.Nil(err)
s.Equal(expected, entity)
Expand All @@ -189,12 +189,12 @@ func (s *ActorProviderTestSuite) TestGetActor_AgentDisplayComesFromTheDisplayAtt
[]string{"default"}).Return(map[string]string{"default": tc.displayPath},
(*tidcommon.ServiceError)(nil)).Once()
provider := Initialize(s.mockInbound, s.mockEntity, s.mockAuthn, s.mockRole, mockType)
s.mockEntity.On("GetEntity", "agent-1").Return(&providers.Entity{
s.mockEntity.On("GetEntity", mock.Anything, "agent-1").Return(&providers.Entity{
ID: "agent-1", Category: providers.EntityCategoryAgent, Type: "default",
Attributes: []byte(`{"name":"Ledger Agent"}`),
}, (*entityprovider.EntityProviderError)(nil)).Once()

entity, err := provider.GetActor("agent-1")
entity, err := provider.GetActor(context.Background(), "agent-1")

s.Nil(err)
s.Equal(tc.want, entity.Display)
Expand All @@ -204,9 +204,9 @@ func (s *ActorProviderTestSuite) TestGetActor_AgentDisplayComesFromTheDisplayAtt

func (s *ActorProviderTestSuite) TestGetActorGroups_Delegates() {
expected := []providers.EntityGroup{{ID: "group-1"}}
s.mockEntity.On("GetTransitiveEntityGroups", "app-1").Return(expected, (*entityprovider.EntityProviderError)(nil))
s.mockEntity.On("GetTransitiveEntityGroups", mock.Anything, "app-1").Return(expected, (*entityprovider.EntityProviderError)(nil))

groups, err := s.provider.GetActorGroups("app-1")
groups, err := s.provider.GetActorGroups(context.Background(), "app-1")

s.Nil(err)
s.Equal(expected, groups)
Expand All @@ -218,7 +218,7 @@ func (s *ActorProviderTestSuite) TestGetActorRoles_Delegates() {
s.mockRole.On("GetUserRoles", mock.Anything, "app-1", groupIDs).
Return(expected, (*tidcommon.ServiceError)(nil))

roles, err := s.provider.GetActorRoles("app-1", groupIDs)
roles, err := s.provider.GetActorRoles(context.Background(), "app-1", groupIDs)

s.Nil(err)
s.Equal(expected, roles)
Expand All @@ -231,7 +231,7 @@ func (s *ActorProviderTestSuite) TestGetActorRoles_PropagatesError() {
}
s.mockRole.On("GetUserRoles", mock.Anything, "app-1", []string{"group-1"}).Return(nil, svcErr)

roles, err := s.provider.GetActorRoles("app-1", []string{"group-1"})
roles, err := s.provider.GetActorRoles(context.Background(), "app-1", []string{"group-1"})

s.Nil(roles)
s.Equal(svcErr, err)
Expand All @@ -240,7 +240,7 @@ func (s *ActorProviderTestSuite) TestGetActorRoles_PropagatesError() {
func (s *ActorProviderTestSuite) TestGetActorRoles_NilRoleService_ReturnsNil() {
provider := Initialize(s.mockInbound, s.mockEntity, s.mockAuthn, nil, nil)

roles, err := provider.GetActorRoles("app-1", []string{"group-1"})
roles, err := provider.GetActorRoles(context.Background(), "app-1", []string{"group-1"})

s.Nil(err)
s.Nil(roles)
Expand Down
2 changes: 1 addition & 1 deletion backend/internal/actorprovider/utils.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ func BuildApplication(
return nil, &ErrorActorNotFound
}

entity, entityErr := provider.GetActor(actorID)
entity, entityErr := provider.GetActor(ctx, actorID)
if entityErr != nil && entityErr.Code != ErrorEntityNotFound.Code {
return nil, &tidcommon.InternalServerError
}
Expand Down
6 changes: 3 additions & 3 deletions backend/internal/actorprovider/utils_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ func (s *UtilsTestSuite) TestBuildApplication_Success() {
entity := &providers.Entity{ID: "app-1", SystemAttributes: attrs}

s.mockInbound.On("GetInboundClientByEntityID", mock.Anything, "app-1").Return(client, nil)
s.mockEntity.On("GetEntity", "app-1").Return(entity, (*entityprovider.EntityProviderError)(nil))
s.mockEntity.On("GetEntity", mock.Anything, "app-1").Return(entity, (*entityprovider.EntityProviderError)(nil))

app, svcErr := BuildApplication(context.Background(), s.provider, "app-1")

Expand All @@ -81,7 +81,7 @@ func (s *UtilsTestSuite) TestBuildApplication_NilClient() {
func (s *UtilsTestSuite) TestBuildApplication_EntityLoadError() {
client := &inboundmodel.InboundClient{ID: "app-1"}
s.mockInbound.On("GetInboundClientByEntityID", mock.Anything, "app-1").Return(client, nil)
s.mockEntity.On("GetEntity", "app-1").Return(
s.mockEntity.On("GetEntity", mock.Anything, "app-1").Return(
(*providers.Entity)(nil),
entityprovider.NewEntityProviderError("INTERNAL_ERROR", "boom", ""))

Expand All @@ -94,7 +94,7 @@ func (s *UtilsTestSuite) TestBuildApplication_EntityLoadError() {
func (s *UtilsTestSuite) TestBuildApplication_EntityNotFound() {
client := &inboundmodel.InboundClient{ID: "app-1", AllowedUserTypes: []string{"customer"}}
s.mockInbound.On("GetInboundClientByEntityID", mock.Anything, "app-1").Return(client, nil)
s.mockEntity.On("GetEntity", "app-1").Return(
s.mockEntity.On("GetEntity", mock.Anything, "app-1").Return(
(*providers.Entity)(nil),
entityprovider.NewEntityProviderError(entityprovider.ErrorCodeEntityNotFound, "missing", ""))

Expand Down
2 changes: 1 addition & 1 deletion backend/internal/application/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -403,7 +403,7 @@ func (as *applicationService) GetOAuthApplication(
appEntity, entErr := as.entityService.GetEntity(ctx, client.ID)
if entErr != nil && !errors.Is(entErr, entity.ErrEntityNotFound) {
as.logger.Error(ctx, "Failed to load entity for OAuth client",
log.String("entityID", client.ID), log.Error(entErr))
log.MaskedString("entityID", client.ID), log.Error(entErr))
return nil, &tidcommon.InternalServerError
}
if appEntity == nil || appEntity.Category != providers.EntityCategoryApp {
Expand Down
2 changes: 1 addition & 1 deletion backend/internal/authn/github/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -137,7 +137,7 @@ func (g *githubOAuthAuthnService) GetOAuthClientConfig(ctx context.Context, idpI
// fetches user info, and builds the federated token. The entity is resolved later through recorded links.
func (g *githubOAuthAuthnService) Authenticate(ctx context.Context, idpID string,
authzData authncm.AuthorizationData) (*authncm.AuthnResult, *tidcommon.ServiceError) {
logger := g.logger.With(log.String("idpId", idpID))
logger := g.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Performing federated GitHub OAuth authentication")

tokenResp, svcErr := g.ExchangeCodeForToken(ctx, idpID, authzData.Code, true)
Expand Down
6 changes: 3 additions & 3 deletions backend/internal/authn/google/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ func (g *googleOIDCAuthnService) ValidateTokenResponse(ctx context.Context, idpI
// is called with validateResponse set to true.
func (g *googleOIDCAuthnService) ValidateIDToken(
ctx context.Context, idpID, idToken string) *tidcommon.ServiceError {
logger := g.logger.With(log.String("idpId", idpID))
logger := g.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Validating ID token")

if strings.TrimSpace(idToken) == "" {
Expand Down Expand Up @@ -137,7 +137,7 @@ func (g *googleOIDCAuthnService) ValidateIDToken(
aud, ok := claims["aud"].(string)
if !ok || aud != oAuthClientConfig.ClientID {
logger.Debug(ctx, "Invalid ID token audience", log.String("audience", aud),
log.MaskedString("clientId", oAuthClientConfig.ClientID))
log.MaskedString("clientID", oAuthClientConfig.ClientID))
return tidcommon.CustomServiceError(authnoidc.ErrorInvalidIDToken, tidcommon.I18nMessage{
Key: "error.authnservice.google.invalid_id_token_audience_description",
DefaultValue: "The ID token audience does not match the expected client ID",
Expand Down Expand Up @@ -224,7 +224,7 @@ func (g *googleOIDCAuthnService) GetOAuthClientConfig(ctx context.Context, idpID
// resolved later through recorded links.
func (g *googleOIDCAuthnService) Authenticate(ctx context.Context, idpID string,
authzData common.AuthorizationData) (*common.AuthnResult, *tidcommon.ServiceError) {
logger := g.logger.With(log.String("idpId", idpID))
logger := g.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Performing federated Google OIDC authentication")

tokenResp, svcErr := g.ExchangeCodeForToken(ctx, idpID, authzData.Code, true)
Expand Down
10 changes: 5 additions & 5 deletions backend/internal/authn/oauth/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -68,7 +68,7 @@ func newOAuthAuthnService(httpClient syshttp.HTTPClientInterface,
// GetOAuthClientConfig retrieves the OAuth client configuration for the given identity provider ID.
func (s *oAuthAuthnService) GetOAuthClientConfig(ctx context.Context, idpID string) (
*OAuthClientConfig, *tidcommon.ServiceError) {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
if strings.TrimSpace(idpID) == "" {
return nil, &ErrorEmptyIdpID
}
Expand Down Expand Up @@ -101,7 +101,7 @@ func (s *oAuthAuthnService) GetOAuthClientConfig(ctx context.Context, idpID stri
// BuildAuthorizeURL constructs the authorization request URL for the external identity provider.
func (s *oAuthAuthnService) BuildAuthorizeURL(
ctx context.Context, idpID string) (string, map[string]string, *tidcommon.ServiceError) {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Building authorize URL")

oAuthClientConfig, svcErr := s.GetOAuthClientConfig(ctx, idpID)
Expand Down Expand Up @@ -151,7 +151,7 @@ func (s *oAuthAuthnService) BuildAuthorizeURL(
// and validates the token response if validateResponse is true.
func (s *oAuthAuthnService) ExchangeCodeForToken(ctx context.Context, idpID, code string, validateResponse bool) (
*TokenResponse, *tidcommon.ServiceError) {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Exchanging authorization code for token")

if strings.TrimSpace(code) == "" {
Expand Down Expand Up @@ -192,7 +192,7 @@ func (s *oAuthAuthnService) ExchangeCodeForToken(ctx context.Context, idpID, cod
// to true. Hence generally you may not need to call this method explicitly.
func (s *oAuthAuthnService) ValidateTokenResponse(ctx context.Context,
idpID string, tokenResp *TokenResponse) *tidcommon.ServiceError {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Validating token response")

if tokenResp == nil {
Expand Down Expand Up @@ -252,7 +252,7 @@ func (s *oAuthAuthnService) FetchUserInfoWithClientConfig(ctx context.Context, o
// claim and builds the federated token. The entity is resolved later through recorded links.
func (s *oAuthAuthnService) Authenticate(ctx context.Context, idpID string,
authzData common.AuthorizationData) (*common.AuthnResult, *tidcommon.ServiceError) {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Performing federated OAuth authentication")

tokenResp, svcErr := s.ExchangeCodeForToken(ctx, idpID, authzData.Code, true)
Expand Down
4 changes: 2 additions & 2 deletions backend/internal/authn/oidc/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -134,7 +134,7 @@ func (s *oidcAuthnService) ValidateTokenResponse(ctx context.Context, idpID stri
// to true. Hence generally you may not need to call this method explicitly if ExchangeCodeForToken method
// is called with validateResponse set to true.
func (s *oidcAuthnService) ValidateIDToken(ctx context.Context, idpID, idToken string) *tidcommon.ServiceError {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Validating ID token")

if strings.TrimSpace(idToken) == "" {
Expand Down Expand Up @@ -197,7 +197,7 @@ func (s *oidcAuthnService) FetchUserInfo(ctx context.Context, idpID, accessToken
// resolved later through recorded links.
func (s *oidcAuthnService) Authenticate(ctx context.Context, idpID string,
authzData authncm.AuthorizationData) (*authncm.AuthnResult, *tidcommon.ServiceError) {
logger := s.logger.With(log.String("idpId", idpID))
logger := s.logger.With(log.String(log.LoggerKeyIDPID, idpID))
logger.Debug(ctx, "Performing federated OIDC authentication")

tokenResp, svcErr := s.ExchangeCodeForToken(ctx, idpID, authzData.Code, true)
Expand Down
8 changes: 4 additions & 4 deletions backend/internal/authn/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -315,7 +315,7 @@ func (as *authenticationService) StartIDPAuthentication(
) (
*IDPAuthInitData, *tidcommon.ServiceError) {
logger := log.GetLogger().With(log.String(log.LoggerKeyComponentName, svcLoggerComponentName))
logger.Debug(ctx, "Starting IDP authentication", log.String("idpId", idpID))
logger.Debug(ctx, "Starting IDP authentication", log.String(log.LoggerKeyIDPID, idpID))

if strings.TrimSpace(idpID) == "" {
return nil, &common.ErrorInvalidIDPID
Expand Down Expand Up @@ -344,7 +344,7 @@ func (as *authenticationService) StartIDPAuthentication(
case providers.IDPTypeGitHub:
redirectURL, _, buildURLErr = as.githubService.BuildAuthorizeURL(ctx, idpID)
default:
logger.Error(ctx, "Unsupported IDP type", log.String("idpId", idpID),
logger.Error(ctx, "Unsupported IDP type", log.String(log.LoggerKeyIDPID, idpID),
log.String("type", string(identityProvider.Type)))
return nil, &tidcommon.InternalServerError
}
Expand All @@ -360,7 +360,7 @@ func (as *authenticationService) StartIDPAuthentication(
}
sessionToken, err := as.createSessionToken(ctx, idpID, identityProvider.Type, nonce)
if err != nil {
logger.Error(ctx, "Failed to create session token", log.String("idpId", idpID),
logger.Error(ctx, "Failed to create session token", log.String(log.LoggerKeyIDPID, idpID),
log.String("error", err.Error.DefaultValue))
return nil, &tidcommon.InternalServerError
}
Expand Down Expand Up @@ -706,7 +706,7 @@ func (as *authenticationService) handleIDPServiceError(
}

logger.Error(ctx, "Error occurred while retrieving IDP",
log.String("idpId", idpID), log.Any("error", svcErr))
log.String(log.LoggerKeyIDPID, idpID), log.Any("error", svcErr))
return &tidcommon.InternalServerError
}

Expand Down
2 changes: 1 addition & 1 deletion backend/internal/authnprovider/defaultprovider/default_authn_provider.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -250,7 +250,7 @@ func (p *defaultAuthnProvider) StoreAccountLink(ctx context.Context, entityRefer
"The user has reached the limit of linked accounts")
}
return p.logAndReturnServerError(ctx, "Failed to link account",
log.String("idpId", idpID), log.String("error", err.Error()))
log.String(log.LoggerKeyIDPID, idpID), log.String("error", err.Error()))
}
return nil
}
Expand Down
2 changes: 1 addition & 1 deletion backend/internal/authnprovider/manager/manager.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -236,7 +236,7 @@ func (m *authnProviderManager) checkSubjectAllowed(
return nil
}
m.logger.Debug(ctx, "resolved subject is not allowed for the application",
log.String("entityId", entityRef.EntityID),
log.MaskedString(log.LoggerKeyEntityID, entityRef.EntityID),
log.String("entityCategory", entityRef.EntityCategory),
log.String("entityType", entityRef.EntityType))
return &ErrorSubjectNotAllowed
Expand Down
2 changes: 1 addition & 1 deletion backend/internal/authz/engine/authzenpdpengine.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -240,7 +240,7 @@ func (p *authZENPDPEngine) evaluateSingle(
if err := p.post(ctx, settings, evaluationEndpoint, payload, &responseDecision); err != nil {
p.logger.Error(ctx, "AuthZEN evaluation failed",
log.String("pdp_endpoint", evaluationEndpoint),
log.String("resource_server_id", evaluation.ResourceServer.ID),
log.String("resourceServerID", evaluation.ResourceServer.ID),
log.String("action", evaluation.Permission.Name),
log.Error(err),
)
Expand Down
4 changes: 2 additions & 2 deletions backend/internal/authzen/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -439,7 +439,7 @@ func (s *authzenService) resolveSubject(ctx context.Context, subject Subject) (S
if s.entityProvider == nil {
return subject, nil
}
entity, err := s.entityProvider.GetEntity(subject.ID)
entity, err := s.entityProvider.GetEntity(ctx, subject.ID)
if err != nil {
if err.Code == entityprovider.ErrorCodeNotImplemented {
return subject, nil
Expand Down Expand Up @@ -539,7 +539,7 @@ func (s *authzenService) resolveGroupIDs(ctx context.Context, entityID string) (
return []string{}, nil
}

groups, err := s.entityProvider.GetTransitiveEntityGroups(entityID)
groups, err := s.entityProvider.GetTransitiveEntityGroups(ctx, entityID)
if err != nil {
if err.Code == entityprovider.ErrorCodeNotImplemented {
return []string{}, nil
Expand Down
Loading
Loading