nginxのログをjsonでStackdriver Loggingに送る

Stackdriver Loggingは構造化ロギングをサポートしており、jsonPayloadの特定フィールドに構造を追加できる。
refs: https://cloud.google.com/logging/docs/structured-logging?hl=ja

GKEからStackdriver Loggingに送る場合、ロギングを有効化しているとDaemonsetのFluentdがstackdriverに送ってくれるけど、こいつは例に載っているようなparserを自由にかけるわけではない。なので、nginxの出力そのものを構造化ロギングに対応させておく必要がある。

自分の場合、各サービスのnginxには以下のような設定を書いている。

      log_format stackdriver escape=json '{"severity":"INFO",'
        '"timestamp":"$time_iso8601",'
        '"httpRequest":{'
          '"requestMethod":"$request_method",'
          '"requestUrl":"$request_uri",'
          '"requestSize":$request_length,'
          '"status":$status,'
          '"responseSize":$bytes_sent,'
          '"userAgent":"$http_user_agent",'
          '"remoteIp":"$remote_addr",'
          '"serverIp":"$server_addr",'
          '"referer":"$http_referer",'
          '"latency":"${request_time}s",'
          '"protocol":"$server_protocol"'
        '},'
        '"uri":"$uri",'
        '"queryString":"$query_string",'
        '"upstreamResponseTime":"${upstream_response_time}s",'
        '"forwardedFor":"$http_x_forwarded_for",'
        '"requestId":"$sent_http_x_request_id",'
        '"userId":"$sent_http_x_user_id",'
        '"pod":"$hostname",'
        '"host":"$http_host"}';
      access_log /dev/stdout stackdriver;

上記の設定でハマりがちなのはlatencyの部分を "${request_time}s" といった表記にしないといけないところ。これはstackdriverの仕様としてsecondsの意味のsを付ける必要があるため。

あとはアプリ側でuser_idをresponse headerで返すようにして、userIdとしてログに載せるようにしている。この辺は問い合わせが来たときにどういう経路で何をしたのかを探るときに使ったりする。

上記の設定で以下のような感じで見れる。

f:id:husq:20191219224624p:plain

生のnginxログでも一応拾えるのは拾えるが検索フィルタもまともに使えないので構造化しておくと色々と便利。デフォルトでは以下のようなクエリを使っている。

resource.type="k8s_container"
resource.labels.project_id="project-id"
resource.labels.location="region"
resource.labels.cluster_name="cluster-name"
resource.labels.namespace_name="ingress"
labels.k8s-pod/app="nginx-ingress"
labels.k8s-pod/component="controller"
labels.k8s-pod/release="prod-nginx"
httpRequest.status!=318

自分のクラスタの場合、1つのnginx-ingress-controllerを経由して各サービスのnginx->appという経路でアクセスしに行くため、 nginx-ingress-controllerのログを表示しておくだけでクラスタ全体のアクセスログが見れる。 nginx-ingress-controller側のアクセスログを上のstackdriverフォーマットにするために以下のようなvalues.yamlを定義している。

controller:
  config:
    log-format-upstream: '{"serverity":"INFO","timestamp":"$time_iso8601","requestId":"$sent_http_x_request_id","userId":"$sent_http_x_user_id","forwardedFor":"$proxy_add_x_forwarded_for","host":"$host","uri":"$uri","requestQuery":"$query_string","cacheStatus":"$sent_http_x_cache_status","httpRequest":{"requestMethod":"$request_method","requestUrl":"$request_uri","requestSize":$request_length,"status":$status,"responseSize":$bytes_sent,"userAgent":"$http_user_agent","remoteIp":"$remote_addr","serverIp":"$server_addr","referer":"$http_referer","latency":"${request_time}s","protocol":"$server_protocol"}}'

またbotのcralwer対策として、318のstatus codeを返すようにしている*1のでそういったアクセスは httpRequest.status!=318 でフィルタされる。 botの判定は気まぐれに手動でやっていて、大体はモーダルに対して新規リンクを求めてRails側でActonViewの例外が発生し、sentryに通知が来たのをトリガーにbotフィルターを追加している。

    if ($http_user_agent ~* (360spider)) {
      return 318;
    }
    if ($http_user_agent ~* (MJ12bot)) {
      return 318;
    }
    if ($http_user_agent ~* (bingbot)) {
      return 318;
    }
    if ($http_user_agent ~* (SemrushBot)) {
      return 318;
    }
    if ($http_user_agent ~* (AhrefsBot)) {
      return 318;
    }
    if ($http_user_agent ~* (YandexBot)) {
      return 318;
    }
    if ($http_user_agent ~* (DotBot)) {
      return 318;
    }
    if ($http_user_agent ~* (BLEXBot)) {
      return 318;
    }

robots.txtでGoogleのbot以外は拒否しているので、それでもアクセスが来る行儀の悪いcrawler対策として記述している。 GKE+helmで管理しているが、各サービスの使い回す設定部分はvalues.yamlに記載しておき、それを各所で呼ぶ出す方式をとっているので、values.yamlのbotフィルターを追加してサービスをデプロイすると各サービスでフィルターが有効化されるような構成になっている。

# values.yaml
  blockBotConf: |-
    if ($http_user_agent ~* (360spider)) {
      return 318;
    }
---
# service-a-configmap.yaml
  nginx.conf: |
    server {
      ...
      access_log /dev/stdout stackdriver;
      ...
{{ .Values.nginx.blockBotConf | indent 6 }}
      ...

stackdriverの書式等も同じ方法で管理しているため、formatを全部のサービスで共通化しやすくていい感じに管理できる。
ログが整ってないと問題が起きたときに辛いことが多いので、あんまり使わなくてもとりあえず揃えておくのが良いなーと思う。

*1:最初は418のI'm a teapotを返していたが、grafanaの集計でエラーレートが高まってしまうので318にした

839の日記

趣味の話を書くブログです。

nginxのログをjsonでStackdriver Loggingに送る