From 21b79405cdbdf34f7c4bfc7ded6a04dda12a318c Mon Sep 17 00:00:00 2001 From: Caleb Doxsey Date: Tue, 25 Jul 2023 12:18:22 -0600 Subject: [PATCH] use strings.Cut, add unit tests --- authorize/log.go | 20 +--- authorize/log_test.go | 97 ++++++++++++++++++++ internal/controlplane/grpc_accesslog.go | 27 ++---- internal/controlplane/grpc_accesslog_test.go | 74 +++++++++++++++ 4 files changed, 183 insertions(+), 35 deletions(-) create mode 100644 authorize/log_test.go create mode 100644 internal/controlplane/grpc_accesslog_test.go diff --git a/authorize/log.go b/authorize/log.go index 663c71141..691b378fc 100644 --- a/authorize/log.go +++ b/authorize/log.go @@ -152,6 +152,8 @@ func populateLogEvent( hdrs map[string]string, impersonateDetails *impersonateDetails, ) *zerolog.Event { + path, query, _ := strings.Cut(in.GetAttributes().GetRequest().GetHttp().GetPath(), "?") + switch field { case log.AuthorizeLogFieldCheckRequestID: return evt.Str(string(field), hdrs["X-Request-Id"]) @@ -179,9 +181,9 @@ func populateLogEvent( case log.AuthorizeLogFieldMethod: return evt.Str(string(field), in.GetAttributes().GetRequest().GetHttp().GetMethod()) case log.AuthorizeLogFieldPath: - return evt.Str(string(field), stripQueryString(in.GetAttributes().GetRequest().GetHttp().GetPath())) + return evt.Str(string(field), path) case log.AuthorizeLogFieldQuery: - return evt.Str(string(field), getQueryString(in.GetAttributes().GetRequest().GetHttp().GetPath())) + return evt.Str(string(field), query) case log.AuthorizeLogFieldRequestID: return evt.Str(string(field), requestid.FromContext(ctx)) case log.AuthorizeLogFieldServiceAccountID: @@ -200,17 +202,3 @@ func populateLogEvent( return evt } } - -func getQueryString(str string) string { - if idx := strings.Index(str, "?"); idx != -1 { - return str[idx+1:] - } - return "" -} - -func stripQueryString(str string) string { - if idx := strings.Index(str, "?"); idx != -1 { - str = str[:idx] - } - return str -} diff --git a/authorize/log_test.go b/authorize/log_test.go new file mode 100644 index 000000000..f6a8907e9 --- /dev/null +++ b/authorize/log_test.go @@ -0,0 +1,97 @@ +package authorize + +import ( + "bytes" + "context" + "strings" + "testing" + + envoy_config_core_v3 "github.com/envoyproxy/go-control-plane/envoy/config/core/v3" + envoy_service_auth_v3 "github.com/envoyproxy/go-control-plane/envoy/service/auth/v3" + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + + "github.com/pomerium/pomerium/internal/log" + "github.com/pomerium/pomerium/internal/telemetry/requestid" + "github.com/pomerium/pomerium/pkg/grpc/session" + "github.com/pomerium/pomerium/pkg/grpc/user" +) + +func Test_populateLogEvent(t *testing.T) { + t.Parallel() + + ctx := context.Background() + ctx = requestid.WithValue(ctx, "REQUEST-ID") + + checkRequest := &envoy_service_auth_v3.CheckRequest{ + Attributes: &envoy_service_auth_v3.AttributeContext{ + Request: &envoy_service_auth_v3.AttributeContext_Request{ + Http: &envoy_service_auth_v3.AttributeContext_HttpRequest{ + Host: "HOST", + Path: "https://www.example.com/some/path?a=b", + Method: "GET", + }, + }, + Source: &envoy_service_auth_v3.AttributeContext_Peer{ + Address: &envoy_config_core_v3.Address{ + Address: &envoy_config_core_v3.Address_SocketAddress{ + SocketAddress: &envoy_config_core_v3.SocketAddress{ + Address: "127.0.0.1", + }, + }, + }, + }, + }, + } + headers := map[string]string{"X-Request-Id": "CHECK-REQUEST-ID"} + s := &session.Session{ + Id: "SESSION-ID", + } + sa := &user.ServiceAccount{ + Id: "SERVICE-ACCOUNT-ID", + } + u := &user.User{ + Id: "USER-ID", + Email: "EMAIL", + } + impersonateDetails := &impersonateDetails{ + email: "IMPERSONATE-EMAIL", + sessionID: "IMPERSONATE-SESSION-ID", + userID: "IMPERSONATE-USER-ID", + } + + for _, tc := range []struct { + field log.AuthorizeLogField + s sessionOrServiceAccount + expect string + }{ + {log.AuthorizeLogFieldCheckRequestID, s, `{"check-request-id":"CHECK-REQUEST-ID"}`}, + {log.AuthorizeLogFieldEmail, s, `{"email":"EMAIL"}`}, + {log.AuthorizeLogFieldHost, s, `{"host":"HOST"}`}, + {log.AuthorizeLogFieldImpersonateEmail, s, `{"impersonate-email":"IMPERSONATE-EMAIL"}`}, + {log.AuthorizeLogFieldImpersonateSessionID, s, `{"impersonate-session-id":"IMPERSONATE-SESSION-ID"}`}, + {log.AuthorizeLogFieldImpersonateUserID, s, `{"impersonate-user-id":"IMPERSONATE-USER-ID"}`}, + {log.AuthorizeLogFieldIP, s, `{"ip":"127.0.0.1"}`}, + {log.AuthorizeLogFieldMethod, s, `{"method":"GET"}`}, + {log.AuthorizeLogFieldPath, s, `{"path":"https://www.example.com/some/path"}`}, + {log.AuthorizeLogFieldQuery, s, `{"query":"a=b"}`}, + {log.AuthorizeLogFieldRequestID, s, `{"request-id":"REQUEST-ID"}`}, + {log.AuthorizeLogFieldServiceAccountID, sa, `{"service-account-id":"SERVICE-ACCOUNT-ID"}`}, + {log.AuthorizeLogFieldSessionID, s, `{"session-id":"SESSION-ID"}`}, + {log.AuthorizeLogFieldUser, s, `{"user":"USER-ID"}`}, + } { + + tc := tc + t.Run(string(tc.field), func(t *testing.T) { + t.Parallel() + + var buf bytes.Buffer + log := zerolog.New(&buf) + evt := log.Log() + evt = populateLogEvent(ctx, tc.field, evt, checkRequest, tc.s, u, headers, impersonateDetails) + evt.Send() + + assert.Equal(t, tc.expect, strings.TrimSpace(buf.String())) + }) + } +} diff --git a/internal/controlplane/grpc_accesslog.go b/internal/controlplane/grpc_accesslog.go index 30cbb4975..1481a381a 100644 --- a/internal/controlplane/grpc_accesslog.go +++ b/internal/controlplane/grpc_accesslog.go @@ -51,22 +51,25 @@ func populateLogEvent( evt *zerolog.Event, entry *envoy_data_accesslog_v3.HTTPAccessLogEntry, ) *zerolog.Event { + referer, _, _ := strings.Cut(entry.GetRequest().GetReferer(), "?") + path, query, _ := strings.Cut(entry.GetRequest().GetPath(), "?") + switch field { case log.AccessLogFieldAuthority: return evt.Str(string(field), entry.GetRequest().GetAuthority()) case log.AccessLogFieldDuration: - dur := entry.CommonProperties.TimeToLastDownstreamTxByte.AsDuration() + dur := entry.GetCommonProperties().GetTimeToLastDownstreamTxByte().AsDuration() return evt.Dur(string(field), dur) case log.AccessLogFieldForwardedFor: return evt.Str(string(field), entry.GetRequest().GetForwardedFor()) case log.AccessLogFieldMethod: return evt.Str(string(field), entry.GetRequest().GetRequestMethod().String()) case log.AccessLogFieldPath: - return evt.Str(string(field), stripQueryString(entry.GetRequest().GetPath())) + return evt.Str(string(field), path) case log.AccessLogFieldQuery: - return evt.Str(string(field), getQueryString(entry.GetRequest().GetPath())) + return evt.Str(string(field), query) case log.AccessLogFieldReferer: - return evt.Str(string(field), stripQueryString(entry.GetRequest().GetReferer())) + return evt.Str(string(field), referer) case log.AccessLogFieldRequestID: return evt.Str(string(field), entry.GetRequest().GetRequestId()) case log.AccessLogFieldResponseCode: @@ -74,7 +77,7 @@ func populateLogEvent( case log.AccessLogFieldResponseCodeDetails: return evt.Str(string(field), entry.GetResponse().GetResponseCodeDetails()) case log.AccessLogFieldSize: - return evt.Uint64(string(field), entry.Response.ResponseBodyBytes) + return evt.Uint64(string(field), entry.GetResponse().GetResponseBodyBytes()) case log.AccessLogFieldUpstreamCluster: return evt.Str(string(field), entry.GetCommonProperties().GetUpstreamCluster()) case log.AccessLogFieldUserAgent: @@ -83,17 +86,3 @@ func populateLogEvent( return evt } } - -func getQueryString(str string) string { - if idx := strings.Index(str, "?"); idx != -1 { - return str[idx+1:] - } - return "" -} - -func stripQueryString(str string) string { - if idx := strings.Index(str, "?"); idx != -1 { - str = str[:idx] - } - return str -} diff --git a/internal/controlplane/grpc_accesslog_test.go b/internal/controlplane/grpc_accesslog_test.go new file mode 100644 index 000000000..aeab3e647 --- /dev/null +++ b/internal/controlplane/grpc_accesslog_test.go @@ -0,0 +1,74 @@ +package controlplane + +import ( + "bytes" + "strings" + "testing" + "time" + + envoy_config_core_v3 "github.com/envoyproxy/go-control-plane/envoy/config/core/v3" + envoy_data_accesslog_v3 "github.com/envoyproxy/go-control-plane/envoy/data/accesslog/v3" + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "google.golang.org/protobuf/types/known/durationpb" + "google.golang.org/protobuf/types/known/wrapperspb" + + "github.com/pomerium/pomerium/internal/log" +) + +func Test_populateLogEvent(t *testing.T) { + t.Parallel() + + entry := &envoy_data_accesslog_v3.HTTPAccessLogEntry{ + CommonProperties: &envoy_data_accesslog_v3.AccessLogCommon{ + TimeToLastDownstreamTxByte: durationpb.New(time.Second * 3), + UpstreamCluster: "UPSTREAM-CLUSTER", + }, + Request: &envoy_data_accesslog_v3.HTTPRequestProperties{ + Authority: "AUTHORITY", + ForwardedFor: "FORWARDED-FOR", + Path: "https://www.example.com/some/path?a=b", + Referer: "https://www.example.com/referer?a=b", + RequestId: "REQUEST-ID", + RequestMethod: envoy_config_core_v3.RequestMethod_GET, + UserAgent: "USER-AGENT", + }, + Response: &envoy_data_accesslog_v3.HTTPResponseProperties{ + ResponseBodyBytes: 1234, + ResponseCode: wrapperspb.UInt32(200), + ResponseCodeDetails: "RESPONSE-CODE-DETAILS", + }, + } + + for _, tc := range []struct { + field log.AccessLogField + expect string + }{ + {log.AccessLogFieldAuthority, `{"authority":"AUTHORITY"}`}, + {log.AccessLogFieldDuration, `{"duration":3000}`}, + {log.AccessLogFieldForwardedFor, `{"forwarded-for":"FORWARDED-FOR"}`}, + {log.AccessLogFieldMethod, `{"method":"GET"}`}, + {log.AccessLogFieldPath, `{"path":"https://www.example.com/some/path"}`}, + {log.AccessLogFieldQuery, `{"query":"a=b"}`}, + {log.AccessLogFieldReferer, `{"referer":"https://www.example.com/referer"}`}, + {log.AccessLogFieldRequestID, `{"request-id":"REQUEST-ID"}`}, + {log.AccessLogFieldResponseCode, `{"response-code":200}`}, + {log.AccessLogFieldResponseCodeDetails, `{"response-code-details":"RESPONSE-CODE-DETAILS"}`}, + {log.AccessLogFieldSize, `{"size":1234}`}, + {log.AccessLogFieldUpstreamCluster, `{"upstream-cluster":"UPSTREAM-CLUSTER"}`}, + {log.AccessLogFieldUserAgent, `{"user-agent":"USER-AGENT"}`}, + } { + tc := tc + t.Run(string(tc.field), func(t *testing.T) { + t.Parallel() + + var buf bytes.Buffer + log := zerolog.New(&buf) + evt := log.Log() + evt = populateLogEvent(tc.field, evt, entry) + evt.Send() + + assert.Equal(t, tc.expect, strings.TrimSpace(buf.String())) + }) + } +}