LibertyからLogstash CollectorでELKへのログ出力を試す
Libertyのログをjson形式で出力してFilebeatでELKに送る
の続きです。
IBM Cloud PrivateにLibertyアプリケーションをデプロイした場合に、どのようにコンテナのログを収集されるのかを調べたメモです。ICP 2.1.0.3で確認しています。
ICPのログ収集の仕組みの概要
コンテナのログ収集の仕組みをの概要を図示すると次のようになります。
- コンテナが標準出力／標準エラー出力は、Dockerのロギング・ドライバーによって
/var/log/containers/にファイルとして保存される - DaemonSetとして稼働しているFilebeatが
/var/log/containers/*.logを監視し、Logstashに送る - Logstashがデータを加工してElasticsearchに送る
- 管理者はKibanaコンソールからデータを検索
コンテナのログ収集
コンテナの標準出力／標準エラー出力は、Dockerのロギング・ドライバーによってノードの/var/log/containers/ディレクトリーの下に出力されます。
/var/log/containers/hello-758d49f796-g9nm5_ns3_hello-df0feb5068ebfa125cee2582bd8bdbeef33fb30fa78d2fc502bd6b19745a0259.log
ファイル名は<Pod名>_<Namespace名>_<コンテナ名>-<コンテナID>.logとなっています。
コンテナが標準出力に以下のメッセージを出力したとすると、
Hello World!
ノード上のログファイルとしては以下が保存されます（1行で）。
{
"log":"Hello World!",
"stream":"stdout",
"time":"2018-05-31T05:49:56.659607745Z"
}
これはDockerのLogging Driverとしてjson-fileを使っているためです。
[root@myicp01 ~]# docker info|grep "Logging Driver"
WARNING: devicemapper: usage of loopback devices is strongly discouraged for production use.
Use `--storage-opt dm.thinpooldev` to specify a custom block storage device.
Logging Driver: json-file
[root@myicp01 ~]#
（参考）
Dockerのlogging driver: それぞれの特徴と使いどころ(json-file, syslog, journald, fluentd)
ちなみに、Libertyがjson形式でログを出力すると（実際は1行で）、
{
"type": "liberty_message",
"host": "hello-758d49f796-g9nm5",
"ibm_userDir": "/opt/ibm/wlp/usr/",
"ibm_serverName": "defaultServer",
"ibm_datetime": "2018-06-20T08:54:46.617+0000",
"ibm_threadId": "000000fc",
"module": "SystemOut",
"loglevel": "SystemOut",
"ibm_sequence": "1529484886617_000000000001F",
"message": "Hello World!"
}
jsonがjsonのなかに入るので/var/log/containers/hogehoge.logは次のようになります。
{
"log": "{\"type\":\"liberty_message\",\"host\":\"hello-758d49f796-g9nm5\",\"ibm_userDir\":\"\\/opt\\/ibm\\/wlp\\/usr\\/\",\"ibm_serverName\":\"defaultServer\",\"ibm_datetime\":\"2018-06-20T08:54:46.617+0000\",\"ibm_threadId\":\"000000fc\",\"module\":\"SystemOut\",\"loglevel\":\"SystemOut\",\"ibm_sequence\":\"1529484886617_000000000001F\",\"message\":\"Hello World!\"}\n",
"stream": "stdout",
"time": "2018-06-20T08:54:46.618375708Z"
}
Filebeatの動作
Filebeatが/var/log/containers/*.logを監視し、Logstashに送ります。Filebeatから直接Elasticsearchに送ることもできますが、Logstashを経由するようになっています。Filebeatでも簡単な変換処理はできますが、Logstashの方が複雑な処理ができます。
FilebeatはDaemonSetとしてデプロイされています。DaemonSetなので、各ノードに必ず1つFilebeatのPodが稼働します。
[root@myicp01 ~]# kubectl get ds -n kube-system logging-elk-filebeat-ds -o wide
NAME DESIRED CURRENT READY UP-TO-DATE AVAILABLE NODE SELECTOR AGE CONTAINERS IMAGES SELECTOR
logging-elk-filebeat-ds 1 1 1 1 1 <none> 8d filebeat ibmcom/filebeat:5.5.1 app=logging-elk-elasticsearch,component=filebeat-ds,heritage=Tiller,release=logging,role=filebeat
[root@myicp01 ~]#
Filebeatの設定は以下のConfigMapに保管されています。
[root@myicp01 ~]# kubectl get cm -n kube-system logging-elk-filebeat-ds-config -o yaml
apiVersion: v1
data:
filebeat.yml: |-
filebeat.prospectors:
- input_type: log
paths:
- /var/log/containers/*.log
（省略）
filebeat.yml部分を抜き出すと以下です。
filebeat.prospectors:
- input_type: log
paths:
- /var/log/containers/*.log
scan_frequency: 10s
symlinks: true
json.message_key: log
json.keys_under_root: true
json.add_error_key: true
multiline.pattern: '^\s'
multiline.match: after
fields_under_root: true
fields:
type: kube-logs
node.hostname: ${NODE_HOSTNAME}
pod.ip: ${POD_IP}
tags:
- k8s-app
filebeat.config.modules:
# Set to true to enable config reloading
reload.enabled: true
output.logstash:
hosts: logstash:5044
timeout: 15
logging.level: info
input_typeはlogです。
（参考）
Log input
paths:で/var/log/containers/*.logを監視対象に指定しています。
json.message_key: logによってログがjson形式であり、メッセージ本文がlogフィールドに入っていることを指定しています。
fields:でtype: kube-logsなどのフィールドを追加しています。
${NODE_HOSTNAME}と${POD_IP}は、KubernetesによってこのFilebeatのコンテナにセットされている環境変数です。すなわち以下のIPとNODEです。
出力先はlogstashで、ホスト名がlogstashでポートが5044です。SSLは使用していません。
（参考）
Configure the Logstash output
filebeat.ymlで以下の設定を追加してコンソール出力すると、実際にどのような内容が送られるか確認できます。
output.console:
pretty: true
例えば、
{
"log":"Hello World!",
"stream":"stdout",
"time":"2018-05-31T05:49:56.659607745Z"
}
のログは、以下の内容でLogstashに送られます。
※以下はローカルPCでFilebeatとLogstashを動かして確認したログなのでホスト名やファイルパスはICP環境と異なります。
{
"@timestamp": "2018-06-20T09:44:43.575Z",
"beat": {
"hostname": "soto-no-air.hogehoge.com",
"name": "soto-no-air.hogehoge.com",
"version": "5.3.3"
},
"input_type": "log",
"log": "Hello World!",
"node": {
"hostname": "<node_hostname>"
},
"offset": 23978,
"pod": {
"ip": "<pod_ip>"
},
"source": "/var/log/containers/hello-758d49f796-g9nm5_ns3_hello-df0feb5068ebfa125cee2582bd8bdbeef33fb30fa78d2fc502bd6b19745a0259.log",
"stream": "stdout",
"tags": [
"k8s-app"
],
"time": "2018-05-31T05:49:56.659607745Z",
"type": "kube-logs"
}
Logstashの側でも、filterなしで受け取った内容をjsonとしてコンソール出力して確認してみます。
output {
stdout { codec => json }
}
確認すると以下です。hostと@versionフィールド、そしてtagsフィールドのbeats_input_raw_eventが追加となっていて、これらはLogstashが追加しています。
@timestampは同じですが、もしかしたらFilebeatの処理時間からLogstashの処理時間に変わっているかもしれませんが未確認。
{
"offset": 23978,
"pod": {
"ip": "<pod_ip>"
},
"log": "Hello World!",
"input_type": "log",
"source": "/var/log/containers/hello-758d49f796-g9nm5_ns3_hello-df0feb5068ebfa125cee2582bd8bdbeef33fb30fa78d2fc502bd6b19745a0259.log",
"type": "kube-logs",
"tags": [
"k8s-app",
"beats_input_raw_event"
],
"node": {
"hostname": "<node_hostname>"
},
"@timestamp": "2018-06-20T09:44:43.575Z",
"stream": "stdout",
"beat": {
"hostname": "soto-no-air.hogehoge.com",
"name": "soto-no-air.hogehoge.com",
"version": "5.3.3"
},
"@version": "1",
"host": "soto-no-air.hogehoge.com",
"time": "2018-05-31T05:49:56.659607745Z"
}
Logstashの動作
LogstashはFilebeatから受け取った内容を少し加工してElasticsearchに送ります。
LogstashはDeploymentとしてデプロイされています。Managementノードにデプロイされます。Managementノードが複数でもレプリカ数は1です。
[root@myicp01 ~]# kubectl get deploy -n kube-system -o wide logging-elk-logstash
NAME DESIRED CURRENT UP-TO-DATE AVAILABLE AGE CONTAINERS IMAGES SELECTOR
logging-elk-logstash 1 1 1 1 8d logstash ibmcom/logstash:5.5.1 app=logging-elk-elasticsearch,component=logstash,heritage=Tiller,release=logging,role=logstash
[root@myicp01 ~]#
設定はConfigMapに保管されています。
[root@myicp01 ~]# kubectl get cm -n kube-system logging-elk-logstash-config -o yaml
apiVersion: v1
data:
k8s.conf: |-
input {
beats {
port => 5044
}
}
（省略）
Logstashの設定ファイル部分は以下です。コメントで補足説明を加えました。
input {
# Filebeatから入力
beats {
port => 5044
# SSLは使用していない
}
}
filter {
# if文により、type: kube-logsである場合のみ処理
# このフィールドはFilebeatが付けている
if [type] == "kube-logs" {
# mutate filterは基本的なフィールドの操作を行う汎用的なフィルター
mutate {
# messageフィールドをlogフィールドにリネーム
# （しかしmessageフィールドはないので何のためか不明）
rename => { "message" => "log" }
# hostフィールドを削除
# このフィールドはLogstashが追加したフィールド
remove_field => ["host"]
}
# date filterは日付文字列を扱う
date {
# timeフィールドをISO8601形式で時刻としてマッチング
# targetが指定されていないので、結果は@timestampフィールドにセットされる
match => ["time", "ISO8601"]
}
# Sample:
# tiller-1279707952-sgd08_kube-system_tiller-0c51282d195d1c21307f6a48b9118d690441cda498fc5a2790c043407eab235b.log
# filebeat-j357d_default_filebeat-1a3113e374ad7937a3efa36c4bb42b46b976bcd7cd96223e6b9e6e3df08d802a.log
# appstdoutpod_default_app-stdout-container-01c2e7a7b105d9141825ea3ae5634b580fdd20a5a4ee890cdbe0816ca002623c.log
# unified-router-4047118581-sm913_kube-system_unified-router-ddda8a8cbcb74c45b64a4b18997b4f2928c998a37e45037cd0304eaa56d1634f.log
# dissect filterは文字列の分割に使える
dissect {
# sourceフィールドから一部を切り出して
# kubernetes.pod
# kubernetes.namespace
# container_file_ext
# にマッピング
mapping => {
"source" => "/var/log/containers/%{kubernetes.pod}_%{kubernetes.namespace}_%{container_file_ext}"
}
}
dissect {
# container_file_extからcontainerを切りだす
# file_extの?はskipしてフィールドにはセットしないことを意味する
mapping => {
"container_file_ext" => "%{container}.%{?file_ext}"
}
# hostとcontainer_file_extフィールドを削除
# （hostは上の方でも削除しているのでなぜもう一度削除するのか不明）
remove_field => ["host", "container_file_ext"]
}
# grok filterはパターンを指定して文字列をフィールドに分割する
grok {
# containerから
# kubernetes.container_name
# kubernetes.container_id
# を取り出している
"match" => {
"container" => "^%{DATA:kubernetes.container_name}-(?<kubernetes.container_id>[0-9A-Za-z]{64,64})"
}
remove_field => ["container"]
}
}
}
# type: kube-logsでない場合も処理対象
filter {
# Drop empty lines
# 空行をドロップする
if [log] =~ /^\s*$/ {
drop { }
}
# Attempt to parse JSON, but ignore failures and pass entries on as-is
# logフィールドについて、JSONとしてパースを試みる
# Libertyのログをjsonで出力した場合はここでパースされる
# パースできなかったらスキップしてそのまま次に渡す
json {
source => "log"
skip_on_invalid_json => true
}
}
output {
# Elastcisearch出力プラグイン
elasticsearch {
hosts => "elasticsearch:9200"
# indexの名前を指定しているがデフォルト値と同じ指定
index => "logstash-%{+YYYY.MM.dd}"
document_type => "%{[@metadata][type]}"
}
}
いろいろやっていますが、つまり、以下のことをやっています。
-
timeフィールドを@timestampフィールドにセットする - ログファイル名から以下の情報を切り出して追加する
{
"kubernetes.pod": "hello-758d49f796-g9nm5",
"kubernetes.namespace": "ns3",
"kubernetes.container_name": "hello",
"kubernetes.container_id": "df0feb5068ebfa125cee2582bd8bdbeef33fb30fa78d2fc502bd6b19745a0259"
}
- logがjsonの場合はパースする
- 空行は削除
以上がLogstashがElasticsearchに送るまでの設定内容です。
フィルター後のデータ全体をICP実機で確認したところ以下となっていました。
{
"offset": 6275,
"pod": {
"ip": "10.1.170.243"
},
"log": "Hello World!",
"kubernetes.pod": "hello-5564fcdfc6-v2n72",
"kubernetes.container_name": "hello",
"input_type": "log",
"source": "/var/log/containers/hello-5564fcdfc6-v2n72_ns3_hello-32ee39e2d8d4dec3e65964b9f579456269bf97e8a4d742ccd65fb906e33363c6.log",
"type": "kube-logs",
"tags": [
"k8s-app",
"beats_input_raw_event"
],
"kubernetes.container_id": "32ee39e2d8d4dec3e65964b9f579456269bf97e8a4d742ccd65fb906e33363c6",
"node": {
"hostname": "172.30.1.224"
},
"@timestamp": "2018-07-23T07:16:54.353Z",
"stream": "stdout",
"kubernetes.namespace": "ns3",
"beat": {
"hostname": "logging-elk-filebeat-ds-ln2gp",
"name": "logging-elk-filebeat-ds-ln2gp",
"version": "5.5.1"
},
"@version": "1",
"time": "2018-07-23T07:16:54.353021511Z"
}