Graphql-tools: Logging (and other) "middleware"

[mklopets]

Setting the scene:
All of the (micro)services at my company log out data about requests both to the console and a log management tool. We are now building our first GraphQL service and figured we should comply with our internal best practices and add thorough request logging to this, too.

In the context of GraphQL, things generally go wrong on a resolver level^[1] (or rather, in the model or whatever the resolver calls) and as such, resolver-level logging would be sweet for tracking down the source of errors.

There aren't currently (or I simply haven't found any!) nice ways of adding logging or other middleware to resolvers.

Tonight, I decided to do some investigation and/or playing around with this, and ended up writing a little higher-order function to wrap a resolver function, essentially applying a logger middleware to it for debugging purposes.

function createResolver(resolver) {
    return (obj, args, context, info) => {
        // Put resolver call into pre-created promise chain to promisify the function if necessary
        return Promise.resolve().then(resolver.bind(this, obj, args, context, info)).then(result => {
            // Logging for successful resolver calls
            console.log({
                data: { obj, args, context, selectionSet: JSON.stringify(info.operation.selectionSet) },
                result: result ? JSON.stringify(result) : result
            });
            return result; // result is eventually passed through the normal way
        }).catch(error => {
            // Logging for failed resolver calls
            console.log({
                data: { obj, args, context, selectionSet: JSON.stringify(info.operation.selectionSet) },
                error
            });
            throw error; // re-throw the error after logging
        });
    };
}

Usage in resolver map:

const resolvers = {
    Query: {
        me: createResolver((obj, args, context, info) => {
            throw new Error('oh noes!'); // crap, my amazing resolver is throwing an error! better get it logged.
            return {
                id: '123',
                firstName: 'John',
                lastName: 'Doe',
            };
        })
    }
};

This exact same kind of approach can be used for other purposes as well:

Logging-related use cases:

• having useful context-aware debug data^[2] provided with automatically collected errors
• performance monitoring/analysis

Other use cases:

• authorization (#313 has a great discussion on how to solve that problem specifically)
• generic middleware to always be applied pre-resolver-invocation

_But_ this sucks.

Wrapping every resolver like this manually is tedious. I would love it if there was a nicer designed, built-in-ish way to define middleware like this, be it for authorization, error logging or performance metric collection. Perhaps beforeEach and afterEach options on makeExecutableSchema. I would love to hear everyone's opinions on this!

Edit 22/07/2017

Upon further reflection on this, I'm starting to think that it might make more sense for this to be solved on the server-side, not be a part of the executable schema outputted by graphql-tools.

Footnotes:
^[1] this is my assumption based on very limited experience
^[2] the arguments provided to each failing resolver, for example

[mklopets]

Just saw Optics thanks to a mention in the Apollo Slack. That being a thing might be one reason why stuff like this hasn't been really pushed into the open source project(?)

[martijnwalraven]

I think having a standard way to add resolver middleware would be great. In optics-agent-js (as well as the new apollo-tracing-js), we currently use a wrapping approach similar to the code you posted above. Ideally, something like this could be added to graphql-js, but that might take a while, so we may want to start off by adding a middleware mechanism to graphql-tools or apollo-server as you suggested.

[giautm]

I think static directives can be fit as middlewares. please check examples in https://github.com/apollographql/graphql-tools/pull/518

[kbrandwijk]

I implement the same pattern graphql-add-middleware uses in my framework to add resolver middleware to my server, and it works very well for things like logging and authentication.

[stubailo]

We're working on this type of functionality in Apollo Server 2.0, the current implementation lives in the graphql-extensions package: https://github.com/apollographql/apollo-server/tree/7f11c605a17f819061f2845b58c0f22e45a6f230/packages/graphql-extensions

I'd suggest looking at that and perhaps opening an issue on Apollo Server to discuss!