ICPインストール時の設定

ICPをインストール時のconfig.yamlファイルに、Ingress Controllerのアクセスログを有効にするかどうかのパラメータがある。デフォルトではアクセスログは出力されない。

## Ingress Controller Settings
## You can add your ingress controller configuration, and the allowed configuration can refer to
## https://github.com/kubernetes/ingress-nginx/blob/nginx-0.9.0/docs/user-guide/configmap.md#configuration-options
# ingress_controller:
#   disable-access-log: 'true'

Ingress ControllerのConfigMapの修正

Nginx Ingress Controllerのカスタマイズは、以下の3箇所で可能。

アノテーション
ConfigMap
Custom template

（参考）
NGINX Configuration

アクセスログの設定はConfigMapにある。ICP v2.1.0.3では上の記事とはConfigMapの名前が異なる。

kubectl editコマンドによる編集

kubectl edit cm nginx-ingress-controller -n kube-system

apiVersion: v1
data:
  disable-access-log: "false" # trueからfalseに変更 
  keep-alive-requests: "10000"
  upstream-keepalive-connections: "64"
kind: ConfigMap
metadata:
  creationTimestamp: null
  name: nginx-ingress-controller
  selfLink: /api/v1/namespaces/kube-system/configmaps/nginx-ingress-controller

kubectl patchコマンドの場合

editコマンドではなくpatchコマンドを使う場合は以下のようにする。

patch-nginx-ingress.yaml

data:
  disable-access-log: "false"

kubectl patch cm nginx-ingress-controller -n kube-system --patch "$(cat patch-nginx-ingress.yaml)"

（参考）helm upgrade

ConfigMapを直接修正するのではなく、helmリリースをupgradeすることも可能。

ただし、ICPが使っているチャートがstable/nginx-ingressからダウンロードできるチャートとは異なるようなので、注意が必要。同じバージョンでも中身が違う。

そのため、ICPのインストーラーイメージからHelmチャートを取得するようにすること。

現在のvaluesをファイルに保存。

helm ls nginx-ingress --tls
helm get values nginx-ingress --tls > values.yaml
cp values.yaml values.yaml.bk

values.yamlを修正。

# diff values.yaml.bk values.yaml
6c6
<     disable-access-log: "true"
---
>     disable-access-log: "false"
#

helm upgradeを実行する。

helm upgrade nginx-ingress nginx-ingress-0.13.0.tgz \
  --version 0.13.0 \
  --values values.yaml \
  --tls

Logstashでのアクセスログの分離

IBM Cloud Privateが集めたコンテナログをLogstashでファイルに保存する

上記のような対応をしている前提で、Ingressのログだけを別ファイルにする。

kubectl edit cm logging-elk-logstash-config -n kube-system


...

    output {
      elasticsearch {
        hosts => "elasticsearch:9200"
        index => "logstash-%{+YYYY.MM.dd}"
        document_type => "%{[@metadata][type]}"
      }
      # 追加ここから
      if [kubernetes.pod] =~ /^nginx-ingress-controller-.*/ {
        file {
          path => "/log/%{kubernetes.pod}-%{+YYYYMMdd}.log"
          codec => line { format => "%{log}" }
        }
      } else {
        file {
          path => "/log/%{kubernetes.namespace}-%{+YYYYMMdd}.log"
          codec => line { format => "%{time} %{kubernetes.pod} %{log}" }
        }
      }
      # 追加ここまで
    }

...

ログ出力確認

ログ出力を確認する。

root@myicp01:/export/logstash# ls -l
total 1748
-rw-r--r-- 1 ubuntu ubuntu 1784199 Jul 19 07:34 kube-system-20180719.log
-rw-r--r-- 1 ubuntu ubuntu    1381 Jul 19 07:29 nginx-ingress-controller-g9r9x-20180719.log
root@myicp01:/export/logstash#

