2019-01-02

Dockerコンテナ上で、ログファイルにしかログを書かないソフトウェアに標準出力・標準エラー出力を使わせるようにする

Docker Linux

Dockerのログまわりのドキュメントを読んでいて、ちょっと気になったところがありまして。

View logs for a container or service | Docker Documentation

The official nginx image creates a symbolic link from /var/log/nginx/access.log to /dev/stdout, and creates another symbolic link from /var/log/nginx/error.log to /dev/stderr, overwriting the log files and causing logs to be sent to the relevant special device instead. See the Dockerfile.

「docker container logs」で表示可能にできるようなコンテナ上で動作するプロセスが出力する内容は、標準出力、または
標準エラー出力にその内容を書き出す必要があります。

このため、たとえばApacheのオフィシャルイメージの場合、Apacheのプロセスをフォアグラウンドで実行するようにして
回避しています。

DockerHub / httpd

https://github.com/docker-library/httpd/blob/a426e299988c48f4937dfb4a9a67ac479ca011e1/2.4/Dockerfile#L148

CMD ["httpd-foreground"]

https://github.com/docker-library/httpd/blob/a426e299988c48f4937dfb4a9a67ac479ca011e1/2.4/httpd-foreground#L7

exec httpd -DFOREGROUND

Nginxの場合はこのような回避策がないため、アクセスログおよびエラーログのファイルを、それぞれ標準出力（/dev/stdout）、
標準エラー出力（/dev/stderr）のシンボリックリンクとして作成することで、回避しているようです。

https://github.com/nginxinc/docker-nginx/blob/8921999083def7ba43a06fabd5f80e4406651353/mainline/jessie/Dockerfile#L21-L23

# forward request and error logs to docker log collector
RUN ln -sf /dev/stdout /var/log/nginx/access.log \
    && ln -sf /dev/stderr /var/log/nginx/error.log

なるほど、覚えておきましょう。

というわけで、ちょっと試してみます。

Apache Tomcatを題材にして、こんなDockerfileを用意。
Dockerfile

FROM openjdk:8

RUN apt-get update -y && \
    apt-get install -y wget sudo && \
    apt-get clean && \
    cd /opt && \
    wget -q https://www-us.apache.org/dist/tomcat/tomcat-9/v9.0.14/bin/apache-tomcat-9.0.14.tar.gz && \
    tar xf apache-tomcat-9.0.14.tar.gz && \
    rm apache-tomcat-9.0.14.tar.gz && \
    mv apache-tomcat-9.0.14 apache-tomcat && \
    ln -sf /dev/stdout /opt/apache-tomcat/logs/catalina.out

ENTRYPOINT /opt/apache-tomcat/bin/startup.sh && sleep 120

catalina.outを、/dev/stdoutのリンクにしています。

    ln -sf /dev/stdout /opt/apache-tomcat/logs/catalina.out

起動はstartup.shで、ですが、そのままだと終了してしまうのでsleepを…。

ENTRYPOINT /opt/apache-tomcat/bin/startup.sh && sleep 120

ちなみに、Apache Tomcatのオフィシャルイメージでは、こんなことをせずにcatalina.shを実行しています。

https://github.com/docker-library/tomcat/blob/f58a6b4236cfe10672c9505aab5024100c9e084d/9.0/jre8/Dockerfile#L167

CMD ["catalina.sh", "run"]

これで、ログの内容が標準出力に書き出されます。

…話を戻して、Dockerイメージをビルド。

$ docker build -t kazuhira/tomcat:9 .

起動。

$ docker container run --rm --name tomcat kazuhira/tomcat:9

すると、catalina.outに出力される内容がずらずらと標準出力に現れます。

Tomcat started.
02-Jan-2019 08:27:06.576 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.14
02-Jan-2019 08:27:06.577 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Dec 6 2018 21:13:53 UTC
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.14.0
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.15.0-43-generic
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-8-openjdk-amd64/jre
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_181-8u181-b13-2~deb9u1-b13
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /opt/apache-tomcat
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /opt/apache-tomcat
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/opt/apache-tomcat/conf/logging.properties
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
02-Jan-2019 08:27:06.579 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
02-Jan-2019 08:27:06.580 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/opt/apache-tomcat
02-Jan-2019 08:27:06.580 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/opt/apache-tomcat
02-Jan-2019 08:27:06.580 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/opt/apache-tomcat/temp
02-Jan-2019 08:27:06.580 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib]
02-Jan-2019 08:27:06.659 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
02-Jan-2019 08:27:06.715 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
02-Jan-2019 08:27:06.717 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [438] milliseconds
02-Jan-2019 08:27:06.742 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]

〜省略〜

「docker container logs」でも、確認することができます。

