概要
CoreOS 上の全てのログをリモートサーバへ送る を応用し、systemd で起動した Docker コンテナのログをリモートサーバへ送る。 systemd で Docker コンテナを起動しておけば journalctl でログが取得でき、さらに systemd の unit のグルーピング(bind)機能を使ってログルーティングプロセスをバインドする。これは "coprocess" や "sidekick" というらしい。
ログの収集
コンテナのログ収集は systemctl を使ってコンテナを起動するだけでよい。そうすれば journalctl
でログを見る事が出来るようになる
# /etc/systemd/system/hello.service
[Unit]
Description=Hello
After=hello.service
Requires=docker.service
[Service]
TimeoutStartSec=0
ExecStartPre=-/usr/bin/docker kill hello
ExecStartPre=-/usr/bin/docker rm hello
ExecStartPre=/usr/bin/docker pull busybox
ExecStart=/usr/bin/docker run -name hello busybox /bin/sh -c "while true; do echo hello world; sleep 1; done"
[Install]
WantedBy=multi-user.target
ポイントとしては -d
を付けずに docker run
コマンドの標準出力にコンテナのログを出力させること
core@core-01 ~ $ sudo systemctl enable /etc/systemd/system/hello.service
Created symlink from /etc/systemd/system/multi-user.target.wants/hello.service to /etc/systemd/system/hello.service.
core@core-01 ~ $ sudo systemctl start hello.service
docker logs
コマンドでログを見てみる
core@core-01 ~ $ docker logs -f hello
hello world
hello world
hello world
hello world
hello world
journalctl
でログを見てみる(hello world しか出てないが、ここは CoreOS 上の全てのログが出てくる)
core@core-01 ~ $ journalctl -f
-- Logs begin at Mon 2014-09-08 15:37:51 JST. --
Sep 08 21:31:59 core-01 docker[2164]: hello world
Sep 08 21:32:00 core-01 docker[2164]: hello world
Sep 08 21:32:01 core-01 docker[2164]: hello world
Sep 08 21:32:02 core-01 docker[2164]: hello world
Sep 08 21:32:03 core-01 docker[2164]: hello world
Sep 08 21:32:04 core-01 docker[2164]: hello world
あらゆるログが出るので漏れはないのだが、どのログがどのコンテナのものか、というのが非常に分かりにくい。 hello.service のログだけ見てみる
core@core-01 ~ $ journalctl -f -u hello.service
-- Logs begin at Mon 2014-09-08 15:37:51 JST. --
Sep 08 21:24:04 core-01 docker[2164]: hello world
Sep 08 21:24:05 core-01 docker[2164]: hello world
Sep 08 21:24:06 core-01 docker[2164]: hello world
Sep 08 21:24:07 core-01 docker[2164]: hello world
Sep 08 21:24:08 core-01 docker[2164]: hello world
Sep 08 21:24:09 core-01 docker[2164]: hello world
Sep 08 21:24:10 core-01 docker[2164]: hello world
集約したログのルーティング
CoreOS 上の全てのログをリモートサーバへ送る を応用し、 Docker コンテナのログをリモートサーバへ送る。
- 起動したいコンテナ
hello.service
に加え
- ログルーティング用 unit
hello.journal-router.service
を起動することで実現する。
# /etc/systemd/system/hello.service
[Unit]
Description=Hello
Requires=docker.service
After=docker.service
Wants=hello.journal-router.service
Before=hello.journal-router.service
[Service]
TimeoutStartSec=0
ExecStartPre=-/usr/bin/docker kill hello
ExecStartPre=-/usr/bin/docker rm hello
ExecStartPre=/usr/bin/docker pull busybox
ExecStart=/usr/bin/docker run -name hello busybox /bin/sh -c "while true; do echo hello world; sleep 1; done"
[Install]
WantedBy=multi-user.target
# /etc/systemd/system/hello.journal-router.service
[Unit]
Description=Journal Router for Hello
Requires=hello.service
After=hello.service
BindsTo=hello.service
[Service]
TimeoutStartSec=0
ExecStart=/bin/sh -c '/usr/bin/journalctl -o short -u hello.service -f | sed \"s/^/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx \\0/g\" | ncat data.logentries.com 10000'
[Install]
WantedBy=multi-user.target
ポイント
-
hello.service
はhello.journal-router.service
をログルーター役として必要としているのでWants=hello.journal-router.service
としている -
hello.service
をhello.journal-router.service
が起動する前に起動したいのでBefore=hello.journal-router.service
としている -
hello.journal-router.service
はhello.service
のために起動しているのでhello.service
が終了したときは一緒に終了したいので、BindsTo=hello.service
としている
hello.service
unit を起動してみる
core@core-02 ~ $ sudo systemctl enable /etc/systemd/system/hello.service
core@core-02 ~ $ sudo systemctl enable /etc/systemd/system/hello.journal-router.service
core@core-02 ~ $ sudo systemctl start hello.service
すると、hello.service
起動後に hello.journal-router.service
も systemd によって起動される。また hello.service
を止めると hello.journal-router.service
も止まる。
このやり方の問題点
新規に追加したいコンテナの unit file を書く際にログ収集用 unit についても気にする必要があること。コンテナを起動すれば勝手にログについてはハンドリングしてくれている方が楽だ。この話は Automatic Docker Service Announcement with Registrator の "The Problem with a Coprocess for Registering" の段落で説明されている。
ただ、 journalctl を json フォーマットで出力すると、このログがどのコンテナのものかわかるので、json を human readable に直して送るならば、CoreOS 上の全てのログをリモートサーバへ送る のようにするだけで Docker のログ管理は完結する。
json output を jq で整形したのちルーティングする
- どのコンテナのログ
- human readable なフォーマット
- 起動したいアプリケーションコンテナはログのことは気にしなくてよい("sidekick" アプローチを取らない
を実現したい。journalctl
の json output からは
{
"__CURSOR" : "s=78035e49faa2491e8dedcb38fc1b5c5e;i=4eb;b=a48ed2e1bee74f18a171e8ac4b8dea9e;m=13e50316;t=502b24b3c9e12;x=96f3d2082539aec9",
"__REALTIME_TIMESTAMP" : "1410339673251346",
"__MONOTONIC_TIMESTAMP" : "333775638",
"_BOOT_ID" : "a48ed2e1bee74f18a171e8ac4b8dea9e",
"PRIORITY" : "6",
"_UID" : "0",
"_GID" : "0",
"_SYSTEMD_SLICE" : "system.slice",
"SYSLOG_FACILITY" : "3",
"_CAP_EFFECTIVE" : "1fffffffff",
"_TRANSPORT" : "stdout",
"_MACHINE_ID" : "ce5fac63ce624124a15ea8a52e838b17",
"_HOSTNAME" : "core-02",
"SYSLOG_IDENTIFIER" : "docker",
"_COMM" : "docker",
"_EXE" : "/usr/bin/docker",
"_SYSTEMD_UNIT" : "dd-agent.service",
"_PID" : "1075",
"_CMDLINE" : "/usr/bin/docker run --privileged --name dd-agent -h core-02 -v /var/run/docker.sock:/var/run/docker.sock -v /proc/mounts:/host/proc/mounts:ro -v /sys/fs/cgroup/:/host/sys/fs/cgroup:ro -e API_KEY=xxxxxxxxxxxxxxxxx datadog/docker-dd-agent",
"_SYSTEMD_CGROUP" : "/system.slice/dd-agent.service",
"MESSAGE" : "2014-09-10 09:01:13,250 CRIT Server 'unix_http_server' running without any HTTP authentication checking"
}
のように、
- ログメッセージ
- ホスト
- コンテナ(unit)
が取得できるので、あまり綺麗ではないが、以下のように jq を使って必要な情報だけ抜き出した後にルーティングすることでいける。
core@core-01 ~ $ journalctl -f -l -o json | \
jq '._HOSTNAME + " " + ._SYSTEMD_UNIT + ": " + .MESSAGE' -c | \
sed -e "s/^\"*\"$/\0/" | \
sed -e "s/^/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx \0/g" | \
ncat data.logentries.com 10000
これで以下のようなログをルーティングできる。(xxxxxxxx
みたいな部分は token)
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx core-01 registry.service: 2014-09-12 06:54:28,697 INFO: Boto based storage initialized
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx core-01 registry.service: 2014-09-12 06:54:29 [1] [INFO] Starting gunicorn 18.0
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx core-01 registry.service: 2014-09-12 06:54:29 [1] [INFO] Listening at: http://0.0.0.0:5000 (1)
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx core-01 registry.service: 2014-09-12 06:54:29 [1] [INFO] Using worker: gevent
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx core-01 registry.service: 2014-09-12 06:54:29 [22] [INFO] Booting worker with pid: 22
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx core-01 registry.service: 2014-09-12 06:54:29 [23] [INFO] Booting worker with pid: 23