Go to Qiita Advent Calendar 2024 Top
LoginSignup
19
14

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 1 year has passed since last update.

@uturned0(Yasunori Kuji)

docker container内で叩いたコマンドを docker log に出力する方法

Last updated at Posted at 2021-07-03

１行で解決

コンテナ内でコレを叩けばいいです

echo 1 > /proc/1/fd/1

やりたかったこと

  • チームメンバーにCLIコマンドを提供した
    • GUI 作る暇がない
  • ACLの関係で指定サーバからしか叩けない
    • security的にproxyなど使いたくなかったため
  • serverへのlogin権限さえあれば叩ける = 権限管理は既存のアレでok
  • host OS の環境は汚したくないのでコンテナで提供
  • docker exec はうざいので、aliasでhost側から実行させる
    • alias cli='docker exec container_name python run.py $@'
  • 実行した結果をelasticsearchに保存したい

前提知識 - コマンド結果を docker log に入力させる方法

terminalを２つ開きます

これでlogを流しておく

$ docker-compose logs -f
Attaching to notip

（notipという名前のコンテナにしてます。）

container内でechoしても

docker-compose exec echo 1

docker logs の方は反応がありません

$ docker-compose logs -f
Attaching to notip
     <---------------- 何も出ない

/dev/stdout に投げれば？と思ったけど、それは /proc/self/fd/1 にsymlinkされてて
さらに追うと /dev/pts/0 つまり ログインした bash process の tty だけに紐付いていた。

$ ll /dev/stdout
lrwxrwxrwx 1 root root 15 Jul  3 09:39 /dev/stdout -> /proc/self/fd/1

$ ll /proc/self/fd/1
lrwx------ 1 root root 64 Jul  3 10:31 /proc/self/fd/1 -> /dev/pts/0

$ ll /dev/pts/0
crw--w---- 1 root tty 136, 0 Jul  3 10:31 /dev/pts/0   ( ← キャラクタデバイス)

$ tty
/dev/pts/0     <----- 一緒だね

じゃあ docker log は何の入力を受け取っているのか？というと、 docker logが PID=1 のstdout/err を受け取るようになっているみたい。
中に入って、pid=1のfile descripterに直接出力すると

docker exec -it notip  /bin/bash
echo 1 > /proc/1/fd/1

$ docker-compose logs -f
Attaching to notip
notip|  1         <--------------出た！

つまり、コンテナ内で実行したコマンド結果を /proc/1/fd/1 に流せば docker logとして扱われます。
これは docker のソースのどこに書いてあるんだろうか。誰かおせーて。

公式なdocumentは見つけてないけど、ここにはヒントがあった

The official httpd driver changes the httpd application’s configuration to write its normal output directly to /proc/self/fd/1 (which is STDOUT) and its errors to /proc/self/fd/2 (which is STDERR). See the Dockerfile.
https://docs.docker.com/config/containers/logging/

apacheのimageはlogを /proc/self/fd/1 に出力してる。httpd process はPID=1なので、それ以外のprocess(PID) からそこに送るには /proc/1/fd/1 を使えばよいということ。なるほどね

python logger で docker log への出力をする

ここでは python の実行結果を /proc/1/fd/1 に流してみます。肝は、出力を docker log だけに出すと コマンド叩いた人に結果が何も見えなくなっちゃう ので、 stdout && docker log 両方に出すことです。

参考: 神記事に感謝

ファイルへのログ出力、Logger生成

python で logger を作る

python の logging モジュールには、ハンドラという概念があります
ハンドラは「出力先」として理解しています。fileだったり、画面(console)だったり、データベースだったり。
fluentdみたいに、loggerに入れたものを様々な場所に出力することができます。
普通は console に表示するだけですが、ハンドラを複数作ると 画面+ファイル とか 画面+データベース に同時に送ることができます。

今回のゴールは ↓ です。

  • handler1 = stdout
    • コマンドを叩いた人に結果が見えるように
  • handler2 = /proc/1/fd/1
    • docker logにも出力（これを監査/debug用に記録）
logger.py
import logging

logger = logging.getLogger("logger")    #logger名loggerを取得
logger.setLevel(logging.DEBUG)  #loggerとしてはDEBUGで

#handler1を作成
handler1 = logging.StreamHandler()
handler1.setFormatter(logging.Formatter("%(asctime)s %(threadName)s %(levelname)8s %(message)s"))

#handler2を作成
handler2 = logging.FileHandler(filename="/proc/1/fd/1")  #handler2はdocker logが使うPID=1のstdoutファイルへ出力
handler2.setFormatter(logging.Formatter("%(asctime)s %(threadName)s %(levelname)8s %(message)s"))