$ docker logs tomcat | head -n 10
Tomcat started.
02-Jan-2019 08:27:06.576 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.14
02-Jan-2019 08:27:06.577 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Dec 6 2018 21:13:53 UTC
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.14.0
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.15.0-43-generic
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-8-openjdk-amd64/jre
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_181-8u181-b13-2~deb9u1-b13
02-Jan-2019 08:27:06.578 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation

なお、先ほどのDockerfileのシンボリックリンクを作成している箇所をコメントアウトしてビルドして

    mv apache-tomcat-9.0.14 apache-tomcat
#    ln -sf /dev/stdout /opt/apache-tomcat/logs/catalina.out

起動すると、ログは以下の1行だけになります。

$ docker container run --rm --name tomcat kazuhira/tomcat:9
Tomcat started.

というわけで、catalina.outの内容を標準出力に書き出すことができるようになったことが、確認できました、と。

気になること

シンボリックリンクにしたファイルに書き出すのは、ログインユーザーと実行ユーザーが異なると、うまくいかないようですね？

シンボリックリンクの作成をDockerfile内で作成した別ユーザーで行い、かつ起動も別ユーザーですると、こんな感じに…。

touch: cannot touch '/opt/apache-tomcat/logs/catalina.out': Permission denied
Tomcat started.
/opt/apache-tomcat/bin/catalina.sh: 1: eval: cannot create /opt/apache-tomcat/logs/catalina.out: Permission denied

この時のDockerfile。tomcatというユーザーを作成し、sudoで一時的にユーザーを変更して実行しています。

FROM openjdk:8

RUN adduser --disabled-login --gecos '' tomcat

RUN apt-get update -y && \
    apt-get install -y wget sudo && \
    apt-get clean && \
    cd /opt && \
    wget -q https://www-us.apache.org/dist/tomcat/tomcat-9/v9.0.14/bin/apache-tomcat-9.0.14.tar.gz && \
    tar xf apache-tomcat-9.0.14.tar.gz && \
    rm apache-tomcat-9.0.14.tar.gz && \
    mv apache-tomcat-9.0.14 apache-tomcat && \
    chown -R tomcat.tomcat apache-tomcat && \
    sudo -u tomcat ln -sf /dev/stdout /opt/apache-tomcat/logs/catalina.out

ENTRYPOINT sudo -u tomcat /opt/apache-tomcat/bin/startup.sh && sleep 120

「sudo -u tomcat」で

sudo -u tomcat /opt/apache-tomcat/bin/startup.sh

ちなみに、こうするとうまくいきます。

FROM openjdk:8

RUN adduser --disabled-login --gecos '' tomcat

RUN apt-get update -y && \
    apt-get install -y wget sudo && \
    apt-get clean && \
    cd /opt && \
    wget -q https://www-us.apache.org/dist/tomcat/tomcat-9/v9.0.14/bin/apache-tomcat-9.0.14.tar.gz && \
    tar xf apache-tomcat-9.0.14.tar.gz && \
    rm apache-tomcat-9.0.14.tar.gz && \
    mv apache-tomcat-9.0.14 apache-tomcat && \
    chown -R tomcat.tomcat apache-tomcat && \
    sudo -u tomcat ln -sf /dev/stdout /opt/apache-tomcat/logs/catalina.out

USER tomcat

ENTRYPOINT /opt/apache-tomcat/bin/startup.sh && sleep 120

「USER tomcat」でユーザーを指定するようにしました。

この時の、/dev/stdoutの差。

rootで実行し、sudoで切り替えようとした場合。

# ls -l /dev/stdout
lrwxrwxrwx 1 root root 15 Jan  2 08:45 /dev/stdout -> /proc/self/fd/1

# ls -l /proc/self/fd/1
lrwx------ 1 root root 64 Jan  2 08:45 /proc/self/fd/1 -> /dev/pts/0

「USER tomcat」と指定した場合。

$ ls -l /dev/stdout
lrwxrwxrwx 1 root root 15 Jan  2 08:47 /dev/stdout -> /proc/self/fd/1

$ ls -l /proc/self/fd/1
lrwx------ 1 tomcat tomcat 64 Jan  2 08:47 /proc/self/fd/1 -> /dev/pts/0

1番目のFile Descriptorのオーナーが異なりますね。

参考）

/dev/stderr（/dev/std{in,out}も）は使うべきではない - Qiita

2019-01-02

Docker環境で、コンテナのログをFluentdに出力する（Docker logging driverとして使う）

Docker Fluentd

これは、なにをしたくて書いたもの？

Dockerのログ出力先（logging driver)をFluentdにできると聞いて
1度、自分でも試してみようと

参考）

Docker/Kubernetes 実践コンテナ開発入門

