diff --git a/authorize/evaluator/evaluator.go b/authorize/evaluator/evaluator.go index 726bd8b8f..eb422ddac 100644 --- a/authorize/evaluator/evaluator.go +++ b/authorize/evaluator/evaluator.go @@ -84,10 +84,11 @@ type RequestSession struct { // Result is the result of evaluation. type Result struct { - Allow RuleResult - Deny RuleResult - Headers http.Header - Traces []contextutil.PolicyEvaluationTrace + Allow RuleResult + Deny RuleResult + Headers http.Header + Traces []contextutil.PolicyEvaluationTrace + AdditionalLogFields map[log.AuthorizeLogField]any } // An Evaluator evaluates policies. @@ -228,10 +229,11 @@ func (e *Evaluator) Evaluate(ctx context.Context, req *Request) (*Result, error) } res := &Result{ - Allow: policyOutput.Allow, - Deny: policyOutput.Deny, - Headers: headersOutput.Headers, - Traces: policyOutput.Traces, + Allow: policyOutput.Allow, + Deny: policyOutput.Deny, + Headers: headersOutput.Headers, + Traces: policyOutput.Traces, + AdditionalLogFields: headersOutput.AdditionalLogFields, } return res, nil } diff --git a/authorize/evaluator/headers_evaluator.go b/authorize/evaluator/headers_evaluator.go index e5a706917..2119aac9c 100644 --- a/authorize/evaluator/headers_evaluator.go +++ b/authorize/evaluator/headers_evaluator.go @@ -8,12 +8,14 @@ import ( "github.com/open-policy-agent/opa/rego" "github.com/pomerium/pomerium/authorize/internal/store" + "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/internal/telemetry/trace" ) // HeadersResponse is the output from the headers.rego script. type HeadersResponse struct { - Headers http.Header + Headers http.Header + AdditionalLogFields map[log.AuthorizeLogField]any } // A HeadersEvaluator evaluates the headers.rego script. diff --git a/authorize/evaluator/headers_evaluator_evaluation.go b/authorize/evaluator/headers_evaluator_evaluation.go index 19db20e6a..d05a7b360 100644 --- a/authorize/evaluator/headers_evaluator_evaluation.go +++ b/authorize/evaluator/headers_evaluator_evaluation.go @@ -15,6 +15,7 @@ import ( envoy_config_cluster_v3 "github.com/envoyproxy/go-control-plane/envoy/config/cluster/v3" "github.com/go-jose/go-jose/v3" "github.com/google/uuid" + "github.com/rs/zerolog" "google.golang.org/protobuf/types/known/structpb" "github.com/pomerium/datasource/pkg/directory" @@ -23,7 +24,7 @@ import ( "github.com/pomerium/pomerium/pkg/cryptutil" "github.com/pomerium/pomerium/pkg/grpc/session" "github.com/pomerium/pomerium/pkg/grpc/user" - "github.com/pomerium/pomerium/pkg/slices" + "github.com/pomerium/pomerium/pkg/telemetry/requestid" ) // A headersEvaluatorEvaluation is a single evaluation of the headers evaluator. @@ -57,8 +58,11 @@ func newHeadersEvaluatorEvaluation(evaluator *HeadersEvaluator, request *Request return &headersEvaluatorEvaluation{ evaluator: evaluator, request: request, - response: &HeadersResponse{Headers: make(http.Header)}, - now: now, + response: &HeadersResponse{ + Headers: make(http.Header), + AdditionalLogFields: make(map[log.AuthorizeLogField]any), + }, + now: now, } } @@ -337,7 +341,8 @@ func (e *headersEvaluatorEvaluation) getFilteredGroups(ctx context.Context) []st if len(filters) == 0 { return groups } - return slices.Filter(groups, func(g string) bool { + + filterFn := func(g string) bool { // A group should be included if it appears in either the global or the route-level filter list. for _, f := range filters { if f.IsAllowed(g) { @@ -345,7 +350,30 @@ func (e *headersEvaluatorEvaluation) getFilteredGroups(ctx context.Context) []st } } return false - }) + } + var included []string + + // Log the specifics of which groups were filtered out at Debug level. + var excluded *zerolog.Array + if log.Ctx(ctx).GetLevel() <= zerolog.DebugLevel { + excluded = zerolog.Arr() + } + + for _, g := range groups { + if filterFn(g) { + included = append(included, g) + } else if excluded != nil { + excluded.Str(g) + } + } + if removedCount := len(groups) - len(included); removedCount > 0 { + log.Ctx(ctx).Debug(). + Str("request-id", requestid.FromContext(ctx)). + Array("removed-groups", excluded). + Msg("group filtering removed groups") + e.response.AdditionalLogFields[log.AuthorizeLogFieldRemovedGroupsCount] = removedCount + } + return included } // getAllGroups returns the full group names/IDs list (without any filtering). diff --git a/authorize/log.go b/authorize/log.go index 594689245..c5e2e5bc7 100644 --- a/authorize/log.go +++ b/authorize/log.go @@ -33,7 +33,7 @@ func (a *Authorize) logAuthorizeCheck( evt := log.Ctx(ctx).Info().Str("service", "authorize") fields := a.currentOptions.Load().GetAuthorizeLogFields() for _, field := range fields { - evt = populateLogEvent(ctx, field, evt, in, s, u, hdrs, impersonateDetails) + evt = populateLogEvent(ctx, field, evt, in, s, u, hdrs, impersonateDetails, res) } evt = log.HTTPHeaders(evt, fields, hdrs) @@ -132,6 +132,7 @@ func populateLogEvent( u *user.User, hdrs map[string]string, impersonateDetails *impersonateDetails, + res *evaluator.Result, ) *zerolog.Event { path, query, _ := strings.Cut(in.GetAttributes().GetRequest().GetHttp().GetPath(), "?") @@ -198,6 +199,11 @@ func populateLogEvent( } return evt.Str(string(field), userID) default: + if res != nil { + if v, ok := res.AdditionalLogFields[field]; ok { + evt = evt.Interface(string(field), v) + } + } return evt } } diff --git a/authorize/log_test.go b/authorize/log_test.go index e03c1da70..9c2ad8453 100644 --- a/authorize/log_test.go +++ b/authorize/log_test.go @@ -11,6 +11,7 @@ import ( "github.com/rs/zerolog" "github.com/stretchr/testify/assert" + "github.com/pomerium/pomerium/authorize/evaluator" "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/pkg/grpc/session" "github.com/pomerium/pomerium/pkg/grpc/user" @@ -64,6 +65,11 @@ func Test_populateLogEvent(t *testing.T) { sessionID: "IMPERSONATE-SESSION-ID", userID: "IMPERSONATE-USER-ID", } + res := &evaluator.Result{ + AdditionalLogFields: map[log.AuthorizeLogField]any{ + log.AuthorizeLogFieldRemovedGroupsCount: 42, + }, + } for _, tc := range []struct { field log.AuthorizeLogField @@ -82,6 +88,7 @@ func Test_populateLogEvent(t *testing.T) { {log.AuthorizeLogFieldMethod, s, `{"method":"GET"}`}, {log.AuthorizeLogFieldPath, s, `{"path":"https://www.example.com/some/path"}`}, {log.AuthorizeLogFieldQuery, s, `{"query":"a=b"}`}, + {log.AuthorizeLogFieldRemovedGroupsCount, s, `{"removed-groups-count":42}`}, {log.AuthorizeLogFieldRequestID, s, `{"request-id":"REQUEST-ID"}`}, {log.AuthorizeLogFieldServiceAccountID, sa, `{"service-account-id":"SERVICE-ACCOUNT-ID"}`}, {log.AuthorizeLogFieldSessionID, s, `{"session-id":"SESSION-ID"}`}, @@ -97,7 +104,7 @@ func Test_populateLogEvent(t *testing.T) { var buf bytes.Buffer log := zerolog.New(&buf) evt := log.Log() - evt = populateLogEvent(ctx, tc.field, evt, checkRequest, tc.s, u, headers, impersonateDetails) + evt = populateLogEvent(ctx, tc.field, evt, checkRequest, tc.s, u, headers, impersonateDetails, res) evt.Send() assert.Equal(t, tc.expect, strings.TrimSpace(buf.String())) diff --git a/internal/log/authorize.go b/internal/log/authorize.go index 18521797e..f2f0c07e2 100644 --- a/internal/log/authorize.go +++ b/internal/log/authorize.go @@ -23,6 +23,7 @@ const ( AuthorizeLogFieldMethod AuthorizeLogField = "method" AuthorizeLogFieldPath AuthorizeLogField = "path" AuthorizeLogFieldQuery AuthorizeLogField = "query" + AuthorizeLogFieldRemovedGroupsCount AuthorizeLogField = "removed-groups-count" AuthorizeLogFieldRequestID AuthorizeLogField = "request-id" AuthorizeLogFieldServiceAccountID AuthorizeLogField = "service-account-id" AuthorizeLogFieldSessionID AuthorizeLogField = "session-id" @@ -41,6 +42,7 @@ var DefaultAuthorizeLogFields = []AuthorizeLogField{ AuthorizeLogFieldImpersonateSessionID, AuthorizeLogFieldImpersonateUserID, AuthorizeLogFieldImpersonateEmail, + AuthorizeLogFieldRemovedGroupsCount, AuthorizeLogFieldServiceAccountID, AuthorizeLogFieldUser, AuthorizeLogFieldEmail, @@ -63,6 +65,7 @@ var authorizeLogFieldLookup = map[AuthorizeLogField]struct{}{ AuthorizeLogFieldMethod: {}, AuthorizeLogFieldPath: {}, AuthorizeLogFieldQuery: {}, + AuthorizeLogFieldRemovedGroupsCount: {}, AuthorizeLogFieldRequestID: {}, AuthorizeLogFieldServiceAccountID: {}, AuthorizeLogFieldSessionID: {},