Skip to content

Commit

Permalink
feat: add more details to apollo query logging
Browse files Browse the repository at this point in the history
  • Loading branch information
gjedlicska committed Jan 9, 2024
1 parent 7d70734 commit 6a6a0ea
Showing 1 changed file with 19 additions and 9 deletions.
28 changes: 19 additions & 9 deletions packages/server/logging/apolloPlugin.js
Original file line number Diff line number Diff line change
@@ -18,9 +18,9 @@ const metricCallCount = new prometheusClient.Counter({
module.exports = {
// eslint-disable-next-line no-unused-vars
requestDidStart(ctx) {
const apolloRequestStart = new Date()

This comment has been minimized.

Copy link
@iainsproat

iainsproat Jan 9, 2024

Contributor

Date.now()? (typescript gets angry when subtracting Date objects)

return {
didResolveOperation(ctx) {
const apolloRequestStart = new Date()
let logger = ctx.context.log || graphqlLogger

const op = `GQL ${ctx.operation.operation} ${ctx.operation.selectionSet.selections[0].name.value}`
@@ -54,10 +54,12 @@ module.exports = {
Sentry.configureScope((scope) => scope.setSpan(transaction))
ctx.request.transaction = transaction
ctx.context.log = logger
ctx.context.apolloRequestStart = apolloRequestStart
},
didEncounterErrors(ctx) {
let logger = ctx.context.log || graphqlLogger
logger = logger.child({
apollo_query_duration_ms: new Date() - apolloRequestStart

This comment has been minimized.

Copy link
@iainsproat

iainsproat Jan 9, 2024

Contributor

Date.now()?

})

for (const err of ctx.errors) {
const operationName = ctx.request.operationName || null
@@ -71,9 +73,15 @@ module.exports = {
(err instanceof GraphQLError && err.extensions?.code === 'FORBIDDEN') ||
err instanceof ApolloError
) {
logger.info(err, 'graphql error')
logger.info(
err,

This comment has been minimized.

Copy link
@iainsproat

iainsproat Jan 9, 2024

Contributor

Only .error wraps the err in an object i.e. {err}. I think we need to do this ourselves for .info
logger.info({err}, etc.

'{graphql_operation_value} failed after {apollo_query_duration_ms} ms'
)
} else {
logger.error(err, 'graphql error')
logger.error(
err,
'{graphql_operation_value} failed after {apollo_query_duration_ms} ms'
)
}

Sentry.withScope((scope) => {
@@ -94,15 +102,17 @@ module.exports = {
},
willSendResponse(ctx) {
let logger = ctx.context.log || graphqlLogger
if (ctx.context.apolloRequestStart)
logger = logger.child({
'apollo-query-duration': new Date() - ctx.context.apolloRequestStart
})
logger = logger.child()

This comment has been minimized.

Copy link
@iainsproat

iainsproat Jan 9, 2024

Contributor

is there a need to call child if we're not adding any additional properties to it?


if (ctx.request.transaction) {
ctx.request.transaction.finish()
}
logger.info('graphql response')
logger.info(
{
apollo_query_duration_ms: new Date() - apolloRequestStart

This comment has been minimized.

Copy link
@iainsproat

iainsproat Jan 9, 2024

Contributor

Date.now()?

},
'{graphql_operation_value} finished after {apollo_query_duration_ms} ms'
)
}
}
}

0 comments on commit 6a6a0ea

Please sign in to comment.