作者:山田明憲
発売日: 2018/08/25
メディア: 単行本（ソフトカバー）

logging driver

Dockerでは、コンテナに出力されたログは「docker logs」コマンドで参照することができます。

View logs for a container or service | Docker Documentation

Configure logging drivers | Docker Documentation

このログの出力先は、logging driverというもので制御されているようです。

logging driverにはいくつか種類があり、デフォルトのlogging driverは「json-file」のようです。これは、ホスト側の
「/var/lib/docker/containers/[コンテナID]/[コンテナID]-json.log」に出力されるものです。

$ docker container run --rm --name httpd httpd:2.4.37

$ docker inspect httpd | grep -i -A 3 Log
        "LogPath": "/var/lib/docker/containers/e01a9083c3a98b48aaeda25292d69ab409b6f5f04e01a9cee31e5549e1a94693/e01a9083c3a98b48aaeda25292d69ab409b6f5f04e01a9cee31e5549e1a94693-json.log",
        "Name": "/httpd",
        "RestartCount": 0,
        "Driver": "overlay2",
--
            "LogConfig": {
                "Type": "json-file",
                "Config": {}
            },

ちなみに、どんな感じでログが入っているのかというと、

$ sudo cat /var/lib/docker/containers/e01a9083c3a98b48aaeda25292d69ab409b6f5f04e01a9cee31e5549e1a94693/e01a9083c3a98b48aaeda25292d69ab409b6f5f04e01a9cee31e5549e1a94693-json.log
{"log":"AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 172.17.0.2. Set the 'ServerName' directive globally to suppress this message\n","stream":"stderr","time":"2019-01-01T15:21:11.353294509Z"}
{"log":"AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 172.17.0.2. Set the 'ServerName' directive globally to suppress this message\n","stream":"stderr","time":"2019-01-01T15:21:11.355605364Z"}
{"log":"[Tue Jan 01 15:21:11.357255 2019] [mpm_event:notice] [pid 1:tid 140069608740032] AH00489: Apache/2.4.37 (Unix) configured -- resuming normal operations\n","stream":"stderr","time":"2019-01-01T15:21:11.357434441Z"}
{"log":"[Tue Jan 01 15:21:11.357493 2019] [core:notice] [pid 1:tid 140069608740032] AH00094: Command line: 'httpd -D FOREGROUND'\n","stream":"stderr","time":"2019-01-01T15:21:11.357602487Z"}

「log」という要素に標準出力なりの内容が全部入っているようですね。標準出力か標準エラー出力かは「stream」を
ログの時間については「time」を見れば良さそうです。

Dockerでサポートされているlogging driverは、ここに一覧があります。

Supported logging drivers

なお、「json-fiile」と「journald」以外のlogging driverを選択した場合は、「docker logs」コマンドは使えなくなるようです。

logging driverを含む、コンテナログの設定は、「docker container run」時にコンテナ単位に設定するか、Linuxの場合であれば
「/etc/docker/daemon.json」でDockerデーモン全体の設定として行うこともできるようです。

Configure the default logging driver

Fluentd logging driver

それで、今回はこのlogging driverをFluentdに変更してみます。

Fluentd logging driverについては、Docker、Fluentd両方にドキュメントがあります。

Fluentd logging driver | Docker Documentation

Docker Logging | Fluentd

このあたりを見ながら、設定していってみましょう。

お題と環境

ApacheのDockerイメージに対してFluentd logging driverを設定し、Fluentdにログを送信してみようと思います。

httpd

Fluentd自体もDockerで立ち上げますが、こちらはコンテナ内に自分でインストールしたものを使用することにします。

また、送信されたApacheのログは、Fluentdのログ（stdout）に出力するものとします。

各種バージョン。

$ docker --version
Docker version 18.09.0, build 4d60db4


$ docker container run --rm --name httpd httpd:2.4.37


2019-01-02 03:17:45 +0000 [info]: gem 'fluentd' version '1.2.6'

各コンテナのIPアドレスは、

Fluentd … 172.17.0.2
Apache … 172.17.0.3

とします。

また、Apacheのイメージはindex.htmlしか入っていないので、ApacheのドキュメントをDocumentRootに設置し、
ドキュメントに対するアクセスログを見ていくことにします。

こんな感じで。

$ wget https://www-eu.apache.org/dist//httpd/docs/httpd-docs-2.4.33.en.zip
$ unzip httpd-docs-2.4.33.en.zip
$ docker container run --rm --name httpd -v `pwd`/httpd-docs-2.4.33.en:/usr/local/apache2/htdocs httpd:2.4.37

この時点では、まだFluentd logging driverは設定していません。

Fluentdの設定

Fluentd側は、ドキュメント側に習ってデフォルトの設定ファイルを編集してこのように設定。

