Skip to content
Open
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
35 changes: 35 additions & 0 deletions docs-website/router/access-logs.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -296,6 +296,41 @@ The response type of the expression is validated upon startup. You should ensure
Note that while `subgraph` attributes can be accessed in the request logger, it will always have "zero" values.
</Warning>

#### Logging operation complexity

Router access-log expressions can record the operation complexity values that are also attached to validation traces. Configure `security.complexity_limits` first. Use `measure` mode to calculate the values without rejecting operations.

```yaml
security:
complexity_calculation_cache:
enabled: true
size: 1024
complexity_limits:
mode: measure

access_logs:
enabled: true
router:
fields:
- key: "query_depth"
value_from:
expression: "request.operation.queryDepth"
- key: "query_total_fields"
value_from:
expression: "request.operation.queryTotalFields"
- key: "query_root_fields"
value_from:
expression: "request.operation.queryRootFields"
- key: "query_root_field_aliases"
value_from:
expression: "request.operation.queryRootFieldAliases"
- key: "query_complexity_cache_hit"
value_from:
expression: "request.operation.queryComplexityCacheHit"
```

The numeric values are logged as integers and the cache status as a boolean. See [Template Expressions](/router/configuration/template-expressions#operation-object) for field definitions and lifecycle limitations.

#### Subgraph Access Log Expressions

<Info>
Expand Down
2 changes: 2 additions & 0 deletions docs-website/router/configuration.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -2508,6 +2508,8 @@ security:
operation_name_length_limit: 1024
```

Both complexity modes calculate and expose operation complexity. `measure` reports the values without rejecting requests. `enforce` reports the same values and rejects requests that exceed enabled limits. The calculated values and cache status can be seen on the traces or added to router access logs with [operation complexity expressions](/router/access-logs#logging-operation-complexity).

<Warning>
Query Depth is now deprecated. We recommend using the
`security.complexity_calculation_cache` and `security.complexity_limits`
Expand Down
8 changes: 8 additions & 0 deletions docs-website/router/configuration/template-expressions.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -78,8 +78,14 @@ The `request` object is a read-only entity that provides details about the incom
- `request.operation.variablesRemappingCacheHit` (bool)
- `request.operation.persistedOperationCacheHit` (bool)
- `request.operation.planCacheHit` (bool)
- `request.operation.queryDepth` (int) - Maximum nesting depth calculated for the operation.
- `request.operation.queryTotalFields` (int) - Calculated total-fields complexity value evaluated against `security.complexity_limits.total_fields`.
- `request.operation.queryRootFields` (int) - Number of root fields without aliases.
- `request.operation.queryRootFieldAliases` (int) - Number of root fields that use aliases.
- `request.operation.queryComplexityCacheHit` (bool) - Whether all four query complexity values were reused from the complexity calculation cache.
- `request.operation.variables` - The operation variables sent with the request, as a JSON string. The value can contain sensitive data and can be large, so log it with care. It is only serialized when an expression references it, so configurations that do not use it pay no cost.

The query complexity fields are calculated during validation when `security.complexity_limits` is configured. They remain zero-valued when complexity limits are not configured or a request exits before validation. Use `mode: measure` to collect them without rejecting operations. Aliased root fields are counted in `queryRootFieldAliases`, not `queryRootFields`.

The serialization of `request.operation.variables` is decided once per request across the whole configuration. If any access log, metric, telemetry, tracing, or rate-limiter expression references it, it is serialized; otherwise it is skipped.

Expand All @@ -94,6 +100,8 @@ hasPrefix(request.operation.name, 'Delete') == true
request.operation.sha256Hash != ''
request.operation.persistedId != ''
request.operation.planCacheHit == true
request.operation.queryDepth > 5
request.operation.queryComplexityCacheHit == true
# Log the variables only when the variable remapping cache missed.
request.operation.variablesRemappingCacheHit ? '' : request.operation.variables
```
Expand Down
98 changes: 98 additions & 0 deletions router-tests/observability/structured_logging_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4358,6 +4358,104 @@ func TestAccessLogs(t *testing.T) {
t.Run("expression field logging", func(t *testing.T) {
t.Parallel()

t.Run("validate query complexity expressions for successful, rejected, and cached operations", func(t *testing.T) {
t.Parallel()

testenv.Run(t,
&testenv.Config{
AccessLogFields: []config.CustomAttribute{
{
Key: "query_depth",
ValueFrom: &config.CustomDynamicAttribute{
Expression: "request.operation.queryDepth",
},
},
{
Key: "query_total_fields",
ValueFrom: &config.CustomDynamicAttribute{
Expression: "request.operation.queryTotalFields",
},
},
{
Key: "query_root_fields",
ValueFrom: &config.CustomDynamicAttribute{
Expression: "request.operation.queryRootFields",
},
},
{
Key: "query_root_field_aliases",
ValueFrom: &config.CustomDynamicAttribute{
Expression: "request.operation.queryRootFieldAliases",
},
},
{
Key: "query_complexity_cache_hit",
ValueFrom: &config.CustomDynamicAttribute{
Expression: "request.operation.queryComplexityCacheHit",
},
},
},
LogObservation: testenv.LogObservationConfig{
Enabled: true,
LogLevel: zapcore.InfoLevel,
},
ModifySecurityConfiguration: func(securityConfiguration *config.SecurityConfiguration) {
securityConfiguration.ComplexityLimits = &config.ComplexityLimits{
Mode: config.ComplexityLimitsModeEnforce,
Depth: &config.ComplexityLimit{
Enabled: true,
Limit: 3,
},
}
securityConfiguration.ComplexityCalculationCache = &config.ComplexityCalculationCache{
Enabled: true,
CacheSize: 1024,
}
},
ModifyEngineExecutionConfiguration: func(engineExecutionConfiguration *config.EngineExecutionConfiguration) {
engineExecutionConfiguration.Debug.SynchronousCacheWrites = true
},
},
func(t *testing.T, xEnv *testenv.Environment) {
successfulQuery := `query {
first: employee(id: 1) { id details { forename surname } }
employee(id: 2) { id details { forename } }
employees { id }
}`
rejectedQuery := `query {
employee(id: 1) { details { pets { name } } }
}`

makeRequest := func(query string, expectedStatus int) {
t.Helper()
res, err := xEnv.MakeGraphQLRequest(testenv.GraphQLRequest{Query: query})
require.NoError(t, err)
require.Equal(t, expectedStatus, res.Response.StatusCode)
}

makeRequest(successfulQuery, http.StatusOK)
makeRequest(successfulQuery, http.StatusOK)
makeRequest(rejectedQuery, http.StatusBadRequest)

requestLogs := xEnv.Observer().FilterMessage("/graphql").All()
require.Len(t, requestLogs, 3)

assertComplexityFields := func(logContext map[string]interface{}, depth, totalFields, rootFields, rootFieldAliases int64, cacheHit bool) {
t.Helper()
require.Equal(t, depth, logContext["query_depth"])
require.Equal(t, totalFields, logContext["query_total_fields"])
require.Equal(t, rootFields, logContext["query_root_fields"])
require.Equal(t, rootFieldAliases, logContext["query_root_field_aliases"])
require.Equal(t, cacheHit, logContext["query_complexity_cache_hit"])
}

assertComplexityFields(requestLogs[0].ContextMap(), 3, 5, 2, 1, false)
assertComplexityFields(requestLogs[1].ContextMap(), 3, 5, 2, 1, true)
assertComplexityFields(requestLogs[2].ContextMap(), 4, 3, 1, 0, false)
},
)
})

t.Run("validate request.operation.normalizationCacheHit expression", func(t *testing.T) {
t.Parallel()

Expand Down
42 changes: 42 additions & 0 deletions router-tests/telemetry/telemetry_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10980,6 +10980,48 @@ func TestFlakyTelemetry(t *testing.T) {
})
})

t.Run("verify query complexity expression attribute", func(t *testing.T) {
t.Parallel()

exporter := tracetest.NewInMemoryExporter(t)

key := "custom.attribute"

testenv.Run(t, &testenv.Config{
TraceExporter: exporter,
CustomTracingAttributes: []config.CustomAttribute{
{
Key: key,
ValueFrom: &config.CustomDynamicAttribute{
Expression: "string(request.operation.queryDepth)",
},
},
},
ModifySecurityConfiguration: func(securityConfiguration *config.SecurityConfiguration) {
securityConfiguration.ComplexityLimits = &config.ComplexityLimits{
Mode: config.ComplexityLimitsModeEnforce,
Depth: &config.ComplexityLimit{
Enabled: true,
Limit: 2,
},
}
},
}, func(t *testing.T, xEnv *testenv.Environment) {
res, err := xEnv.MakeGraphQLRequest(testenv.GraphQLRequest{
Query: `query { employee(id: 1) { details { forename } } }`,
})
require.NoError(t, err)
require.Equal(t, http.StatusBadRequest, res.Response.StatusCode)

customAttribute := attribute.String(key, "3")
normalizeSpan := testutils.RequireSpanWithName(t, exporter, "Operation - Normalize")
require.NotContains(t, normalizeSpan.Attributes(), customAttribute)

validateSpan := testutils.RequireSpanWithName(t, exporter, "Operation - Validate")
require.Contains(t, validateSpan.Attributes(), customAttribute)
})
})

t.Run("verify validationTime expression attribute", func(t *testing.T) {
t.Parallel()

Expand Down
3 changes: 3 additions & 0 deletions router/core/graph_server.go
Original file line number Diff line number Diff line change
Expand Up @@ -896,6 +896,9 @@ func (s *graphMux) waitForCaches() {
if s.operationHashCache != nil {
s.operationHashCache.Wait()
}
if s.complexityCalculationCache != nil {
s.complexityCalculationCache.Wait()
}
}

// configureCacheMetrics sets up the cache metrics for this mux if enabled in the config.
Expand Down
7 changes: 7 additions & 0 deletions router/core/graphql_prehandler.go
Original file line number Diff line number Diff line change
Expand Up @@ -1065,11 +1065,18 @@ func (h *PreHandler) handleOperation(req *http.Request, httpOperation *httpOpera
// This check runs if they've configured a max query depth, and it can optionally be turned off for persisted operations
if h.complexityLimits != nil {
cacheHit, complexityCalcs, queryDepthErr := operationKit.ValidateQueryComplexity()
requestContext.expressionContext.Request.Operation.QueryDepth = complexityCalcs.Depth
engineValidateSpan.SetAttributes(otel.WgQueryDepth.Int(complexityCalcs.Depth))
requestContext.expressionContext.Request.Operation.QueryTotalFields = complexityCalcs.TotalFields
engineValidateSpan.SetAttributes(otel.WgQueryTotalFields.Int(complexityCalcs.TotalFields))
requestContext.expressionContext.Request.Operation.QueryRootFields = complexityCalcs.RootFields
engineValidateSpan.SetAttributes(otel.WgQueryRootFields.Int(complexityCalcs.RootFields))
requestContext.expressionContext.Request.Operation.QueryRootFieldAliases = complexityCalcs.RootFieldAliases
engineValidateSpan.SetAttributes(otel.WgQueryRootFieldAliases.Int(complexityCalcs.RootFieldAliases))
requestContext.expressionContext.Request.Operation.QueryComplexityCacheHit = cacheHit
engineValidateSpan.SetAttributes(otel.WgQueryDepthCacheHit.Bool(cacheHit))
setTelemetryAttributes(validationCtx, requestContext, expr.BucketQueryComplexity)

if queryDepthErr != nil {
rtrace.AttachErrToSpan(engineValidateSpan, err)

Expand Down
5 changes: 5 additions & 0 deletions router/internal/expr/expr.go
Original file line number Diff line number Diff line change
Expand Up @@ -96,6 +96,11 @@ type Operation struct {
VariablesRemappingCacheHit bool `expr:"variablesRemappingCacheHit"`
PersistedOperationCacheHit bool `expr:"persistedOperationCacheHit"`
PlanCacheHit bool `expr:"planCacheHit"`
QueryDepth int `expr:"queryDepth"`
QueryTotalFields int `expr:"queryTotalFields"`
QueryRootFields int `expr:"queryRootFields"`
QueryRootFieldAliases int `expr:"queryRootFieldAliases"`
QueryComplexityCacheHit bool `expr:"queryComplexityCacheHit"`

// Variables is the JSON string of the operation variables sent with the request. It is only
// populated when an expression references it, to avoid the serialization cost on every request.
Expand Down
9 changes: 8 additions & 1 deletion router/internal/expr/request_operation_bucket_visitor.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,14 +17,15 @@ const (
BucketNormalizationTime
BucketHash
BucketQueryPlanHash
BucketQueryComplexity
BucketValidationTime
BucketPlanningTime
BucketSubgraph
)

// RequestOperationBucketVisitor inspects nodes and sets Bucket to the highest-priority match
// Priority (low -> high): any, auth, sha256, parsingTime, name/type, persistedId, normalizationTime,
// hash, queryPlanHash, validationTime, planningTime, subgraph
// hash, queryPlanHash, query complexity, validationTime, planningTime, subgraph
type RequestOperationBucketVisitor struct {
Bucket AttributeBucket
}
Expand Down Expand Up @@ -97,6 +98,12 @@ func (v *RequestOperationBucketVisitor) Visit(baseNode *ast.Node) {
v.setBucketIfHigher(BucketHash)
case "queryPlanHash":
v.setBucketIfHigher(BucketQueryPlanHash)
case "queryDepth",
"queryTotalFields",
"queryRootFields",
"queryRootFieldAliases",
"queryComplexityCacheHit":
v.setBucketIfHigher(BucketQueryComplexity)
case "validationTime":
v.setBucketIfHigher(BucketValidationTime)
case "planningTime":
Expand Down
Loading
Loading