Webhookを受けるサーバーのリクエストログをnginx, Filebeat, Logstash, Elasticsearchで収集

## まえおき

ほぼ自分用のメモ。
　


チャットボットを作るには、Webhookを受ける君を作らないといけない。
普通なら、迷わず AWS LambdaとAPI GatewayとCloudWatch logsを使うと思うし、それがよい。

ただ今回は、諸事情によりMicrosoftのAzureを使わないといけなかった。

Azure Functions使えばいいやん？と思うかもしれない。なんだけどこいつは（慣れていない自分にとっては）とても使いづらい。~~AWS Lambdaのマネしてくれればいいだけなのに、どうしてこんなものをマイクロソフトはリリースしたんだ？~~
~~リファレンスやチュートリアルが死ぬほどわかりづらく、すべてのモチベーションを持っていかれたので、~~諦めてAzure VMでサーバー建てて、そこでWebhook受けて返す君を作ることにした。

その際に、Webアプリケーション側でログを取得するだけだと、なんかの拍子にアプリケーションサーバーがエラーで落ちたりしたらログを取りこぼすことになるので、前段のnginx側で、Webhookのログ（JSON）を全部残せるようにした。

![全体.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/74571/77d80234-2df8-bcd3-e1b5-ce55e1a73a66.png)

## nginxでJSONリクエストボディを記録する

デフォルトのLogFormatは

```
    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';
```

このようなもので、POSTした内容は残してくれない。

なので、とりあえずJSONボディを残すために

```conf:/etc/nginx/conf.d/webhook.conf
log_format with_body '$remote_addr - $remote_user [$time_local] "$request" '
                     '$status $body_bytes_sent "$http_referer" '
                     '"$http_user_agent" "$http_x_forwarded_for" "$request_body"';

server {
    listen       443 ssl;
    server_name  ....;
    ssl_certificate /etc/letsencrypt/live/..../fullchain.pem;
    ssl_certificate_key /etc/letsencrypt/live/..../privkey.pem;

    set_real_ip_from   '10.0.0.0/8';
    real_ip_header     X-Forwarded-For;
    proxy_set_header   X-Forwarded-Scheme $http_x_forwarded_proto;
    proxy_set_header   Host $host;
    resolver           127.0.0.11 valid=5s;

    location /webhook {
        if ($request_method !~ ^(POST)$ ) {
            return 405;
        }

        access_log /var/log/nginx/post_webhook.log with_body;
        proxy_pass http://localhost:8080;
    }
}
```

こんな感じで `$request_body` つきのLogFormatを使うようにnginxのconfに書く。（serverやlocationの中にlog_formatディレクティブは書けないっぽく、この位置）

## Filebeatでログファイルの位置をカスタマイズ

Filebeatはデフォルトだと `/var/log/nginx/access.log` を見に行くようになっているので、

```/etc/filebeat/modules.d/nginx.yml
- module: nginx
  # Access logs
  access:
    enabled: true

    var.paths:
      - /var/log/nginx/post_webhook.log
```

こんな感じにする。

## LogstashでJSON文字列を整形する

これが今回のなかで一番ハマった。

nginxで記録したJSONは、エスケープされていて、

`{\x22text\x22:\x22abscd\x22,\x22textFormat\x22:\x22plain\x22,\x22type\x22:\x22message\x22,\x22timestamp\x22:\x222019-10-04T18:35:27.5194926Z\x22,\x22localTimestamp\x22:\x222019-10-05T03:35:27.5194926+09:00\x22,\x22id\x22:\x221570214127504\x22,\x22channelId\x22:\x22msteams\x22,\x22serviceUrl\x22:\x22https://smba.trafficmanager.net/apac/\x22,\x22from\x22:{\x22id\x22:\x2229:1EaRHI2dlI.....WPdO92g\x22,\x22name\x22:\x22\xE5\xB2\xA9\xE6\x9C\xA8 \xE7\xA5\x90\xE8\xBC\x94\x22,\x22aadObjectId\x22:\x22541478d2-6a03-47b3-aeb7-8675cdd45db3\x22},\x22conversation\x22:{\x22conversationType\x22:\x22personal\x22,\x22tenantId\x22:\x2215b67c2a-8e8f-4a5d-8e1d-186e9cf06150\x22,\x22id\x22:\x22a:1bDh2aVy.......j5FUCYYG\x22},\x22recipient\x22:{\x22id\x22:\x2228:d5d5e.....6a6\x22,\x22name\x22:\x22CSE bot\x22},\x22entities\x22:[{\x22locale\x22:\x22ja-JP\x22,\x22country\x22:\x22JP\x22,\x22platform\x22:\x22Mac\x22,\x22type\x22:\x22clientInfo\x22}],\x22channelData\x22:{\x22tenant\x22:{\x22id\x22:\x2215b67c2......06150\x22}},\x22locale\x22:\x22ja-JP\x22}`

こんな感じになっている。JSONとして解釈するには、 `\x22` を `"` に変換（バックスラッシュのエスケープ解除）しないといけない。

https://www.elastic.co/guide/en/logstash/current/filter-plugins.html を見てみた感じ、unescapeするようなフィルタは（多分）ない。

### Rubyフィルタを使ってエスケープ解除する

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/74571/fc104fc4-baf9-82e1-c6db-8a1f7265dc60.png)

Rubyスクリプトを使って自由に変換処理が書けるフィルタがあったので、（パフォーマンス的にどうなの？とは気になりつつも）これを使うことにした。

Pythonだと `.decode("string_escape")` すればいいだけなんだけど、Rubyだとどう書くんだっけ・・・

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/74571/92b081e4-9bb0-3a73-03b6-88c30d92c8bb.png)
https://stackoverflow.com/questions/8639642/best-way-to-escape-and-unescape-strings-in-ruby


うーん、、evalかぁ・・・・、、とりあえず `eval %Q{"#{s}"}` をする処理で一旦やってみることに。

変換処理は [Event API](https://www.elastic.co/guide/en/logstash/current/event-api.html) っていうやつを使って書く。ver 7.3時点だと

* `event.get('[nginx][access][response_body]')` で `[nginx][access][response_body]` に入っているものが読めて、
* `event.set('[nginx][access][raw_response_body]', raw_response)` で `[nginx][access][raw_response_body]` に `raw_response` の値を書き込むことができる

みたいな感じらしい。すっっっごい無理やりだけど、

```
      ruby {
        code => "body = event.get('[nginx][access][request_body]'); raw_body = eval %Q{\"#{body}\"}; event.set('raw_request_body', raw_body)"
        remove_field => "[nginx][access][request_body]"
      }
```

こんなフィルタを書く。

## Elasticsearchは起動するだけでOK

とくに何もやることはなかった。

## できあがり

`http GET http://localhost:9200/_search` してみると...

<img width="1082" alt="貼り付けた画像_2019_10_06_17_29.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/74571/51864e78-ed36-f944-c0e4-7f05a4447685.png">

こんなかんじで、JSONがパースされてElasticsearchにつっこまれていた。うぇい