Docker Logging | Fluentd

/etc/td-agent/td-agent.conf

<source>
  @type forward
  @id input_forward
</source>

<match *.**>
  @type stdout
  @id output_stdout
</match>

「@id」は付けておきました。

ドキュメントだとportおよびbindも指定していますが、デフォルト値そのものみたいなので、まあいいかなと。

forward - Fluentd

Apache側

ドキュメントルートにApacheのドキュメントを置きつつ、構築したFluentdに対してlogging driverを設定します。

$ docker container run --rm \
  --name httpd \
  -v `pwd`/httpd-docs-2.4.33.en:/usr/local/apache2/htdocs \
  --log-driver=fluentd \
  --log-opt fluentd-address=tcp://172.17.0.2:24224 \
  --log-opt tag=docker.{{.ImageName}}.{{.Name}}.{{.ID}} \
  httpd:2.4.37

「--log-driver」に「fluentd」を指定し、「--log-opt」でオプションの設定を行います。このあたりの情報は、こちらに
記載があります。

Fluentd logging driver / Options

「fluentd-address」では送信先のFluentdを指定し（デフォルトは「localhost:24224」）、「tag」ではFluentdで使うタグを
指定します（デフォルトでは12文字のコンテナID）。

今回は、タグとして「docker.[イメージ名].[コンテナ名].[コンテナID（12文字）]」を指定しています。指定している
テンプレートの意味は、こちらを参照してください。

Customize log driver output | Docker Documentation

このタグは、Fluentdのタグとして使われます。

確認

では、ファイルを参照して確認してみましょう。

ここは、一気にwgetでミラーしてみます。

$ wget -m -p -r -nH -np 172.17.0.3

Fluentd側には、こんな感じでログ出力されます。

2019-01-02 03:55:42.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"log":"172.17.0.1 - - [02/Jan/2019:03:55:42 +0000] \"GET / HTTP/1.1\" 200 7004","container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34","container_name":"/httpd","source":"stdout"}
2019-01-02 03:55:42.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"container_name":"/httpd","source":"stdout","log":"172.17.0.1 - - [02/Jan/2019:03:55:42 +0000] \"GET /robots.txt HTTP/1.1\" 404 208","container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34"}
2019-01-02 03:55:42.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34","container_name":"/httpd","source":"stdout","log":"172.17.0.1 - - [02/Jan/2019:03:55:42 +0000] \"GET /style/css/manual-zip.css HTTP/1.1\" 200 874"}
2019-01-02 03:55:42.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34","container_name":"/httpd","source":"stdout","log":"172.17.0.1 - - [02/Jan/2019:03:55:42 +0000] \"GET /style/css/manual-zip-100pc.css HTTP/1.1\" 200 885"}
2019-01-02 03:55:42.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"log":"172.17.0.1 - - [02/Jan/2019:03:55:42 +0000] \"GET /style/css/manual-print.css HTTP/1.1\" 200 13200","container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34","container_name":"/httpd","source":"stdout"}
2019-01-02 03:55:42.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34","container_name":"/httpd","source":"stdout","log":"172.17.0.1 - - [02/Jan/2019:03:55:42 +0000] \"GET /style/css/prettify.css HTTP/1.1\" 200 3616"}

含まれる要素は、「log」、「container_name」、「container_name」、「source」のようです。

「source」は、標準出力か標準エラー出力かを表すようですね。

例えば、Apache起動時のログは標準エラー出力に出るようなので、こんな感じになります。

2019-01-02 03:44:54.000000000 +0000 docker.httpd:2.4.37.httpd.76d3304af17a: {"container_id":"76d3304af17a71ce363407f855d544bccab2c0e39142c4be1dc2ba4385304c34","container_name":"/httpd","source":"stderr","log":"[Wed Jan 02 03:44:54.260937 2019] [core:notice] [pid 1:tid 140541962106048] AH00094: Command line: 'httpd -D FOREGROUND'"}

この時、Apache側のコンテナに対して「docker container logs」を実行すると、エラーになります。

$ docker container logs httpd
Error response from daemon: configured logging driver does not support reading

こんな感じで動作確認できました。

また、ログメッセージのJSONをパースするサンプルや、ログメッセージが複数行になっている場合に結合する
サンプルも、こちらのドキュメントに記載があります。

Docker Logging | Fluentd

こんなところで。

CLOVER🍀

That was when it all began.

Dockerコンテナ上で、ログファイルにしかログを書かないソフトウェアに標準出力・標準エラー出力を使わせるようにする

気になること

Docker環境で、コンテナのログをFluentdに出力する（Docker logging driverとして使う）

これは、なにをしたくて書いたもの？

logging driver

Fluentd logging driver

お題と環境

Fluentdの設定

Apache側

確認