Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
152 changes: 152 additions & 0 deletions router-tests/structured_logging_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import (
"fmt"
"math"
"net/http"
"net/url"
"os"
"path/filepath"
"testing"
Expand Down Expand Up @@ -3075,6 +3076,157 @@ func TestFlakyAccessLogs(t *testing.T) {

})

t.Run("verify ignore list", func(t *testing.T) {
t.Parallel()

t.Run("without any ignored values", func(t *testing.T) {
t.Parallel()

testenv.Run(t, &testenv.Config{
LogObservation: testenv.LogObservationConfig{
Enabled: true,
LogLevel: zapcore.InfoLevel,
},
}, func(t *testing.T, xEnv *testenv.Environment) {
variables := `{"criteria": {"nationality": "GERMAN" }}`
persistedQueries := `{"persistedQuery": {"version": 1, "sha256Hash": "e33580cf6276de9a75fb3b1c4b7580fec2a1c8facd13f3487bf6c7c3f854f7e3"}}`
operationName := `Find`

header := make(http.Header)
header.Add("graphql-client-name", "my-client")
res, err := xEnv.MakeGraphQLRequestOverGET(testenv.GraphQLRequest{
OperationName: []byte(operationName),
Variables: []byte(variables),
Extensions: []byte(persistedQueries),
Header: header,
})
require.NoError(t, err)
require.Equal(t, `{"data":{"findEmployees":[{"id":1,"details":{"forename":"Jens","surname":"Neuse"}},{"id":2,"details":{"forename":"Dustin","surname":"Deus"}},{"id":4,"details":{"forename":"Björn","surname":"Schwenzer"}},{"id":11,"details":{"forename":"Alexandra","surname":"Neuse"}}]}}`, res.Body)

requestLog := xEnv.Observer().FilterMessage("/graphql")
require.Equal(t, 1, requestLog.Len())
requestContext := requestLog.All()[0].ContextMap()

query := requestContext["query"].(string)

rawQueryString := fmt.Sprintf("extensions=%s&operationName=%s&variables=%s",
url.QueryEscape(persistedQueries),
url.QueryEscape(operationName),
url.QueryEscape(variables))
require.Equal(t, rawQueryString, query)

parseQuery, err := url.ParseQuery(query)
require.NoError(t, err)

require.Equal(t, variables, parseQuery.Get("variables"))
require.Equal(t, operationName, parseQuery.Get("operationName"))
require.Equal(t, persistedQueries, parseQuery.Get("extensions"))
})
})

t.Run("with ignored values", func(t *testing.T) {
t.Parallel()

ignoreList := []string{
"operationName",
"variables",
}

testenv.Run(t, &testenv.Config{
IgnoreQueryParamsList: ignoreList,
LogObservation: testenv.LogObservationConfig{
Enabled: true,
LogLevel: zapcore.InfoLevel,
},
}, func(t *testing.T, xEnv *testenv.Environment) {
variables := `{"criteria": {"nationality": "GERMAN" }}`
persistedQueries := `{"persistedQuery": {"version": 1, "sha256Hash": "e33580cf6276de9a75fb3b1c4b7580fec2a1c8facd13f3487bf6c7c3f854f7e3"}}`
operationName := `Find`

header := make(http.Header)
header.Add("graphql-client-name", "my-client")
res, err := xEnv.MakeGraphQLRequestOverGET(testenv.GraphQLRequest{
OperationName: []byte(operationName),
Variables: []byte(variables),
Extensions: []byte(persistedQueries),
Header: header,
})
require.NoError(t, err)
require.Equal(t, `{"data":{"findEmployees":[{"id":1,"details":{"forename":"Jens","surname":"Neuse"}},{"id":2,"details":{"forename":"Dustin","surname":"Deus"}},{"id":4,"details":{"forename":"Björn","surname":"Schwenzer"}},{"id":11,"details":{"forename":"Alexandra","surname":"Neuse"}}]}}`, res.Body)

requestLog := xEnv.Observer().FilterMessage("/graphql")
require.Equal(t, 1, requestLog.Len())
requestContext := requestLog.All()[0].ContextMap()

query := requestContext["query"].(string)

rawQueryString := "extensions=" + url.QueryEscape(persistedQueries)

require.Equal(t, rawQueryString, query)

parseQuery, err := url.ParseQuery(query)
require.NoError(t, err)

require.Empty(t, parseQuery.Get("variables"))
require.Empty(t, parseQuery.Get("operationName"))
require.Equal(t, persistedQueries, parseQuery.Get("extensions"))
})
})

t.Run("with POST while including query params", func(t *testing.T) {
t.Parallel()

customQueryParamHeaderName := "somekey"
customQueryParamHeaderValue := "somevalue"

ignoreList := []string{
customQueryParamHeaderName,
}

testenv.Run(t, &testenv.Config{
IgnoreQueryParamsList: ignoreList,
LogObservation: testenv.LogObservationConfig{
Enabled: true,
LogLevel: zapcore.InfoLevel,
},
}, func(t *testing.T, xEnv *testenv.Environment) {
request := testenv.GraphQLRequest{
Query: `{ employees { id } }`,
}
data, err := json.Marshal(request)
require.NoError(t, err)
req, err := http.NewRequestWithContext(xEnv.Context, http.MethodPost, xEnv.GraphQLRequestURL(), bytes.NewReader(data))
require.NoError(t, err)
req.Header.Set("Accept-Encoding", "identity")

additionalKey := "anothervariable"
additionalValue := "anothervalue"

q := req.URL.Query()
q.Add(customQueryParamHeaderName, customQueryParamHeaderValue)
q.Add(additionalKey, additionalValue)
req.URL.RawQuery = q.Encode()

res, err := xEnv.MakeGraphQLRequestRaw(req)
require.NoError(t, err)
require.Equal(t, `{"data":{"employees":[{"id":1},{"id":2},{"id":3},{"id":4},{"id":5},{"id":7},{"id":8},{"id":10},{"id":11},{"id":12}]}}`, res.Body)

requestLog := xEnv.Observer().FilterMessage("/graphql")
require.Equal(t, 1, requestLog.Len())
requestContext := requestLog.All()[0].ContextMap()

query := requestContext["query"].(string)

rawQueryString := fmt.Sprintf("%s=%s", additionalKey, url.QueryEscape(additionalValue))
require.Equal(t, rawQueryString, query)

parseQuery, err := url.ParseQuery(query)
require.NoError(t, err)

require.Empty(t, parseQuery.Get(customQueryParamHeaderName))
})
})
})
}

