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)を全部残せるようにした。

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ボディを残すために

/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フィルタを使ってエスケープ解除する

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

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


https://stackoverflow.com/questions/8639642/best-way-to-escape-and-unescape-strings-in-ruby

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

変換処理は Event API っていうやつを使って書く。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 してみると...

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