GraphQLサーバのマイクロサービス環境でのログフォーマットを考える

# この記事の背景

現在担当しているプロジェクトでは、GraphQLを提供するAPIサーバを中心とした、マイクロサービスアーキテクチャを構築しています。
サービスが複雑化するにつれて、ログの出力フォーマットや統一された方法でのログ確認が重要になります。
この記事では担当プロジェクトで取り組んだロギングのシステムと、そのフォーマットについて紹介します。

フォーマットを考える過程で、以下の書籍と記事は大変参考になりました。
併せてお読みいただけると嬉しいです。

https://book.productionreadygraphql.com/
https://lab.mo-t.com/blog/microservice-log

# システム全体図

ラフに描いた全体図は以下になります。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/28883/7e305294-4400-8680-326d-f4918a5bf4ae.png)

具体的なサービス名は伏せているため、分かりづらいかもしれませんが、GraphQL Gatewayの下にいくつかのサービスがあり、それとはまた別に比較的小さなサービスが存在していて、全体を構築するシステムになっています。

細かい部分ではCloudWatchサブスクリプションフィルターを通して、Firehoseにログを送信し、データを整形した上でOpenSearchと連携をしてたりもしますが、本題から外れるので本記事ではそういった実装の細かい部分は省略します。

どのサービスのリクエストであっても、最終的にはOpenSearchに連携し、フォーマットと方法が統一された状態でログの閲覧が可能となることを目的としています。

以下にリクエストの流れの例を示します。

```mermaid
sequenceDiagram
    participant Client
    participant GraphQLGateway as GraphQL Gateway
    participant ServiceA as Service 1
    participant ServiceB as Service 2
    participant ServiceC as Service 3

    Client->>GraphQLGateway: リクエスト送信
    GraphQLGateway->>ServiceA: Service 1へのリクエスト
    ServiceA-->>GraphQLGateway: Service 1のレスポンス
    GraphQLGateway->>ServiceB: Service 2へのリクエスト
    ServiceB->>ServiceC: Service 3へのリクエスト
    ServiceC-->>ServiceB: Service 3のレスポンス
    ServiceB-->>GraphQLGateway: Service 2のレスポンス
    GraphQLGateway-->>Client: 最終レスポンス
```

# ログフォーマット

以下に出力されるログの例を示します。

```JSON
{
  "type": "REQUEST_END",
  "requestId": "xxxxxxxxxxxxx",
  "request": {
    "id": "xxxx-xxxx-xxxx-xxxx-xxxxxxxxxxx",
    "type": "graphql",
    "clientName": "clientName",
    "clientVersion": "v1.8.0",
    "serverName": "serverName",
    "serverVersion": "v1.8.0",
    "ua": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36",
    "method": "POST /",
    "body": """{"operationName":"OperationName","variables":{"keyword":"","take":20,"skip":0},"query":"query GetList($skip: Int, $take: Int) {\n  items(skip: $skip, take: $take) {\n    id\n    name\n __typename\n  }\n}\n"}""",
    "queryParams": "{}",
    "startTime": "2024-10-14T22:45:42.966Z",
    "endTime": "2024-10-14T22:45:52.888Z",
    "durationMs": 631,
    "statusCode": 200
  },
  "error": {
    "code": "INVALID_ARGUMENT",
    "message": "",
    "details": "..."
  },
  "context": {
    "userId": "xxxxxxxxxx",
    "role": "Admin"
  }
}
```

## 各項目の説明

| フィールド名 | 値 | 説明 |
| ---- | ---- | ---- |
| type | REQUEST_START \| REQUEST_END \| INFO \| DEBUG \| ERROR | ログを送信した理由
| requestId | ID | リクエストのID。AWS Gatewayで生成したx-amz-apigw-idを連携する |
| request | JSON | リクエスト内容 |
| error | JSON | エラー内容 |
| context | JSON | サービス固有の情報 |

### type
typeにはログを送信した理由を格納しています。
現状はREQUEST_START \| REQUEST_END \| INFO \| DEBUG \| ERRORを規定していますが、追加されることも想定しています。
これにより用途に応じて特定のログを追跡しやすくします。