func checkValues(t *testing.T, requestContext map[string]interface{}, expectedValues map[string]interface{}, additionalExpectedKeys []string) {
Expand Down
10 changes: 6 additions & 4 deletions router-tests/testenv/testenv.go
Original file line number Diff line number Diff line change
Expand Up @@ -333,6 +333,7 @@ type Config struct {
EnableRedisCluster bool
Plugins PluginConfig
EnableGRPC bool
IgnoreQueryParamsList []string
}

type PluginConfig struct {
Expand Down Expand Up @@ -1389,10 +1390,11 @@ func configureRouter(listenerAddr string, testConfig *Config, routerConfig *node
core.WithDisableUsageTracking(),
core.WithLogger(testConfig.Logger),
core.WithAccessLogs(&core.AccessLogsConfig{
Logger: testConfig.AccessLogger,
Attributes: testConfig.AccessLogFields,
SubgraphEnabled: testConfig.SubgraphAccessLogsEnabled,
SubgraphAttributes: testConfig.SubgraphAccessLogFields,
Logger: testConfig.AccessLogger,
Attributes: testConfig.AccessLogFields,
IgnoreQueryParamsList: testConfig.IgnoreQueryParamsList,
SubgraphEnabled: testConfig.SubgraphAccessLogsEnabled,
SubgraphAttributes: testConfig.SubgraphAccessLogFields,
}),
core.WithGraphApiToken(graphApiToken),
core.WithDevelopmentMode(true),
Expand Down
1 change: 1 addition & 0 deletions router/core/graph_server.go
Original file line number Diff line number Diff line change
Expand Up @@ -1056,6 +1056,7 @@ func (s *graphServer) buildGraphMux(
requestlogger.WithAttributes(accessLogAttributes),
requestlogger.WithExprAttributes(exprAttributes),
requestlogger.WithFieldsHandler(RouterAccessLogsFieldHandler),
requestlogger.WithIgnoreQueryParamsList(s.accessLogsConfig.IgnoreQueryParamsList),
}

var ipAnonConfig *requestlogger.IPAnonymizationConfig
Expand Down
9 changes: 5 additions & 4 deletions router/core/router.go
Original file line number Diff line number Diff line change
Expand Up @@ -161,10 +161,11 @@ type (
}

AccessLogsConfig struct {
Attributes []config.CustomAttribute
Logger *zap.Logger
SubgraphEnabled bool
SubgraphAttributes []config.CustomAttribute
Attributes []config.CustomAttribute
Logger *zap.Logger
SubgraphEnabled bool
SubgraphAttributes []config.CustomAttribute
IgnoreQueryParamsList []string
}

// Option defines the method to customize server.
Expand Down
7 changes: 4 additions & 3 deletions router/core/supervisor_instance.go
Original file line number Diff line number Diff line change
Expand Up @@ -67,9 +67,10 @@ func newRouter(ctx context.Context, params RouterResources, additionalOptions ..

if cfg.AccessLogs.Enabled {
c := &AccessLogsConfig{
Attributes: cfg.AccessLogs.Router.Fields,
SubgraphEnabled: cfg.AccessLogs.Subgraphs.Enabled,
SubgraphAttributes: cfg.AccessLogs.Subgraphs.Fields,
Attributes: cfg.AccessLogs.Router.Fields,
IgnoreQueryParamsList: cfg.AccessLogs.Router.IgnoreQueryParamsList,
SubgraphEnabled: cfg.AccessLogs.Subgraphs.Enabled,
SubgraphAttributes: cfg.AccessLogs.Subgraphs.Fields,
}

if cfg.AccessLogs.Output.File.Enabled {
Expand Down
34 changes: 29 additions & 5 deletions router/internal/requestlogger/requestlogger.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import (
"encoding/hex"
"net"
"net/http"
"net/url"
"time"

"github.com/wundergraph/cosmo/router/internal/errors"
Expand Down Expand Up @@ -109,6 +110,12 @@ func WithDefaultOptions() Option {
}
}

func WithIgnoreQueryParamsList(ignoreList []string) Option {
return func(r *handler) {
r.accessLogger.ignoreQueryParamsList = ignoreList
}
}

func New(logger *zap.Logger, opts ...Option) func(h http.Handler) http.Handler {
return func(h http.Handler) http.Handler {
r := &handler{
Expand All @@ -124,7 +131,7 @@ func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {

start := time.Now()
path := r.URL.Path
fields := h.accessLogger.getRequestFields(r)
fields := h.accessLogger.getRequestFields(r, h.logger)

defer func() {

Expand Down Expand Up @@ -184,15 +191,15 @@ func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
h.logger.Info(path, append(fields, resFields...)...)
}

func (al *accessLogger) getRequestFields(r *http.Request) []zapcore.Field {
func (al *accessLogger) getRequestFields(r *http.Request, logger *zap.Logger) []zapcore.Field {
if r == nil {
return al.baseFields
}

start := time.Now()
url := r.URL
path := url.Path
query := url.RawQuery
reqUrl := r.URL
path := reqUrl.Path
query := reqUrl.RawQuery
remoteAddr := r.RemoteAddr

if al.ipAnonymizationConfig != nil && al.ipAnonymizationConfig.Enabled {
Expand All @@ -206,6 +213,23 @@ func (al *accessLogger) getRequestFields(r *http.Request) []zapcore.Field {
}
}

if query != "" && len(al.ignoreQueryParamsList) > 0 {
Comment thread
StarpTech marked this conversation as resolved.
vals, err := url.ParseQuery(reqUrl.RawQuery)
if err != nil {
// We ignore logging the err since it could leak partial sensitive data
// such as %pa from "%password"
logger.Error("Failed to parse query parameters")
// Since we wanted to ignore some values but we cant parse it
// we default to a safer skip all
query = ""
} else {
for _, ignoreQueryParam := range al.ignoreQueryParamsList {
vals.Del(ignoreQueryParam)
}
query = vals.Encode()
}
}

// All fields are snake_case

fields := []zapcore.Field{
Expand Down
3 changes: 2 additions & 1 deletion router/internal/requestlogger/subgraphlogger.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ type accessLogger struct {
baseFields []zapcore.Field
attributes []config.CustomAttribute
exprAttributes []ExpressionAttribute
ignoreQueryParamsList []string
}

type SubgraphAccessLogger struct {
Expand Down Expand Up @@ -52,7 +53,7 @@ func (h *SubgraphAccessLogger) RequestFields(respInfo *resolve.ResponseInfo, ove
return []zap.Field{}
}

fields := h.accessLogger.getRequestFields(respInfo.Request)
fields := h.accessLogger.getRequestFields(respInfo.Request, h.logger)
if respInfo.Request != nil && respInfo.Request.URL != nil {
fields = append(fields, zap.String("url", respInfo.Request.URL.String()))
}
Expand Down
3 changes: 2 additions & 1 deletion router/pkg/config/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -891,7 +891,8 @@ type AccessLogsFileOutputConfig struct {
}

type AccessLogsRouterConfig struct {
Fields []CustomAttribute `yaml:"fields,omitempty" env:"ACCESS_LOGS_ROUTER_FIELDS"`
Fields []CustomAttribute `yaml:"fields,omitempty" env:"ACCESS_LOGS_ROUTER_FIELDS"`
IgnoreQueryParamsList []string `yaml:"ignore_query_params_list,omitempty" env:"ACCESS_LOGS_ROUTER_IGNORE_QUERY_PARAMS_LIST" envDefault:"variables"`
}

type AccessLogsSubgraphsConfig struct {
Expand Down
8 changes: 8 additions & 0 deletions router/pkg/config/config.schema.json
Original file line number Diff line number Diff line change
Expand Up @@ -694,6 +694,14 @@
"properties": {
"fields": {
"$ref": "#/$defs/context_fields"
},
"ignore_query_params_list": {
Comment thread
StarpTech marked this conversation as resolved.
"type": "array",
"description": "List of query params to be ignored from being logged in the query field.",
"default": ["variables"],
"items": {
"type": "string"
}
}
}
},
Expand Down
3 changes: 3 additions & 0 deletions router/pkg/config/fixtures/full.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,9 @@ access_logs:
- key: 'request_information'
value_from:
expression: "request.error ?? 'success'"
ignore_query_params_list:
- variables
- anothervalue
subgraphs:
enabled: true
fields:
Expand Down
5 changes: 4 additions & 1 deletion router/pkg/config/testdata/config_defaults.json
Original file line number Diff line number Diff line change
Expand Up @@ -197,7 +197,10 @@
}
},
"Router": {
"Fields": null
"Fields": null,
"IgnoreQueryParamsList": [
"variables"
]
},
"Subgraphs": {
"Enabled": false,
Expand Down
4 changes: 4 additions & 0 deletions router/pkg/config/testdata/config_full.json
Original file line number Diff line number Diff line change
Expand Up @@ -415,6 +415,10 @@
"Expression": "request.error ?? 'success'"
}
}
],
"IgnoreQueryParamsList": [
"variables",
"anothervalue"
]
Comment thread
SkArchon marked this conversation as resolved.
},
"Subgraphs": {
Expand Down
Loading