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

# １行で解決

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

```
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を流しておく

```ruby
$ docker-compose logs -f
Attaching to notip
```

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

container内でechoしても

```ruby
docker-compose exec echo 1
```

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

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

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

```vb
$ 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に直接出力すると

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

```ruby
$ 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](https://github.com/docker-library/httpd/blob/b13054c7de5c74bbaa6d595dbe38969e6d4f860c/2.2/Dockerfile#L72-L75) に出力してる。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生成](https://python.civic-apps.com/logifle-logger/)

### python で logger を作る

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

今回のゴールは ↓ です。

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

```py: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を走らせてみます。

```ruby: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 にも同じ内容が出力されています！　目的達成！

```ruby: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はさわれないのか。

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

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

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

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

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

```rb
$ 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に送る

```yml: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


```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 します

```js: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経由させると、コンテナ名とか一緒に保存してくれるので便利！