NestJSのGraphQLサーバにApplication Insightsのトレースを仕込む

NestJS (GraphQL) アプリをAzureのAppServiceでホストしているのですが、どうもレスポンスが遅いということで、調査のためにトレースログを仕込む方法を調べたログです。

Apollo Serverのプラグインを作成し、Apolloの各種イベントにカスタムトレースログを出力するコードを書きます。

import * as appInsights from 'applicationinsights';
import { ApolloServerPlugin, GraphQLRequestListener } from '@apollo/server';
import { Plugin } from '@nestjs/apollo';

/**
 * GraphQLの各種イベント実行時にAzureのApplicationInsightsへトレースを送信するためのプラグイン
 */
@Plugin()
export class ApplicationInsightsApolloServerPlugin
  implements ApolloServerPlugin
{
  async requestDidStart(): Promise<GraphQLRequestListener<any>> {
    const client = appInsights.defaultClient;
    client.trackMetric({ name: 'graphql-query', value: 1 });
    return {
      // GraphQLのASTを解析後実行が開始したら呼ばれます
      // REF: https://www.apollographql.com/docs/apollo-server/integrations/plugins-event-reference/#executiondidstart
      async executionDidStart(requestContext) {
        if (requestContext.errors) {
          client.trackException({
            exception: new Error(
              `graphql-error: ${JSON.stringify(requestContext.errors)}`,
            ),
          });
        } else {
          client.trackTrace({
            message: `graphql executionDidStart: ${JSON.stringify({
              operationName: requestContext.request.operationName,
              query: requestContext.request.query,
              variables: requestContext.request.variables,
              request: requestContext.request,
            })}`,
          });
        }
      },
      // GraphQLのレスポンス送信のたびに呼ばれます
      // REF: https://www.apollographql.com/docs/apollo-server/integrations/plugins-event-reference/#willsendresponse
      async willSendResponse(requestContext) {
        if (requestContext.errors) {
          client.trackException({
            exception: new Error(
              `graphql-error: ${JSON.stringify(requestContext.errors)}`,
            ),
          });
        } else {
          client.trackTrace({
            message: `graphql willSendResponse: ${JSON.stringify(
              requestContext.response,
            )}`,
          });
        }
      },
    };
  }
}

client.trackTrace によってトレースされたデータは、Application Insights -> Logs の traces テーブルへ格納されます。

Apolloのイベントはたくさんあるので、トレースしたい箇所のイベントを探して仕込みましょう。

https://www.apollographql.com/docs/apollo-server/integrations/plugins-event-reference/

AppModuleなどでPluginを読み込む必要があります。

import { Module } from '@nestjs/common';
import { GraphQLModule } from '@nestjs/graphql';
import { ApolloDriver, ApolloDriverConfig } from '@nestjs/apollo';
import { ApplicationInsightsApolloServerPlugin } from './application-insights-apollo-server-plugin';

@Module({
  imports: [
    GraphQLModule.forRoot<ApolloDriverConfig>({
      driver: ApolloDriver,
      ...
    }),
  ],
  providers: process.env.APPLICATIONINSIGHTS_CONNECTION_STRING
    ? [ApplicationInsightsApolloServerPlugin]
    : [],
})
export class AppModule {}

利用するために、main.tsの速い段階で、applicationInsightsをstart()しておく必要があります。

import { NestFactory } from '@nestjs/core';
import * as appInsights from 'applicationinsights';

import { AppModule } from './app.module';

async function bootstrap() {
  if (process.env.APPLICATIONINSIGHTS_CONNECTION_STRING) {
    appInsights
      .setup(process.env.APPLICATIONINSIGHTS_CONNECTION_STRING)
      .start();
  }

  const app = await NestFactory.create(AppModule);
  await app.listen(3000);
}
bootstrap();

参考: