Skip to content

Commit dfbd60d

Browse files
xperiandriclaude
andcommitted
Use structured logging templates in GraphQLRequestHandler (#600)
The log message templates in `GraphQLRequestHandler` passed the message as an interpolated string ($"...{{name}}...") instead of a literal template. Since F# string interpolation replaces `{{` with a literal `{` before the ILogger call ever sees the string, the resulting message template was a constant string with no placeholders, so the arguments were logged as extra values rather than substituted into the message - defeating structured logging (and any log-based redaction or querying by field name). Switch these calls to plain string templates with `{placeholder}` tokens, matching the pattern already used elsewhere in the file. Also fix a stray `\n:` typo in the direct-response trace message, and correct a copy-pasted label ("GraphQL deferred data") in the subscription-errors trace message that should have read "GraphQL subscription data". Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com>
1 parent 182d1a1 commit dfbd60d

1 file changed

Lines changed: 25 additions & 31 deletions

File tree

‎src/FSharp.Data.GraphQL.Server.AspNetCore/GraphQLRequestHandler.fs‎

Lines changed: 25 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -37,14 +37,10 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
3737
/// <param name="httpContextAccessor">The accessor to the current HTTP context.</param>
3838
/// <param name="options">The options monitor for GraphQL options.</param>
3939
/// <param name="logger">The logger to log messages.</param>
40-
(
41-
httpContextAccessor : IHttpContextAccessor,
42-
options : IOptionsMonitor<GraphQLOptions<'Root>>,
43-
logger : ILogger
44-
) =
40+
(httpContextAccessor : IHttpContextAccessor, options : IOptionsMonitor<GraphQLOptions<'Root>>, logger : ILogger) =
4541

4642
let ctx = httpContextAccessor.HttpContext
47-
let getInputContext() = ctx.RequestServices.GetRequiredService<IInputExecutionContext>()
43+
let getInputContext () = ctx.RequestServices.GetRequiredService<IInputExecutionContext>()
4844

4945
let toResponse { DocumentId = documentId; Content = content; Metadata = metadata } =
5046

@@ -54,18 +50,14 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
5450

5551
match content with
5652
| Direct (data, errs) ->
57-
logger.LogDebug ($"Produced direct GraphQL response with documentId = '{{documentId}}' and metadata:\n{{metadata}}", documentId, metadata)
53+
logger.LogDebug ("Produced direct GraphQL response with documentId = '{documentId}' and metadata:\n{metadata}", documentId, metadata)
5854

5955
if logger.IsEnabled LogLevel.Trace then
60-
logger.LogTrace ($"GraphQL response data:\n:{{data}}", serializeIndented data)
56+
logger.LogTrace ("GraphQL response data:\n{data}", serializeIndented data)
6157

6258
GQLResponse.Direct (documentId, data, errs)
6359
| Deferred (data, errs, deferred) ->
64-
logger.LogDebug (
65-
$"Produced deferred GraphQL response with documentId = '{{documentId}}' and metadata:\n{{metadata}}",
66-
documentId,
67-
metadata
68-
)
60+
logger.LogDebug ("Produced deferred GraphQL response with documentId = '{documentId}' and metadata:\n{metadata}", documentId, metadata)
6961

7062
if logger.IsEnabled LogLevel.Debug then
7163
deferred
@@ -74,29 +66,25 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
7466
logger.LogDebug ("Produced GraphQL deferred result for path: {path}", path |> Seq.map string |> Seq.toArray |> Path.Join)
7567

7668
if logger.IsEnabled LogLevel.Trace then
77-
logger.LogTrace ($"GraphQL deferred data:\n{{data}}", serializeIndented data)
69+
logger.LogTrace ("GraphQL deferred data:\n{data}", serializeIndented data)
7870
| DeferredErrors (null, errors, path) ->
7971
logger.LogDebug ("Produced GraphQL deferred errors for path: {path}", path |> Seq.map string |> Seq.toArray |> Path.Join)
8072

8173
if logger.IsEnabled LogLevel.Trace then
82-
logger.LogTrace ($"GraphQL deferred errors:\n{{errors}}", errors)
74+
logger.LogTrace ("GraphQL deferred errors:\n{errors}", errors)
8375
| DeferredErrors (data, errors, path) ->
8476
logger.LogDebug (
8577
"Produced GraphQL deferred result with errors for path: {path}",
8678
path |> Seq.map string |> Seq.toArray |> Path.Join
8779
)
8880

8981
if logger.IsEnabled LogLevel.Trace then
90-
logger.LogTrace (
91-
$"GraphQL deferred errors:\n{{errors}}\nGraphQL deferred data:\n{{data}}",
92-
errors,
93-
serializeIndented data
94-
))
82+
logger.LogTrace ("GraphQL deferred errors:\n{errors}\nGraphQL deferred data:\n{data}", errors, serializeIndented data))
9583

