APIリクエストのログを加工してrsyslogサーバに送る


Kong Gatewayではリクエストのログを送るための様々なプラグインが[用意されている](https://docs.jp.konghq.com/hub/?category=logging)。
今回は[TCP Log Pugin](https://docs.konghq.com/hub/kong-inc/tcp-log/)を使ってrsyslogにログを飛ばしてみるのと、ログ系のプラグインの多くで用意されている`custom_fields_by_lua`の機能を使ってどのようにログを加工できるか確認する。

```mermaid
flowchart LR
    subgraph Kong Gateway
        A1[TCP Log Plugin]
    end

    A1 --> E[rsyslog]
```
なお、Kongのログ系のプラグインは基本的に構造化ログを送るため、rsyslogで受け取ってそのまま見るようなものではないので注意。
今回はあくまでも検証用途と捉えて欲しい。


## 検証環境
今回は以下の環境で検証した。
- EKS
- rsyslogはK8s上に用意（[こちら](https://qiita.com/ipppppei/items/fa90e7efddf61ae63594#rsyslog%E7%92%B0%E5%A2%83podservice%E3%81%AE%E6%A7%8B%E7%AF%89)の手順で用意）
- Kong Gateway 3.10.0.1を利用
- Kong Konnectを利用

上記の準備の手順については省略する。
EKSやKonnect固有の機能は利用していないので、rsyslogがあってKong Gatewayが利用できるなら同じことが出来ると思う。
## Service/Route/Pluginの設定
Service/Route/Pluginは[decK](https://docs.jp.konghq.com/deck/)でササッと用意する。
ここでは以下の設定で作成した。
- 接続先：`https://httpbin.konghq.com`
- Routeのパス：`/httpbin`
- TCP LogPlugin:
	- ログの転送先：`rsyslog.rsyslog.svc`
	- 待ち受けポート：`514`

```yaml:demo-deck.yaml
cat <<EOF > ./demo-deck.yaml
_format_version: "3.0"
services:
- enabled: true
  host: httpbin.konghq.com
  name: httpbin-svc
  path: /
  port: 443
  protocol: https
  routes:
  - name: httpbin-route
    paths:
    - /httpbin
    plugins:
    - config:
        host: rsyslog.rsyslog.svc
        port: 514
      enabled: true
      name: tcp-log
      tags:
      - rsyslog-demo
    tags:
    - rsyslog-demo
  tags:
  - rsyslog-demo
EOF
```

```bash
deck gateway sync demo-deck.yaml --select-tag rsyslog-demo
```

## ログの取得
リクエストを投げてログを確認する。
```bash
curl <Data Planeのアドレス:ポート>/httpbin
```
rsyslog内のログを確認する。(sedで`{`以降の出力のみに絞っている)
```bash
kubectl exec -it rsyslog -n rsyslog -- tail -n 1 /var/log/remote.log | sed 's/^[^{]*//' | jq .
```
するとJSON形式のログが確認できると思う。
出てきている値の意味はざっくり以下となる。（公式の記載は[こちら](https://docs.konghq.com/hub/kong-inc/tcp-log/#log-format-definitions)）

| キー名               | 意味                                                                               |
| ----------------- | -------------------------------------------------------------------------------- |
| `client_ip`       | クライアント（リクエスト元）のIPアドレス                                                            |
| `started_at`      | リクエストの処理が開始された時刻（UNIXタイムスタンプ、ミリ秒単位）                                              |
| `upstream_status` | Upstreamから返されたHTTPステータスコード（例: 200）                                               |
| `source`          | ログの発生源（例: `upstream`）                                                            |
| `workspace_name`  | ワークスペースの表示名（例: `default`）                                                        |
| `workspace`       | ワークスペースのUUID                                                                     |
| `upstream_uri`    | Upstreamに対して送信された実際のURI                                                          |
| `service`オブジェクト   | リクエストが使用したServiceの設定                                                             |
| `route`オブジェクト     | リクエストが使用したRouteの設定                                                               |
| `tries`オブジェクト     | [Upstream](https://docs.konghq.com/gateway/latest/key-concepts/upstreams/)に関する情報 |
| `request`オブジェクト   | リクエストのメタ情報（メソッド、ヘッダ、クエリ、URL等）</br>※bodyは含まない                                     |
| `response`オブジェクト  | レスポンスのステータスコード、ヘッダ、サイズ</br>※bodyは含まない                                            |
| `latencies`オブジェクト | Kong内、リクエスト全体、Kongとアップストリーム間のレイテンシ。proxyとreceiveの違いはレスポンスの受信開始時と受信完了時の違い。        |

なお、レスポンスに関する情報があるのは、ログ系のプラグインが動作するのはレスポンスを受け取った後であるためである。（参考：[lua-nginx-moduleのDirective](https://openresty-reference.readthedocs.io/en/latest/Directives/)）
リクエストヘッダに関しては、全てそのまま出力する訳ではなく、例えばAuthorization
ヘッダは以下のような感じでマスクしてログに出力される。
```json
      "authorization": "REDACTED",
```

## `custom_fields_by_lua`によるログの書き換え
`custom_fields_by_lua`を使うとログの内容をLuaによって動的に書き換えることが出来る。
利用例としては以下のようなものがある。
- Grafana Loki/Tempoでログとトレースを相互補完する際に、トレースIDをログに記載する
- 個人情報に紐づくようなヘッダの削除

なお、利用の注意点としては以下がある。
- 後続の処理で別でログ系プラグインが呼ばれる場合、`custom_fields_by_lua`が再度呼ばれる
  →ある特定のログ系プラグインでは書き換えたくない場合などは明示的に`custom_fields_by_lua`で`return nil`などの何もしないコードを設定する必要あり
- セキュリティ観点から一部の関数（`os.*`のほとんどや`_G`など）は利用不可
- [PDK](https://docs.jp.konghq.com/gateway/latest/plugin-development/pdk/)は利用可能だが、log phaseで利用可能なものに限定される

とりあえず使ってみる。
#### ケース1: トレースIDの追加
Jaegerなどのトレーシングで使うトレースIDは通常クライアント側で追加する必要があるが、KongのOTEL Pluginを使ってKong Gateway経由で通信すると、クライアントの改修なしにトレースIDを埋め込むことが出来る。
OTEL Pluginではいくつかのトレースフォーマットをサポートしているが、例えばw3cにすると以下のようなトレース用ヘッダを追加することが出来る。
```
    "Traceparent": "00-7f4cc1958ed2339ab7d1e3a9c864251c-f6eb5a175212ac7f-00",
```

これはW3Cで`<version>-<トレースID>-<スパンID>-<フラグ>`と[定義されている](https://www.w3.org/TR/trace-context/#traceparent-header)。
実際にLokiと連携する時はこれを分解して
```json
{
  trace_id: 7f4cc1958ed2339ab7d1e3a9c864251c,
  span_id: f6eb5a175212ac7f
}
```
のような感じでログに渡してあげると連携がスムーズに行く。
ということでdeckに以下のような感じで`custom_fields_by_lua`の設定を追加する。
```yaml
    config:
      custom_fields_by_lua:
        span_id: |-
          local h = kong.request.get_header("traceparent")
          return h:match("%-[a-f0-9]+%-([a-f0-9]+)%-")
        trace_id: |-
          local h = kong.request.get_header("traceparent")
          return h:match("%-([a-f0-9]+)%-[a-f0-9]+%-")
```
`spin_id:`, `trace_id:`がそれぞれ追加するログのキーとして設定される部分で、`|-`以降で値となる部分をLua関数で定義している。
`kong.request.get_header`はKongのPDKでリファレンスは[ここ](https://docs.konghq.com/gateway/latest/plugin-development/pdk/kong.request/#kongrequestget_headername)になる。
PDKを使ってヘッダ名から値を取得し、`h:match`で正規表現を使ってダブルクォート内の`(...)`の箇所で対象の値を抜き出している。

動作確認してみる。
OTEL Pluginを適用して動作確認してもよいが、面倒だったのでここではcurlにヘッダを追加することで確認する。
```sh
curl proxy.bootcamp.kong-imurata.click/httpbin -H "Traceparent: 00-7f4cc1958ed2339ab7d1e3a9c864251c-f6eb5a175212ac7f-00"
```
ログを確認する。traceとspanを含む文字列だけ抜き出す。
```sh
$ kubectl exec -it rsyslog -n rsyslog -- tail -n 1 /var/log/remote.log |sed 's/^[^{]*//' | jq . | grep "trace\|span"
```
意図した通りにトレース情報がトレースIDとスパンIDに分かれてログに残っているのが確認できる。
```json
      "traceparent": "00-7f4cc1958ed2339ab7d1e3a9c864251c-f6eb5a175212ac7f-00",
  "trace_id": "7f4cc1958ed2339ab7d1e3a9c864251c",
  "span_id": "f6eb5a175212ac7f",
```

ちなみに今の書き方だと`kong.request.get_header`に失敗した時の実装が含まれていないので、該当するヘッダを含まないリクエストを送ると以下のようにPluginがエラーを吐いてログを転送しないので注意。
```
2025/05/29 06:23:07 [error] 2614#0: *1371158 failed to run log_by_lua*: [string "local h = kong.request.get_header("traceparen..."]:2: attempt to index local 'h' (a nil value)
```
#### ケース2: 特定のヘッダの削除
Authorizationヘッダについてはマスクしてくれるが、独自にヘッダを作ってそこに機密情報的なものを含むようなケースでは保護されない。
ここでは`my-cert`というヘッダに対応する値に保護したい情報が載っているとして、それを`PROTECTED`という文字に置き換えてみる。
```yaml
    config:
      custom_fields_by_lua:
          request.headers.my-cert: |-
            return "PROTECTED"
```
ネストした箇所に対してはJSONで辿るのと同じように`.`で繋いで`request.headers.my-cert`のように書けば設定できる。
ちなみにヘッダ自体を削除したい場合は対応するキーに対して`"return nil"`を書いてあげればOK。
上記の設定を追加したdeckのYAMLを適用後、curlで試してみる。
ここでは以下のリクエストで検証する。
```sh
curl proxy.bootcamp.kong-imurata.click/httpbin -H "my-cert: YWxhZGRpbjpvcGVuc2VzYW1l"
```
`custom_fields_by_lua`の適用前は以下のようになる。
```json
$ kubectl exec -it rsyslog -n rsyslog -- tail -n 1 /var/log/remote.log |sed 's/^[^{]*//' | jq . |grep my-cert
      "my-cert": "YWxhZGRpbjpvcGVuc2VzYW1l"
```

`custom_fields_by_lua`の適用後は以下のようになる。
```json
$ kubectl exec -it rsyslog -n rsyslog -- tail -n 1 /var/log/remote.log |sed 's/^[^{]*//' | jq . |grep my-cert
      "my-cert": "PROTECTED"
```
問題なく変更できた。

## 結論
- APIリクエスト、レスポンスをログに転送するのにいい感じのPluginが揃ってる
- ただし、Bodyは取得できない
- ログにはリクエスト・レスポンスのメタデータの他にレイテンシやService/Route/Upstreamの情報も含まれる
- `custom_fields_by_lua`を使うとログの書き換えが出来て、トレースIDの埋め込みなども可能に

ちなみにBodyを出力させたい要望もあると思う。
その場合は英語になるが、「[How to Log Request and Response Body With Kong](https://tech.aufomm.com/how-to-log-request-and-response-body-with-kong/)」というブログ記事や「[How to add Request and Response payloads to the logging plugins](https://support.konghq.com/support/s/article/How-to-add-Request-and-Response-payloads-to-the-logging-plugins)」というKBが参考になると思う。