How to Collect HTTP Request Telemetry with GraphQL and RESTDataSource?

Posted on: 2019-05-28

I have been working in a GraphQL solution at Netflix for few months now. I am always keen to have insight about what is going on. While I created from the ground-up the GraphQL server with NodeJS I had in mind to find a way to give me, the software engineer, some insights by providing some direct feedback in the bash console running the server but also to send the data to an ElasticSearch cluster. Before rendering or sending the telemetry, we need to collect it. In this article, I'll write how I proceeded to get information on individual HTTP calls that the GraphQL query invoke to retrieve the information while resolving a graph of objects.

The solution is oriented toward the library RESTDataSource but it is exactly the same principle with Axios or other HTTP request library. The idea is to subscribe to a global event that is invoked when a request starts and when a response comes back. By having a hook at the beginning and the end, it is possible to collect the time elapsed without having to code something on every request.

RESTDataSource Override

In the case of RESTDataSource, it is a matter of overriding the willSendRequest function. It takes a request parameter. We will use the request to add in the HTTP's header a unique identifier that will give the response function a reference to the originator. The second function to override is didReceiveResponse. This one has two parameters: the request and the response.

The willSendRequest function performs three actions. The first one is to generate a GUID that will serve as a unique identifier. It is added into the HTTP header. Then, the second action is to add in the GraphQL's context a collection of HTTP requests. I created a type that will keep track of the time, the total bytes received, the URL, query string, the starting time and also the unique request identifier (GUID). The unique identifier is needed for the second function.

export interface HttpStatsEndpoints {
    requestUuid: string;
    url: string;
    urlSearchParams: URLSearchParams;
    elapsedTimeMs: number;
    totalBytes: number;
}

The didReceiveResponse function gets a response, but also the request object. Because we have the request, we can peek at the GUID and extract from the GraphQL context the information and subtract the actual time from the time saved when the request started. The number of bytes and the elapsed time is saved in the context until read by the GraphQL Extension.

public didReceiveResponse(response: Response, request: Request): Promise<any> {
    return super.didReceiveResponse(response, request).then(result => {
        const requestId = request.headers.get(HEADER_REQUEST_UUID);
        const startTime = request.headers.get(HEADER_START_TIME);
        const httpRequest = this.context.stats.httpRequests.find(d => d.requestUuid === requestId);
        if (httpRequest !== undefined && startTime !== null) {
            const totalNanoSecondsElapsed = process.hrtime();
            const totalMilliSecondsElaspsed = this.convertNodeHrTimeToMs(totalNanoSecondsElapsed);
            httpRequest.elapsedTimeMs = totalMilliSecondsElaspsed - Number(startTime);
            httpRequest.totalBytes = JSON.stringify(result).length;
        }
        return result;
    });
}

GraphQL Extension

At this point, when all requests are completed and the GraphQL is ready to send a response back, a custom extension can come into play. I covered the detail of a custom GraphQL Extension in a previous post concerning telemetry and how to display it on the console. The idea is the same, this time we can read the GraphQL context and while looping through the telemetry display the bytes and time taken for each request.

How to Collect HTTP Request Telemetry with GraphQL and RESTDataSource?

RESTDataSource Override

GraphQL Extension

Here are some of my GraphQL post of this series