Log apollo-server GraphQL query and variables per request

Question

When using apollo-server 2.2.1 or later, how can one log, for each request, the query and the variables?

This seems like a simple requirement and common use case, but the documentation is very vague, and the query object passed to formatResponse no longer has the queryString and variables properties.

Vacillating

Answer 1

Amit's answer works (today), but IMHO it is a bit hacky and it may not work as expected in the future, or it may not work correctly in some scenarios.

For instance, the first thing that I thought when I saw it was: "that may not work if the query is invalid", it turns out that today it does work when the query is invalid. Because with the current implementation the context is evaluated before the the query is validated. However, that's an implementation detail that can change in the future. For instance, what if one day the apollo team decides that it would be a performance win to evaluate the context only after the query has been parsed and validated? That's actually what I was expecting :-)

What I'm trying to say is that if you just want to log something quick in order to debug something in your dev environment, then Amit's solution is definitely the way to go.

However, if what you want is to register logs for a production environment, then using the context function is probably not the best idea. In that case, I would install the graphql-extensions and I would use them for logging, something like:

const { print } = require('graphql');

class BasicLogging {
  requestDidStart({queryString, parsedQuery, variables}) {
    const query = queryString || print(parsedQuery);
    console.log(query);
    console.log(variables);
  }

  willSendResponse({graphqlResponse}) {
    console.log(JSON.stringify(graphqlResponse, null, 2));
  }
}

const server = new ApolloServer({
  typeDefs,
  resolvers,
  extensions: [() => new BasicLogging()]
});

Edit:

As Dan pointed out, there is no need to install the graphql-extensions package because it has been integrated inside the apollo-server-core package.

Coagulum

This may be the way to go, but it seems woefully undocumented. BTW, the code worked without installing graphql-extensions. – Vacillating

You are correct @DanDascalescu, there is absolutely no documentation for this ATM... Hopefully that is something that will improve in the near future. In the meanwhile, if you want to know more about the available life-cycle methods, have a look at this class definition. – Coagulum

Apollo Server now has documentation for plugins – Burd

this answer is outdated as the extensions are deprecated. use the plugins instead, see below post from @amoe – Eros

Answer 2

With the new plugins API, you can use a very similar approach to Josep's answer, except that you structure the code a bit differently.

const BASIC_LOGGING = {
    requestDidStart(requestContext) {
        console.log("request started");
        console.log(requestContext.request.query);
        console.log(requestContext.request.variables);
        return {
            didEncounterErrors(requestContext) {
                console.log("an error happened in response to query " + requestContext.request.query);
                console.log(requestContext.errors);
            }
        };
    },

    willSendResponse(requestContext) {
        console.log("response sent", requestContext.response);
    }
};


const server = new ApolloServer(
    {
        schema,
        plugins: [BASIC_LOGGING]
    }
)

server.listen(3003, '0.0.0.0').then(({ url }) => {
    console.log(`GraphQL API ready at ${url}`);
});

Intravasation

This approach is very nice. The only thing is that willSendResponse should be returned in the same context as didEncounterErrors since both depend on requestDidStart – Holophrastic

Answer 3

Dan's solution mostly resolves the problem but if you want to log it without using express, you can capture it in context shown in below sample.

const server = new ApolloServer({
schema,
context: params => () => {
    console.log(params.req.body.query);
    console.log(params.req.body.variables);
}
});

Rodarte

For the record, I upvoted this answer, but is it possible that you meant to do it like this instead:context: params => { console.log(params.req.body.query); console.log(params.req.body.variables); return emptyObject; } ? I mean, I think that the context is supposed to return an object when using the "function" override. – Coagulum

Answer 4

If I had to log the query and variables, I would probably use apollo-server-express, instead of apollo-server, so that I could add a separate express middleware before the graphql one that logged that for me:

const express = require('express')
const { ApolloServer } = require('apollo-server-express')
const { typeDefs, resolvers } = require('./graphql')

const server = new ApolloServer({ typeDefs, resolvers })
const app = express()

app.use(bodyParser.json())
app.use('/graphql', (req, res, next) => {
  console.log(req.body.query)
  console.log(req.body.variables)
  return next()
})

server.applyMiddleware({ app })

app.listen({ port: 4000}, () => {
  console.log(`🚀 Server ready at http://localhost:4000${server.graphqlPath}`)
})

Selfexplanatory

What advantages would this solution have over Amit's much simpler one? – Vacillating

Nothing beyond the fact that I gave my answer two days before he did – Selfexplanatory

This is actually a much more flexible solution, it really helped me – Painless

Answer 5

I found myself needing something like this but in a more compact form - just the query or mutation name and the ID of the user making the request. This is for logging queries in production to trace what the user was doing.

I call logGraphQlQueries(req) at the end of my context.js code:

export const logGraphQlQueries = ( req ) => { 

  // the operation name is the first token in the first line
  const operationName = req.body.query.split(' ')[0]; 

  // the query name is first token in the 2nd line
  const queryName = req.body.query
    .split('\n')[1]
    .trim()
    .split(' ')[0]
    .split('(')[0];

  // in my case the user object is attached to the request (after decoding the jwt)
  const userString = req.user?.id
    ? `for user ${req.user.id}`
    : '(unauthenticated)';
  console.log(`${operationName} ${queryName} ${userString}`);
};

This outputs lines such as:

query foo for user e0ab63d9-2513-4140-aad9-d9f2f43f7744

Dobb

Answer 6

Apollo Server exposes a request lifecycle event called didResolveOperation at which point the requestContext has populated properties called operation and operationName

plugins: [
  {
    requestDidStart(requestContext) {
      return {
        didResolveOperation({ operation, operationName }) {
          const operationType = operation.operation;
          console.log(`${operationType} recieved: ${operationName}`)
        }
      };
    }
  }
]
// query recieved: ExampleQuery
// mutation recieved: ExampleMutation

Glassworker

Answer 7

Here's a colorful logging plugin for apollo

https://github.com/youssef-ahamid/apollo-logging-plugin#readme

Installation

npm i apollo-logging-plugin #npm
yarn add apollo-logging-plugin #yarn
pnpm add apollo-logging-plugin #pnpm

Usage

import { ApolloServer, BaseContext } from '@apollo/server';
import { ApolloLogPlugin } from 'apollo-logging-plugin';

const server = new ApolloServer<BaseContext>({
  typeDefs,
  resolvers,
  plugins: [ApolloLogPlugin()]
});

Example logs:

OperationName  OperationType  OperationStatus  [TIMESTAMP] 
Example        query          success          [TIMESTAMP] 
Example2       mutation       info             [TIMESTAMP] 
Example3       query          error            [TIMESTAMP] 
Error:
Cannot query field "user" on type Query.

Custom handlers

import { ApolloServer, BaseContext } from '@apollo/server';
import { ApolloLogPlugin } from 'apollo-logging-plugin';

const handlers = (log: Log) => ({
  didEncounterErrors: log.error,
  didResolveOperation: log.info,
  didEncounterSubsequentErrors: (context) =>
    log.error(context, 'Custom Message'),
  parsingDidStart: (context) => {
    // handle event
  }
  // ... other handlers
});

const server = new ApolloServer<BaseContext>({
  typeDefs,
  resolvers,
  plugins: [ApolloLogPlugin(handlers)]
});

Tamarau