Skip to content

Commit

Permalink
logs: add support for logging the http query (#4390)
Browse files Browse the repository at this point in the history 
* config: add customization options for logging

* config: validate log fields

* proxy: add support for logging http request headers

* log subset of headers

* add support for logging the http query

* fix test name

* use strings.Cut, add unit tests
  • Loading branch information
@calebdoxsey
calebdoxsey committed Jul 25, 2023
1 parent 8401170 commit baf8918
Show file tree
Hide file tree
Showing 6 changed files with 186 additions and 21 deletions.
13 changes: 4 additions & 9 deletions authorize/log.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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"])
Expand Down Expand Up @@ -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), in.GetAttributes().GetRequest().GetHttp().GetQuery())
return evt.Str(string(field), query)
case log.AuthorizeLogFieldRequestID:
return evt.Str(string(field), requestid.FromContext(ctx))
case log.AuthorizeLogFieldServiceAccountID:
Expand All @@ -200,10 +202,3 @@ func populateLogEvent(
return evt
}
}

func stripQueryString(str string) string {
if idx := strings.Index(str, "?"); idx != -1 {
str = str[:idx]
}
return str
}
97 changes: 97 additions & 0 deletions authorize/log_test.go
View file
Original file line number Diff line number Diff line change
@@ -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()))
})
}
}
20 changes: 9 additions & 11 deletions internal/controlplane/grpc_accesslog.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -51,28 +51,33 @@ 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), 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:
return evt.Uint32(string(field), entry.GetResponse().GetResponseCode().GetValue())
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:
Expand All @@ -81,10 +86,3 @@ func populateLogEvent(
return evt
}
}

func stripQueryString(str string) string {
if idx := strings.Index(str, "?"); idx != -1 {
str = str[:idx]
}
return str
}
74 changes: 74 additions & 0 deletions internal/controlplane/grpc_accesslog_test.go
View file
Original file line number Diff line number Diff line change
@@ -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()))
})
}
}
2 changes: 2 additions & 0 deletions internal/log/access.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ const (
AccessLogFieldForwardedFor AccessLogField = "forwarded-for"
AccessLogFieldMethod AccessLogField = "method"
AccessLogFieldPath AccessLogField = "path"
AccessLogFieldQuery AccessLogField = "query"
AccessLogFieldReferer AccessLogField = "referer"
AccessLogFieldRequestID AccessLogField = "request-id"
AccessLogFieldResponseCode AccessLogField = "response-code"
Expand Down Expand Up @@ -53,6 +54,7 @@ var accessLogFieldLookup = map[AccessLogField]struct{}{
AccessLogFieldForwardedFor: {},
AccessLogFieldMethod: {},
AccessLogFieldPath: {},
AccessLogFieldQuery: {},
AccessLogFieldReferer: {},
AccessLogFieldRequestID: {},
AccessLogFieldResponseCode: {},
Expand Down
1 change: 0 additions & 1 deletion internal/log/authorize.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,6 @@ var defaultAuthorizeLogFields = []AuthorizeLogField{
AuthorizeLogFieldMethod,
AuthorizeLogFieldPath,
AuthorizeLogFieldHost,
AuthorizeLogFieldQuery,
AuthorizeLogFieldIP,
AuthorizeLogFieldSessionID,
AuthorizeLogFieldImpersonateSessionID,
Expand Down

0 comments on commit baf8918

Please sign in to comment.