diff --git a/contrib/claude/authorization.md b/contrib/claude/authorization.md index 795e84917..2e9039980 100644 --- a/contrib/claude/authorization.md +++ b/contrib/claude/authorization.md @@ -292,6 +292,20 @@ When adding a new entity that needs authorization: 4. **Entity type registry** — register in `pkg/coredata/entity_type_reg.go` and `NewEntityFromID` so the authorizer can construct the entity from its GID 5. **Resolver calls** — add `scope, err := r.authorize(ctx, id, probo.ActionEntityGet)` in GraphQL resolvers and `scope, err := r.Authorize(ctx, id, probo.ActionEntityGet)` in MCP resolvers, then pass `scope` to services +## Decision logging + +Every authorization evaluation (allow and deny) emits a structured `authz decision` +log line through the authorizer logger with opaque IDs only: + +- `effect` — `allow`, `deny`, `no_match`, or `error` +- `action`, `principal_id`, `resource_id` +- `policy_id` — statement SID when available +- `reason` — human-readable explanation for operators (never returned to clients) +- `latency` — PDP evaluation duration + +Audit log entries remain **allow-only**. Denials are visible in application logs, +not the product audit trail. + ## Key patterns - **Always use `organization_id` condition** — most policies scope access to the principal's organization diff --git a/pkg/iam/authorizer.go b/pkg/iam/authorizer.go index d03edac41..f5aa47431 100644 --- a/pkg/iam/authorizer.go +++ b/pkg/iam/authorizer.go @@ -445,6 +445,17 @@ func (a *Authorizer) evaluateMultiInTx( if assumptionErr != nil && !item.SkipAssumptionCheck { decisions[i] = assumptionErr + a.logDecision( + ctx, + DecisionRecord{ + Effect: effectError, + Action: item.Action, + ResourceID: item.Resource, + Principal: params.Principal, + Reason: assumptionErr.Error(), + }, + ) + continue } @@ -458,7 +469,22 @@ func (a *Authorizer) evaluateMultiInTx( }, } - if !a.evaluator.Evaluate(req, policies).IsAllowed() { + startedAt := time.Now() + result := a.evaluator.Evaluate(req, policies) + + a.logDecision( + ctx, + newDecisionRecord( + result, + params.Principal, + item.Resource, + item.Action, + role, + time.Since(startedAt), + ), + ) + + if !result.IsAllowed() { decisions[i] = NewInsufficientPermissionsError(params.Principal, item.Resource, item.Action) } } diff --git a/pkg/iam/authorizer_decisionlog_test.go b/pkg/iam/authorizer_decisionlog_test.go new file mode 100644 index 000000000..0d896574e --- /dev/null +++ b/pkg/iam/authorizer_decisionlog_test.go @@ -0,0 +1,163 @@ +// Copyright (c) 2026 Probo Inc . +// +// Permission to use, copy, modify, and/or distribute this software for any +// purpose with or without fee is hereby granted, provided that the above +// copyright notice and this permission notice appear in all copies. +// +// THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES WITH +// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY +// AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY SPECIAL, DIRECT, +// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM +// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE OR +// OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR +// PERFORMANCE OF THIS SOFTWARE. + +package iam_test + +import ( + "bytes" + "context" + "strings" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "go.gearno.de/kit/log" + "go.gearno.de/kit/pg" + + "go.probo.inc/probo/internal/test" + "go.probo.inc/probo/pkg/coredata" + "go.probo.inc/probo/pkg/gid" + "go.probo.inc/probo/pkg/iam" + "go.probo.inc/probo/pkg/iam/policy" +) + +func TestAuthorizer_DecisionLogging(t *testing.T) { + t.Parallel() + + t.Run("allow writes audit and decision log", func(t *testing.T) { + t.Parallel() + + client := test.PGClient(t) + fixture := seedBatchAuthorizeFixture(t, context.Background(), client) + action := newBatchTestAction() + + var logOutput bytes.Buffer + + authorizer := newTestAuthorizerWithLogger(client, action, nil, &logOutput) + + _, err := authorizer.AuthorizeBatch( + context.Background(), + iam.AuthorizeBatchParams{ + Principal: fixture.identityID, + Action: action, + Resources: []gid.GID{fixture.frameworkID1}, + }, + ) + require.NoError(t, err) + + output := logOutput.String() + assert.Contains(t, output, "authz decision") + assert.Contains(t, output, "allow") + assert.Contains(t, output, action) + assert.Contains(t, output, fixture.identityID.String()) + assert.Contains(t, output, fixture.frameworkID1.String()) + assert.Contains(t, output, "allow-test-action") + assert.Equal(t, 1, countAuditLogsForAction(t, context.Background(), client, action)) + }) + + t.Run("deny writes decision log without audit row", func(t *testing.T) { + t.Parallel() + + client := test.PGClient(t) + fixture := seedBatchAuthorizeFixture(t, context.Background(), client) + action := newBatchTestAction() + + var logOutput bytes.Buffer + + authorizer := newTestAuthorizerWithLogger( + client, + action, + nil, + &logOutput, + policy.Deny(action).WithSID("deny-test-action"), + ) + + _, err := authorizer.AuthorizeBatch( + context.Background(), + iam.AuthorizeBatchParams{ + Principal: fixture.identityID, + Action: action, + Resources: []gid.GID{fixture.frameworkID1}, + }, + ) + require.Error(t, err) + + output := logOutput.String() + assert.Contains(t, output, "authz decision") + assert.Contains(t, output, "deny") + assert.Contains(t, output, "deny-test-action") + assert.Contains(t, output, "explicit deny by statement deny-test-action") + assert.Equal(t, 0, countAuditLogsForAction(t, context.Background(), client, action)) + }) + + t.Run("implicit deny logs no_match without policy id", func(t *testing.T) { + t.Parallel() + + client := test.PGClient(t) + fixture := seedBatchAuthorizeFixture(t, context.Background(), client) + action := newBatchTestAction() + + var logOutput bytes.Buffer + + authorizer := newTestAuthorizerWithLogger( + client, + "core:other:action", + nil, + &logOutput, + ) + + _, err := authorizer.AuthorizeBatch( + context.Background(), + iam.AuthorizeBatchParams{ + Principal: fixture.identityID, + Action: action, + Resources: []gid.GID{fixture.frameworkID1}, + }, + ) + require.Error(t, err) + + output := logOutput.String() + assert.Contains(t, output, "authz decision") + assert.Contains(t, output, "no_match") + assert.NotContains(t, output, "policy_id") + assert.True(t, strings.Contains(output, "implicit deny")) + }) +} + +func newTestAuthorizerWithLogger( + client *pg.Client, + action string, + allowResourceID *gid.GID, + logOutput *bytes.Buffer, + extraStatements ...policy.Statement, +) *iam.Authorizer { + statements := []policy.Statement{ + policy.Allow(action).WithSID("allow-test-action"), + } + if allowResourceID != nil { + statements[0] = statements[0].When(policy.Equals("resource.id", allowResourceID.String())) + } + + statements = append(statements, extraStatements...) + + authorizer := iam.NewAuthorizer(client, log.NewLogger(log.WithOutput(logOutput))) + authorizer.RegisterPolicySet( + iam.NewPolicySet().AddRolePolicy( + string(coredata.MembershipRoleOwner), + policy.NewPolicy("batch-authorize-test", "Batch Authorize Test", statements...), + ), + ) + + return authorizer +} diff --git a/pkg/iam/decision_log.go b/pkg/iam/decision_log.go new file mode 100644 index 000000000..42b464240 --- /dev/null +++ b/pkg/iam/decision_log.go @@ -0,0 +1,89 @@ +// Copyright (c) 2026 Probo Inc . +// +// Permission to use, copy, modify, and/or distribute this software for any +// purpose with or without fee is hereby granted, provided that the above +// copyright notice and this permission notice appear in all copies. +// +// THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES WITH +// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY +// AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY SPECIAL, DIRECT, +// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM +// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE OR +// OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR +// PERFORMANCE OF THIS SOFTWARE. + +package iam + +import ( + "context" + "time" + + "go.gearno.de/kit/log" + "go.probo.inc/probo/pkg/gid" + "go.probo.inc/probo/pkg/iam/policy" +) + +const effectError = "error" + +// DecisionRecord is a structured authorization decision for logging. +type DecisionRecord struct { + Effect string + Action string + ResourceID gid.GID + Principal gid.GID + PolicyID string + Reason string + Latency time.Duration +} + +func newDecisionRecord( + result policy.EvaluationResult, + principal gid.GID, + resourceID gid.GID, + action string, + role string, + latency time.Duration, +) DecisionRecord { + return DecisionRecord{ + Effect: string(result.Decision), + Action: action, + ResourceID: resourceID, + Principal: principal, + PolicyID: result.PolicyID(), + Reason: result.Reason(role), + Latency: latency, + } +} + +func (a *Authorizer) logDecision(ctx context.Context, rec DecisionRecord) { + if a.logger == nil { + return + } + + if rec.PolicyID != "" { + a.logger.InfoCtx( + ctx, + "authz decision", + log.String("effect", rec.Effect), + log.String("action", rec.Action), + log.String("principal_id", rec.Principal.String()), + log.String("resource_id", rec.ResourceID.String()), + log.String("policy_id", rec.PolicyID), + log.String("reason", rec.Reason), + log.Duration("latency", rec.Latency), + ) + + return + } + + a.logger.InfoCtx( + ctx, + "authz decision", + log.String("effect", rec.Effect), + log.String("action", rec.Action), + log.String("principal_id", rec.Principal.String()), + log.String("resource_id", rec.ResourceID.String()), + log.String("reason", rec.Reason), + log.Duration("latency", rec.Latency), + ) +} diff --git a/pkg/iam/policy/evaluator.go b/pkg/iam/policy/evaluator.go index 8ea746947..72100e16e 100644 --- a/pkg/iam/policy/evaluator.go +++ b/pkg/iam/policy/evaluator.go @@ -47,6 +47,52 @@ func (r EvaluationResult) IsAllowed() bool { return r.Decision == DecisionAllow } +func (r EvaluationResult) statementSID() string { + if r.MatchedStatement != nil { + return r.MatchedStatement.SID + } + + return "" +} + +// PolicyID returns the statement SID or matched policy ID for logging. +func (r EvaluationResult) PolicyID() string { + if sid := r.statementSID(); sid != "" { + return sid + } + + if r.MatchedPolicy != nil { + return r.MatchedPolicy.ID + } + + return "" +} + +// Reason returns a human-readable explanation for logging. +func (r EvaluationResult) Reason(role string) string { + if sid := r.statementSID(); sid != "" { + switch r.Decision { + case DecisionAllow: + return "allowed by statement " + sid + case DecisionDeny: + return "explicit deny by statement " + sid + } + } + + switch r.Decision { + case DecisionAllow: + return "allowed" + case DecisionDeny: + return "explicit deny" + default: + if role != "" { + return "implicit deny: no matching allow for role " + role + } + + return "implicit deny: no matching allow" + } +} + // AuthorizationRequest contains all information needed to evaluate access. type AuthorizationRequest struct { // Principal is the actor requesting access. diff --git a/pkg/iam/policy/evaluator_test.go b/pkg/iam/policy/evaluator_test.go index 7e2b4a9d2..337933285 100644 --- a/pkg/iam/policy/evaluator_test.go +++ b/pkg/iam/policy/evaluator_test.go @@ -462,3 +462,52 @@ func TestEvaluationResult_IsAllowed(t *testing.T) { }) } } + +func TestEvaluationResult_PolicyID(t *testing.T) { + t.Parallel() + + result := EvaluationResult{ + Decision: DecisionAllow, + MatchedStatement: &Statement{ + SID: "read-thirdParties", + }, + MatchedPolicy: &Policy{ + ID: "probo:viewer", + }, + } + + if got := result.PolicyID(); got != "read-thirdParties" { + t.Errorf("PolicyID() = %q, want read-thirdParties", got) + } +} + +func TestEvaluationResult_Reason(t *testing.T) { + t.Parallel() + + t.Run("implicit deny includes role", func(t *testing.T) { + t.Parallel() + + result := EvaluationResult{Decision: DecisionNoMatch} + want := "implicit deny: no matching allow for role VIEWER" + + if got := result.Reason("VIEWER"); got != want { + t.Errorf("Reason() = %q, want %q", got, want) + } + }) + + t.Run("explicit deny uses statement sid", func(t *testing.T) { + t.Parallel() + + result := EvaluationResult{ + Decision: DecisionDeny, + MatchedStatement: &Statement{ + SID: "deny-delete", + }, + } + want := "explicit deny by statement deny-delete" + + if got := result.Reason("ADMIN"); got != want { + t.Errorf("Reason() = %q, want %q", got, want) + } + }) +}