### requestId
requestIdには全体のフローで一意となる値を格納しています。
ほぼ全てのサービスはAWS Gatewayを使用しているため、API Gatewayで生成されたid(x-amz-apigw-id)をそのまま使用しています。
このIDは下流のサービスのログにおいても同様のものを出力しています。
これにより、1つのリクエストで発生した関連する複数のログを追跡することを可能にしています。

### request

requestにはリクエストの情報を格納しています。
requestの各項目は以下になります。

| フィールド名 | 値 | 説明 |
| ---- | ---- | ---- |
| id | ID | リクエストのID |
| type | GraphQL \| REST \| gRPC | リクエストの種類 |
| clientName | string | クライアント名 |
| clientVersion | string | クライアントバージョン |
| serverName | string | サーバー名 |
| serverVersion | string | サーバーバージョン |
| ua | string | ユーザーエージェント |
| method | string | メソッド |
| body | string | リクエストボディ |
| queryParams | string | クエリパラメータ |
| startTime | Timestamp | 開始時間 |
| endTime | Timestamp | 終了時間 |
| durationMs | number | 処理時間 |
| statusCode | number | ステータスコード |

ここで使用されるIDは、リクエストのIDではなく、サービス内のライフサイクルにおいて一意のIDです。このIDは、REQUEST_STARTとREQUEST_ENDの間に発生したログにおいて共通となります。そのため、このIDをキーとして検索することで、1つのサービスの処理に関するログをまとめて閲覧できるようにしています。

typeにはGraphQL、REST、gRPCなどのプロトコルを格納しています。ほぼ全てのサービスはGraphQLを使用してはいますが、一部のサービスではRESTを使用しているため、その場合にはtypeにRESTを格納しています。将来的に別のプロトコルを使用する場合も想定しています。

clientName、clientVersionはクライアントの情報を格納しています。
Production Ready GraphQLでは、Performance & Monitoringの章にて、Clientの情報を出力することを推奨しています。
ここではその考えを取り入れて、調査の際にどのクライアントからのリクエストであるか、特定のバージョンにおける問題かどうかを特定しやすくしています。
clientはweb client(ブラウザ)に限らず、サーバ間のプロセス間通信においても送信側はクライアントとなります。

serverName、serverVersionはサーバーの情報を格納しています。
こちらもclientName、clientVersionと同様の目的です。

body、queryParamsはリクエストの内容を格納しますが、ユーザ名などのセンシティブな情報は含めないようにする必要があります。

startTime、endTime、durationMsはリクエストの開始時間、終了時間、処理時間を格納しています。
durationを格納しておくことで、時間がかかる処理を追跡しやすくしています。

### error

errorにはエラーの情報を格納しています。
typeがERRORの場合には必ず存在しますが、その他では存在しない場合もあります。
detailsにはエラーに関連する情報(stack traceなど)を含めます。

### context

contextにはサービス固有の情報を格納しています。
ここではフォーマットを規定せず、サービスによって自由にフィールドを追加しています。

# Schema Registry

ロギングとは直接的には関係しませんが、ロギングの整理の過程でSchema Registryの整備を行いました。
Production Ready GraphQLでは、Analyticsの章にて、GraphQLリクエストを1つ1つのエンティティの単位まで"de-normalized"することの利点を述べています。

現段階ではそこまで着手できていないのですが、将来的に分析の用途でログを使用する場合に元となるSchemaを参照できるようにする目的で、リリース時点のSchemaを保存しておくことにしました。
この用途で使うためにも、フォーマットの中でサーバ(=schema)のバージョンを出力しておくことが重要になります。

少し本題から外れますが、一般的にGraphQLのSchema RegistryはCI/CDにおけるSchemaのBreaking Changeの検知に使用されています。

分析用途ではまだ使用していませんが、このプロジェクトでも副次的にリリース前のSchemaのBreaking changesの検知も行えるようになりました。

今回は自前のs3に保存していますが、Schema registryはApollo StudioやHasuraなどのサービスでも提供されています。

https://www.apollographql.com/docs/graphos/platform/schema-management

https://hasura.io/docs/2.0/data-federation/schema-registry/

# おわりに

本記事ではGraphQLを提供するAPIサーバを中心としたマイクロサービスアーキテクチャにおけるロギングのシステムと、そのフォーマットの一例を紹介しました。
まだ運用の中で変わっていく部分も出てくるとは思いますが、その際には随時更新していきたいと思います。
どなたかの参考になれば幸いです。