9684
GQLResponse.Direct (documentId, data, errs)
9785

9886
| Stream stream ->
99-
logger.LogDebug ($"Produced stream GraphQL response with documentId = '{{documentId}}' and metadata:\n{{metadata}}", documentId, metadata)
87+
logger.LogDebug ("Produced stream GraphQL response with documentId = '{documentId}' and metadata:\n{metadata}", documentId, metadata)
10088

10189
if logger.IsEnabled LogLevel.Debug then
10290
stream
@@ -105,18 +93,18 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
10593
logger.LogDebug ("Produced GraphQL subscription result")
10694

10795
if logger.IsEnabled LogLevel.Trace then
108-
logger.LogTrace ($"GraphQL subscription data:\n{{data}}", serializeIndented data)
96+
logger.LogTrace ("GraphQL subscription data:\n{data}", serializeIndented data)
10997
| SubscriptionErrors (null, errors) ->
11098
logger.LogDebug ("Produced GraphQL subscription errors")
11199

112100
if logger.IsEnabled LogLevel.Trace then
113-
logger.LogTrace ($"GraphQL subscription errors:\n{{errors}}", errors)
101+
logger.LogTrace ("GraphQL subscription errors:\n{errors}", errors)
114102
| SubscriptionErrors (data, errors) ->
115103
logger.LogDebug ("Produced GraphQL subscription result with errors")
116104

117105
if logger.IsEnabled LogLevel.Trace then
118106
logger.LogTrace (
119-
$"GraphQL subscription errors:\n{{errors}}\nGraphQL deferred data:\n{{data}}",
107+
"GraphQL subscription errors:\n{errors}\nGraphQL subscription data:\n{data}",
120108
errors,
121109
serializeIndented data
122110
))
@@ -125,7 +113,7 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
125113

126114
| RequestError errs ->
127115
logger.LogWarning (
128-
$"Produced request error GraphQL response with documentId = '{{documentId}}' and metadata:\n{{metadata}}",
116+
"Produced request error GraphQL response with documentId = '{documentId}' and metadata:\n{metadata}",
129117
documentId,
130118
metadata
131119
)
@@ -164,7 +152,7 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
164152
let checkOperationType () = taskResult {
165153

166154
let checkAnonymousFieldsOnly (ctx : HttpContext) = taskResult {
167-
let! gqlRequest = ctx.TryBindJsonAsync<GQLRequestContent> (GQLRequestContent.expectedJSON)
155+
let! gqlRequest = ctx.TryBindJsonAsync<GQLRequestContent>(GQLRequestContent.expectedJSON)
168156
let! ast = Parser.parseOrIResult ctx.Request.Path.Value gqlRequest.Query
169157
let operationName = gqlRequest.OperationName |> Skippable.toValueOption
170158

@@ -190,7 +178,7 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
190178
let hasNonMetaFields =
191179
Ast.containsFieldsBeyond
192180
Ast.metaTypeFields
193-
(fun field -> logger.LogTrace ($"Operation Selection in Field with name: {{fieldName}}", field.Name))
181+
(fun field -> logger.LogTrace ("Operation Selection in Field with name: {fieldName}", field.Name))
194182
(fun _ -> logger.LogTrace "Operation Selection is non-Field type")
195183
op
196184

@@ -220,16 +208,22 @@ and [<AbstractClass>] GraphQLRequestHandler<'Root>
220208
/// Execute the operation for given request
221209
default _.ExecuteOperation<'Root> (executor : Executor<'Root>, content) = task {
222210

223-
let operationName = content.OperationName |> Skippable.filter (not << isNull) |> Skippable.toOption
224-
let variables = content.Variables |> Skippable.filter (not << isNull) |> Skippable.toOption
211+
let operationName =
212+
content.OperationName
213+
|> Skippable.filter (not << isNull)
214+
|> Skippable.toOption
215+
let variables =
216+
content.Variables
217+
|> Skippable.filter (not << isNull)
218+
|> Skippable.toOption
225219

226220
operationName
227221
|> Option.iter (fun on -> logger.LogTrace ("GraphQL operation name: '{operationName}'", on))
228222

229-
logger.LogTrace ($"Executing GraphQL query:\n{{query}}", content.Query)
223+
logger.LogTrace ("Executing GraphQL query:\n{query}", content.Query)
230224

231225
variables
232-
|> Option.iter (fun v -> logger.LogTrace ($"GraphQL variables:\n{{variables}}", v))
226+
|> Option.iter (fun v -> logger.LogTrace ("GraphQL variables:\n{variables}", v))
233227

234228
let root = options.CurrentValue.RootFactory ctx
235229

0 commit comments

Comments
 (0)