#loggerに2つのハンドラを設定
logger.addHandler(handler1)
logger.addHandler(handler2)

#出力処理
logger.debug("debug message")
logger.info("info message")
logger.warning("warn message")
logger.error("error message")

thread使うため、 formatterに threadName を追加しています
どちらも DEBUG levelで出力

先にdocker logを tail しておきます

docker-compose logs -f
Attaching to notip

loggerを走らせてみます。

host-side
$ docker exec notip python logger.py
2021-07-03 10:23:36,738 MainThread    DEBUG debug message
2021-07-03 10:23:36,738 MainThread     INFO info message
2021-07-03 10:23:36,738 MainThread  WARNING warn message
2021-07-03 10:23:36,738 MainThread    ERROR error message

stdout に結果が出ました。

docker log にも同じ内容が出力されています！　目的達成！

docker-log
docker-compose logs -f
Attaching to notip
notip   | 2021-07-03 10:23:36,738 MainThread    DEBUG debug message
notip   | 2021-07-03 10:23:36,738 MainThread     INFO info message
notip   | 2021-07-03 10:23:36,738 MainThread  WARNING warn message
notip   | 2021-07-03 10:23:36,738 MainThread    ERROR error message

/proc の注意点

副産物として、 linux の host OS から直接 /proc/1/fd/1 を叩くと、permission denied になるようです. systemdのfdはさわれないのか。

centos7
[vagrant@localhost ~]$ sudo echo 1 > /proc/1/fd/1
-bash: /proc/1/fd/1: Permission denied

これはこれでオペミスを防ぐのによさそう。docker containerはそういうところもいじってあるのね。学び。

ちなみに linux以外の os　から直接叩くと、/proc 自体がないためコケます。

mac$ echo 1 > /proc/1/fd/1
-bash: /proc/1/fd/1: No such file or directory

これはちょっと開発に不便なので、symlinkでも作っておきますかね。python側で fd を切り替えてもよい。

$ sudo mkdir -p /proc/1/fd/
$ sudo ln -s $(tty) /proc/1/fd/1
$ echo 1 > /proc/1/fd/1
1

elasticsearchに送る方法

ここからはおまけです。

まず docker log を elasticsearch に送る設定を解説 (fluentd経由）

logging: docker container

docker logging driver を使って、docker logをelasticsearchに送る

app/docker-compose.yml
version: '2'

services:
  web:
    restart: always
    build:
      context: .
    logging:
      driver: "fluentd"
      options:
        fluentd-address: localhost:24224
        tag: "docker.logging_driver.production"

logging: fluentd

自分はここのfluentd部分を使って、コンテナ建ててます

https://github.com/myoshimi/es-docker-logging/blob/master/docker-compose.yml

fluentd/docker-compose.yml
version: '3.7'

services:
  fluentd:
    build: ./fluentd
    restart: always
    command: >
      /usr/bin/fluentd -c /fluentd/etc/fluent.conf -v
    ports:
      - "24224:24224"
      - "24224:24224/udp"
    volumes:
      - ${PWD}/log:/fluentd/log
      - ${PWD}/fluent.conf:/fluentd/etc/fluent.conf:ro

fluent.conf で elasticsearch に forward します

fluentd/fluent.conf
<source>
  @type  forward
  @id    input1
  @label @mainstream
  port  24224
</source>

<filter **>
  @type stdout
</filter>

<label @mainstream>
  <match docker.**>
    @type copy
    <store>
        @type file
        @id   output_docker1
        path         /fluentd/log/docker.*.log
        symlink_path /fluentd/log/docker.log
        append       true
        time_slice_format %Y%m%d
        time_slice_wait   1m
        time_format       %Y%m%dT%H%M%S%z
    </store>
    <store>
      @type elasticsearch
      hosts https://<user>:<pw>@<host>:12000    # <------ ES 接続情報
      logstash_format true
      logstash_prefix application_name    # <-- ES index 名になる. kibanaは application_name.* で表示すればok
    </store>
  </match>
  <match **>
    @type file
    @id   output1
    path         /fluentd/log/data.*.log
    symlink_path /fluentd/log/data.log
    append       true
    time_slice_format %Y%m%d
    time_slice_wait   10m
    time_format       %Y%m%dT%H%M%S%z
  </match>
</label>

これで、コンテナ内で実行したpythonコマンドの結果が elasticsearch に自動保存されるようになりました。
docker log経由させると、コンテナ名とか一緒に保存してくれるので便利！

19
14
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
19
14

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?