root@myicp01:/export/logstash# tail kube-system-20180719.log
2018-07-19T07:35:55.943989296Z calico-node-kkvqg 2018-07-19 07:35:55.943 [INFO][102] ipsets.go 295: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=913.287μs
2018-07-19T07:35:55.94401942Z calico-node-kkvqg 2018-07-19 07:35:55.943 [INFO][102] int_dataplane.go 704: Finished applying updates to dataplane. msecToApply=1.0629229999999998
2018-07-19T07:35:55.822582571Z k8s-master-172.30.1.224 I0719 07:35:55.822478       1 wrap.go:42] GET /apis/admissionregistration.k8s.io/v1alpha1/initializerconfigurations: (882.706μs) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c] 127.0.0.1:42346]
2018-07-19T07:35:56.443222841Z k8s-master-172.30.1.224 I0719 07:35:56.443126       1 wrap.go:42] GET /api/v1/namespaces/kube-system/endpoints/kube-controller-manager: (1.044882ms) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c/leader-election] 127.0.0.1:42088]
2018-07-19T07:35:56.445099146Z k8s-master-172.30.1.224 I0719 07:35:56.444870       1 wrap.go:42] PUT /api/v1/namespaces/kube-system/endpoints/kube-controller-manager: (1.271066ms) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c/leader-election] 127.0.0.1:42088]
2018-07-19T07:35:56.450603528Z k8s-master-172.30.1.224 I0719 07:35:56.450531       1 wrap.go:42] GET /api/v1/namespaces/kube-system/endpoints/kube-scheduler: (2.86802ms) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c/leader-election] 127.0.0.1:42090]
2018-07-19T07:35:56.452301191Z k8s-master-172.30.1.224 I0719 07:35:56.452196       1 wrap.go:42] PUT /api/v1/namespaces/kube-system/endpoints/kube-scheduler: (1.246054ms) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c/leader-election] 127.0.0.1:42090]
2018-07-19T07:35:56.824012624Z k8s-master-172.30.1.224 I0719 07:35:56.823917       1 wrap.go:42] GET /apis/admissionregistration.k8s.io/v1alpha1/initializerconfigurations: (870.631μs) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c] 127.0.0.1:42346]
2018-07-19T07:35:56.864785061Z k8s-master-172.30.1.224 I0719 07:35:56.864709       1 wrap.go:42] GET /api/v1/nodes/172.30.1.224?resourceVersion=0&timeout=10s: (594.008μs) 200 [[hyperkube/v1.10.0+icp (linux/amd64) kubernetes/1c6988c] 172.30.1.224:46030]
2018-07-19T07:35:50.851399046Z service-catalog-apiserver-27wh6 I0719 07:35:50.850618       1 wrap.go:42] GET /: (1.06961ms) 403 [[Go-http-client/2.0] 172.30.1.224:51640]
root@myicp01:/export/logstash#

root@myicp01:/export/logstash# tail nginx-ingress-controller-g9r9x-20180719.log
2018/07/19 07:29:02 [notice] 1690#1690: *26 "/hellomysql/(.*)" matches "/hellomysql/hellomysql/HelloServlet", client: 127.0.0.1, server: _, request: "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0", host: "mycluster.icp"
2018/07/19 07:29:02 [notice] 1690#1690: *26 rewritten data: "/hellomysql/HelloServlet", args: "", client: 127.0.0.1, server: _, request: "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0", host: "mycluster.icp"
127.0.0.1 - [127.0.0.1] - - [19/Jul/2018:07:29:02 +0000] "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0" 200 59 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:52.0) Gecko/20100101 Firefox/52.0" 233 0.005 [ns3-hellomysql-9080] 10.1.170.223:9080 45 0.004 200
2018/07/19 07:29:05 [notice] 1690#1690: *26 "/hellomysql/(.*)" matches "/hellomysql/hellomysql/HelloServlet", client: 127.0.0.1, server: _, request: "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0", host: "mycluster.icp"
2018/07/19 07:29:05 [notice] 1690#1690: *26 rewritten data: "/hellomysql/HelloServlet", args: "", client: 127.0.0.1, server: _, request: "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0", host: "mycluster.icp"
127.0.0.1 - [127.0.0.1] - - [19/Jul/2018:07:29:05 +0000] "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0" 200 59 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:52.0) Gecko/20100101 Firefox/52.0" 45 0.005 [ns3-hellomysql-9080] 10.1.170.223:9080 45 0.004 200
root@myicp01:/export/logstash#

アクセスログと普通のログが混ざっているので、アクセスログだけにするにはもう少し工夫が必要。

リモートのIPがとれておらず、127.0.0.1になってしまっているが、ConfigMapのforwarded-for-headerパラメータのデフォルト値がX-Forwarded-Forとなっており、X-Forwarded-ForヘッダをクライアントIPとして使用するようになっているので、ICPの前にBig-IP等がいる場合は、このヘッダを送ればよい。

試しにcurlでヘッダを送ってみると、X-Forwarded-Forで送ったIPアドレスがログに記録されることが確認できる。

（curlコマンド）

curl -H 'X-Forwarded-For:192.168.100.100' -k https://mycluster.icp/hellomysql/hellomysql/HelloServlet

（ログ出力内容）

192.168.100.100 - [192.168.100.100] - - [31/Jul/2018:12:14:11 +0000] "GET /hellomysql/hellomysql/HelloServlet HTTP/2.0" 200 34 "-" "curl/7.54.0" 82 0.005 [ns3-hellomysql-9080] 10.1.170.221:9080 45 0.008 200

ログフォーマットをカスタマイズしたい場合はConfigMapのlog-format-upstreamパラメータでカスタマイズできそう。デフォルトは以下となっている。

%v - [$the_real_ip] - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" $request_length $request_time [$proxy_upstream_name] $upstream_addr $upstream_response_length $upstream_response_time $upstream_status

参考リンク

Logstashで内容ごとに送信先を複数に振り分ける設定