authorize: log JWT groups filtering

Add a new Authorize Log Fields option for logging the number of groups
removed during JWT groups filtering. This will be enabled by default.

Additionally, when the log level is Debug (or more verbose), store and
log the IDs of any groups removed during JWT groups filtering.
This commit is contained in:
Kenneth Jenkins 2025-01-08 13:33:21 -08:00
parent e9786f9719
commit 2bde1daab5
7 changed files with 84 additions and 29 deletions

View file

@ -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
}

View file

@ -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.

View file

@ -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,
}
}
@ -325,7 +329,7 @@ func (e *headersEvaluatorEvaluation) getJWTPayloadGroups(ctx context.Context) []
func (e *headersEvaluatorEvaluation) getGroups(ctx context.Context) []string {
groupIDs := e.getGroupIDs(ctx)
if len(groupIDs) > 0 {
groupIDs = e.filterGroups(groupIDs)
groupIDs = e.filterGroups(ctx, groupIDs)
groups := make([]string, 0, len(groupIDs)*2)
groups = append(groups, groupIDs...)
groups = append(groups, e.getDataBrokerGroupNames(ctx, groupIDs)...)
@ -337,7 +341,7 @@ func (e *headersEvaluatorEvaluation) getGroups(ctx context.Context) []string {
return groups
}
func (e *headersEvaluatorEvaluation) filterGroups(groups []string) []string {
func (e *headersEvaluatorEvaluation) filterGroups(ctx context.Context, groups []string) []string {
// Apply the global groups filter or the per-route groups filter, if either is enabled.
filters := make([]config.JWTGroupsFilter, 0, 2)
if f := e.evaluator.store.GetJWTGroupsFilter(); f.Enabled() {
@ -349,7 +353,8 @@ func (e *headersEvaluatorEvaluation) filterGroups(groups []string) []string {
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) {
@ -357,7 +362,30 @@ func (e *headersEvaluatorEvaluation) filterGroups(groups []string) []string {
}
}
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-ids", excluded).
Msg("JWT group filtering removed groups")
e.response.AdditionalLogFields[log.AuthorizeLogFieldRemovedGroupsCount] = removedCount
}
return included
}
func (e *headersEvaluatorEvaluation) getJWTPayloadSID() string {

View file

@ -26,6 +26,7 @@ import (
"github.com/pomerium/datasource/pkg/directory"
"github.com/pomerium/pomerium/authorize/internal/store"
"github.com/pomerium/pomerium/config"
"github.com/pomerium/pomerium/internal/log"
"github.com/pomerium/pomerium/pkg/cryptutil"
"github.com/pomerium/pomerium/pkg/grpc/databroker"
"github.com/pomerium/pomerium/pkg/grpc/session"
@ -503,22 +504,23 @@ func TestHeadersEvaluator_JWTGroupsFilter(t *testing.T) {
routeFilter []string
sessionID string
expected []any
removed int
}{
{"global filter 1", []string{"42", "1"}, nil, "SESSION-1", []any{"1", "42", "GROUP-1", "GROUP-42"}},
{"global filter 2", []string{"42", "1"}, nil, "SESSION-2", []any{"42", "GROUP-42"}},
{"route filter 1", nil, []string{"42", "1"}, "SESSION-1", []any{"1", "42", "GROUP-1", "GROUP-42"}},
{"route filter 2", nil, []string{"42", "1"}, "SESSION-2", []any{"42", "GROUP-42"}},
{"both filters 1", []string{"1"}, []string{"42"}, "SESSION-1", []any{"1", "42", "GROUP-1", "GROUP-42"}},
{"both filters 2", []string{"1"}, []string{"42"}, "SESSION-2", []any{"42", "GROUP-42"}},
{"cannot filter by name", []string{"GROUP-1"}, nil, "SESSION-1", []any{}},
{"overlapping", []string{"1"}, []string{"1"}, "SESSION-1", []any{"1", "GROUP-1"}},
{"empty route filter", []string{"1", "2", "3"}, []string{}, "SESSION-1", []any{"1", "2", "3", "GROUP-1", "GROUP-2", "GROUP-3"}},
{"global filter 1", []string{"42", "1"}, nil, "SESSION-1", []any{"1", "42", "GROUP-1", "GROUP-42"}, 48},
{"global filter 2", []string{"42", "1"}, nil, "SESSION-2", []any{"42", "GROUP-42"}, 24},
{"route filter 1", nil, []string{"42", "1"}, "SESSION-1", []any{"1", "42", "GROUP-1", "GROUP-42"}, 48},
{"route filter 2", nil, []string{"42", "1"}, "SESSION-2", []any{"42", "GROUP-42"}, 24},
{"both filters 1", []string{"1"}, []string{"42"}, "SESSION-1", []any{"1", "42", "GROUP-1", "GROUP-42"}, 48},
{"both filters 2", []string{"1"}, []string{"42"}, "SESSION-2", []any{"42", "GROUP-42"}, 24},
{"cannot filter by name", []string{"GROUP-1"}, nil, "SESSION-1", []any{}, 50},
{"overlapping", []string{"1"}, []string{"1"}, "SESSION-1", []any{"1", "GROUP-1"}, 49},
{"empty route filter", []string{"1", "2", "3"}, []string{}, "SESSION-1", []any{"1", "2", "3", "GROUP-1", "GROUP-2", "GROUP-3"}, 47},
{
"no filtering", nil, nil, "SESSION-10",
[]any{"10", "20", "30", "40", "50", "GROUP-10", "GROUP-20", "GROUP-30", "GROUP-40", "GROUP-50"},
[]any{"10", "20", "30", "40", "50", "GROUP-10", "GROUP-20", "GROUP-30", "GROUP-40", "GROUP-50"}, 0,
},
// filtering has no effect on groups from an IdP "groups" claim
{"groups claim", []string{"foo", "quux"}, nil, "SESSION-11", []any{"foo", "bar", "baz"}},
{"groups claim", []string{"foo", "quux"}, nil, "SESSION-11", []any{"foo", "bar", "baz"}, 0},
}
ctx := storage.WithQuerier(context.Background(), storage.NewStaticQuerier(records...))
@ -538,6 +540,11 @@ func TestHeadersEvaluator_JWTGroupsFilter(t *testing.T) {
require.NoError(t, err)
decoded := decodeJWTAssertion(t, resp.Headers)
assert.Equal(t, c.expected, decoded["groups"])
if c.removed > 0 {
assert.Equal(t, c.removed, resp.AdditionalLogFields[log.AuthorizeLogFieldRemovedGroupsCount])
} else {
assert.Nil(t, resp.AdditionalLogFields[log.AuthorizeLogFieldRemovedGroupsCount])
}
})
}
}

View file

@ -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)
@ -139,6 +139,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(), "?")
@ -205,6 +206,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
}
}

View file

@ -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()))

View file

@ -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: {},