use strings.Cut, add unit tests

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

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()))
+		})
+	}
+}

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

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()))
+		})
+	}
+}