使用 Logspout + syslog-ng 實現 docker logs 的 local 端集中 log 管理

Last updated on Aug 30, 2021

最近(2021/08/07) 我的 Storj Node Operator 被 Disqualified，原因不詳，欲回去查看過去幾天的 container log，卻發現在 08/05 的時候，watchtower 已經自動下載最新版 image 進行更新了。更新後會重啟 container，但由於 container 是 stateless，其中所有的 log 如果沒有統一記錄在另外一個地方，就會消失，這時我才意識到問題的嚴重性...。原來 log 是一項很重要的資訊，需要被妥善記錄在另外一個地方，當出現問題時，才有辦法可以查出問題並解決。

經過一番搜尋，我發現網路上有很多雲端服務是專門用來記錄 log 資訊的，例如 papertrail，以及分析工具如 Sematext, Datadog 等(參考這篇)，但其實我並不是專業用戶，不需要用到那麼專業的工具，只是想要把 log 儲存在一個統一的地方，出問題時可以回溯到足夠長時間。

後來查到了以下這篇 blog，利用 Logspout + syslog-ng 可以實現自動蒐集所有 container 的 log 資料，並集中儲存在指定的資料夾中：

以下方法我也在 github 上回答了，請參考這裡：

下面是該blog中所使用的 docker-compose.yml 和 syslog-ng.conf 設定，將這兩個檔案放在同一個資料夾底下，執行 docker-compose up -d ，就會啟動 logspout 和 syslogng 容器，並自動收集所有運行中容器的 log 到 local 端的 /logs 資料夾。

docker-compose.yml

version: '3'
services:
  logspout:
    image: gliderlabs/logspout:latest
    restart: always
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"
    command: syslog+udp://syslogng:514
  syslogng:
    image: balabit/syslog-ng:latest
    restart: always
    command: -F --no-caps
    volumes:
      - "/logs/:/var/log/syslogng/"
      - "./syslog-ng.conf:/etc/syslog-ng/syslog-ng.conf"

syslog-ng.conf

@version: 3.31
@include "scl.conf"
source s_network {
  default-network-drivers();
};
destination d_local {
  file("/var/log/syslogng/${PROGRAM}.${HOST}.log");
};
log {
  source(s_network);
  destination(d_local);
};

檢查 syslogng 容器的 log，如果出現：

WARNING: Configuration file format is too old, syslog-ng is running in compatibility mode. Please update it to use the syslog-ng 3.31 format at your time of convenience. To upgrade the configuration, please review the warnings about incompatible changes printed by syslog-ng, and once completed change the @version header at the top of the configuration file; config-version='3.19'

把 @version: 3.19 改成最新的版本 @version: 3.31 即可。

若出現：

You have a TLS enabled source without a X.509 keypair. Make sure you have tls(key-file() and cert-file()) options, TLS handshake to this source will fail; location='/etc/syslog-ng/syslog-ng.conf:4:3'

就是無法使用 tls 加密的port 6514 而已，可以無須理會。參考：

syslog-ng Open Source Edition 3.18 - Administration Guide
CAUTION:

To receive messages using a TLS-encrypted connection, you must set the tls(key-file() cert-file()) options of the default-network-drivers() source. For example:
```
source s_network {
    default-network-drivers(
        tls(
            key-file("/path/to/ssl-private-key")
            cert-file("/path/to/ssl-cert")
        )
    );
};
```

時間格式的設定，參考：

syslog-ng Open Source Edition 3.18 - Administration Guide

Example: Using the file() driver with macros in the file name and a template for the message
destination d_file {
    file("/var/log/${YEAR}.${MONTH}.${DAY}/messages"
         template("${HOUR}:${MIN}:${SEC} ${TZ} ${HOST} [${LEVEL}] ${MESSAGE}\n")
         template-escape(no));
};

但是 blog 作者說，這裡沒有自動 log 旋轉(rotation)/清理(flushing)的功能，但是可以透過 cron job 的功能來達成：

建立一個檔案名為 rotate_and_flush.sh 內容如下：

rotate_and_flush.sh

# to compress 2 days old logs
find /var/log/syslogng/ -name "*.log" -daystart -ctime +2 -type f -exec gzip {} \;
# to remove 14 days old logs
find /var/log/syslogng/ -name "*.gz" -daystart -ctime +14 -type f -exec rm {} \;

2. 在 docker-compose.yml 中的 syslogng 容器下，加入一個 volume entry - "./rotate_and_flush.sh:/etc/cron.daily/rotate_and_flush.sh" ，這是把 rotate_and_flush.sh 這個檔案 mount 到 /etc/cron.hourly/ 底下，cron 會每個小時執行一次底下的工作：

docker-compose.yml

version: '3'
services:
  logspout:
    image: gliderlabs/logspout:latest
    restart: always
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"
    command: syslog+udp://syslogng:514
  syslogng:
    image: balabit/syslog-ng:latest
    restart: always
    command: -F --no-caps
    volumes:
      - "/logs/:/var/log/syslogng/"
      - "./syslog-ng.conf:/etc/syslog-ng/syslog-ng.conf"
      - "./rotate_and_flush.sh:/etc/cron.daily/rotate_and_flush.sh"

使用 logrotate 旋轉日誌

前面我們使用了自訂的 script 來進行日誌旋轉與清洗，但是有沒有更好的方式呢？有的，其實 linux 系統原本就有對 /var/log/ 底下的 log 檔進行旋轉與清洗，透過系統自帶的 logrotate 來完成。因此，我們可以利用這個系統自帶的工具進行統一的處理。

首先我們新增一個檔案 syslogng-logratate.conf ，內容如下：

syslogng-logratate.conf

/var/log/syslogng/*.log
{
        minsize 50M
        rotate 20
        daily
        dateext
        dateformat -%Y-%m-%d-%s
        missingok
        notifempty
        delaycompress
        compress
        sharedscripts
        postrotate
          /usr/bin/killall -HUP syslog-ng
        endscript
}

常見配置參數

daily ：指定转储周期为每天
weekly ：指定转储周期为每周
monthly ：指定转储周期为每月
dateext 指示让旧日志文件以创建日期命名。
rotate count ：指定日志文件删除之前转储的次数，0 指没有备份，5 指保留 5 个备份
tabooext [+] list：让 logrotate 不转储指定扩展名的文件，缺省的扩展名是：.rpm-orig, .rpmsave, v, 和～
missingok：在日志轮循期间，任何错误将被忽略，例如 "文件无法找到" 之类的错误。
compress：通过 gzip 压缩转储以后的日志
delaycompress: 总是与 compress 选项一起用，delaycompress 选项指示 logrotate 不要将最近的归档压缩，压缩将在下一次轮循周期进行。这在你或任何软件仍然需要读取最新归档时很有用。
nocompress：不压缩
copytruncate：用于还在打开中的日志文件，把当前日志备份并截断
nocopytruncate：备份日志文件但是不截断
create mode owner group ：转储文件，使用指定的文件模式创建新的日志文件
nocreate：不建立新的日志文件
delaycompress：和 compress 一起使用时，转储的日志文件到下一次转储时才压缩
nodelaycompress：覆盖 delaycompress 选项，转储同时压缩。
errors address ：专储时的错误信息发送到指定的 Email 地址
ifempty ：即使是空文件也转储，这个是 logrotate 的缺省选项。
notifempty ：如果是空文件的话，不转储
mail address ：把转储的日志文件发送到指定的 E-mail 地址
nomail ：转储时不发送日志文件
olddir directory：储后的日志文件放入指定的目录，必须和当前日志文件在同一个文件系统
noolddir：转储后的日志文件和当前日志文件放在同一个目录下
create 644 root root: 以指定的权限创建全新的日志文件，同时 logrotate 也会重命名原始日志文件。
prerotate/endscript：在转储以前需要执行的命令可以放入这个对，这两个关键字必须单独成行
size size
Log files are rotated only if they grow bigger then size bytes. If size is followed by k, the size is assumed to be in kilobytes. If the M is used, the size is in megabytes, and if G is used, the size is in gigabytes. So size 100, size 100k, size 100M and size 100Gare all valid.
minsize size
Log files are rotated when they grow bigger than size bytes, but not before the additionally specified time interval (daily, weekly, monthly, or yearly). The related size option is similar except that it is mutually exclusive with the time interval options, and it causes log files to be rotated without regard for the last rotation time. When minsize is used, both the size and timestamp of a log file are considered.
sharedscripts
Normally, prerotate and postrotate scripts are run for each log which is rotated and the absolute path to the log file is passed as first argument to the script. That means a single script may be run multiple times for log file entries which match multiple files (such as the /var/log/news/ example). If sharedscripts is specified, the scripts are only run once, no matter how many logs match the wildcarded pattern, and whole pattern is passed to them. However, if none of the logs in the pattern require rotating, the scripts will not be run at all. If the scripts exit with error, the remaining actions will not be executed for any logs. This option overrides the nosharedscripts option and implies create option.*

其中 /usr/bin/killall -HUP syslog-ng 表示 reload syslog-ng process

Linux 日志切割神器 logrotate 原理介绍和配置详解 | HelloDog
USR1 亦通常被用来告知应用程序重载配置文件；例如，向 Apache HTTP 服务器发送一个 USR1 信号将导致以下步骤的发生：停止接受新的连接，等待当前连接停止，重新载入配置文件，重新打开日志文件，重启服务器，从而实现相对平滑的不关机的更改。

对于 USR1 和 2 都可以用户自定义的，在 POSIX 兼容的平台上，SIGUSR1 和 SIGUSR2 是发送给一个进程的信号，它表示了用户定义的情况。它们的符号常量在头文件 signal.h 中定义。在不同的平台上，信号的编号可能发生变化，因此需要使用符号名称。
```
kill -HUP pid
killall -HUP pName
```
其中 pid 是进程标识，pName 是进程的名称。

如果想要更改配置而不需停止并重新启动服务，可以使用上面两个命令。在对配置文件作必要的更改后，发出该命令以动态更新服务配置。根据约定，当你发送一个挂起信号 (信号 1 或 HUP) 时，大多数服务器进程 (所有常用的进程) 都会进行复位操作并重新加载它们的配置文件。

關於 dateext 附加在檔案名稱最後的日期標籤格式，為了避免同一天產生多組同名檔案，可在最後附加上 unix seconds 如下：

linux - logrotate suffix: dateext + rotate - Stack Overflow
You can use "date" as a suffix of the rotated file:
```
dateext dateformat -%Y-%m-%d-%s
```

參考：
logrotate(8) - Linux man page
被遗忘的Logrotate | 火丁笔记

關於 logrotate 的目標檔案路徑，可以使用星號來匹配任意檔名，如上面的 /var/log/syslogng/*.log ，可以將設定套用到所有 /var/log/syslogng/ 底下的 .log 檔案。

參考：logrotate - logrotating files in a directories and its subdirectories - Server Fault

2. 在 docker-compose.yml 中的 volumes 下新增一條 -n "./syslogng-logratate.conf:/etc/logrotate.d/syslogng-logratate.conf" ，並將先前的 rotate_and_flush.sh 註解掉，避免兩者產生衝突：

docker-compose.yml

version: '3'
services:
  logspout:
    image: gliderlabs/logspout:latest
    restart: always
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"
    command: syslog+udp://syslogng:514
  syslogng:
    image: balabit/syslog-ng:latest
    restart: always
    command: -F --no-caps
    volumes:
      - "/logs/:/var/log/syslogng/"
      - "./syslog-ng.conf:/etc/syslog-ng/syslog-ng.conf"
      # - "./rotate_and_flush.sh:/etc/cron.hourly/rotate_and_flush.sh"
      - "./syslogng-logratate.conf:/etc/logrotate.d/syslogng-logratate.conf"

3. 若想進行測試，先進入容器中：

docker exec -ti syslogng bash

執行

logrotate -df /etc/logrotate.d/syslogng-logratate.conf

其中參數 -d 為debug模式，不會進行任何真實操作，而 -f 為強制模式，無論是否判定為無須旋轉，都會執行旋轉，可藉此看檢查輸出的訊息是否正確。

路徑 /etc/logrotate.d/ 中放的是自定義的 logrotate 配置檔案，時間到了就會自動執行。而預設的主配置是放在 /etc/logrotate.conf 中。

由於 logrotate 是基於 cron 運行的，所以可以在 crontab 中查看執行時間：

cat /etc/crontab

# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# Example of job definition:
# .---------------- minute (0 - 59)
# |  .------------- hour (0 - 23)
# |  |  .---------- day of month (1 - 31)
# |  |  |  .------- month (1 - 12) OR jan,feb,mar,apr ...
# |  |  |  |  .---- day of week (0 - 6) (Sunday=0 or 7) OR sun,mon,tue,wed,thu,fri,sat
# |  |  |  |  |
# *  *  *  *  * user-name command to be executed
17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly
25 6    * * *   root  test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6    * * 7   root  test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6    1 * *   root  test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )
#

可以看到 cron 是每天 6h47m 的時候執行 /etc/cron.daily/ 資料夾底下的任務，其中有 logrotate 這項任務：

 cat /etc/cron.daily/logrotate

#!/bin/sh

# skip in favour of systemd timer
if [ -d /run/systemd/system ]; then
    exit 0
fi

# this cronjob persists removals (but not purges)
if [ ! -x /usr/sbin/logrotate ]; then
    exit 0
fi

/usr/sbin/logrotate /etc/logrotate.conf
EXITVALUE=$?
if [ $EXITVALUE != 0 ]; then
    /usr/bin/logger -t logrotate "ALERT exited abnormally with [$EXITVALUE]"
fi
exit $EXITVALUE

如何確認 cron 有執行？

經過一陣子後發現， logrotate 似乎沒有執行，以至於 log 檔越來越大...。因此決定檢查 cron 是否有在運作。一般來說都會用 ps 下去看，如 Checking and Restarting the Cron Daemon 所說：

ps -ef | grep crond

(若在 ubuntu 或 debian 下， crond 改為 cron。)

但是我們的 syslogng container 中並沒有 ps 指令，因此只能透過其它方法。根據 busybox - Find the PID's of all threads of a process without ps or pidof - Unix & Linux Stack Exchange 執行：

find /proc -mindepth 2 -maxdepth 2 -name exe -exec ls -lh {} \; 2>/dev/null

lrwxrwxrwx 1 root root 0 Aug 17 11:12 /proc/1/exe -> /bin/bash
lrwxrwxrwx 1 root root 0 Aug 17 11:12 /proc/13/exe -> /usr/sbin/syslog-ng
lrwxrwxrwx 1 root root 0 Aug 17 11:08 /proc/15/exe -> /bin/bash
lrwxrwxrwx 1 root root 0 Aug 17 11:32 /proc/190/exe -> /usr/bin/find

會發現沒有 cron 執行。進一步我們可以檢查 /usr/sbin/syslog-ng 的參數，根據 scripting - How to get whole command line from a process? - Unix & Linux Stack Exchange 執行：

tr '\0' ' ' </proc/13/cmdline

得到

/usr/sbin/syslog-ng -F --no-caps

表示 syslog-ng 有按照輸入的參數執行。

因此，問題應該是出在 cron 沒有執行。因此新增一個檔案 init.sh 在 ./syslogng/ 底下：

syslogng/init.sh

#!/bin/bash
echo "$@"
/etc/init.d/cron start
/usr/sbin/syslog-ng "$@"

修改 docker-compose.yml ，在 syslogng 的 volumes 中新增一條 ./syslogng:/syslogng 並且將 entrypoint 指定為執行 /syslogng/init.sh ，這樣每次啟動 syslogng 容器時就會執行上面的 init.sh ，其中 /etc/init.d/cron start 這行就會先啟動 cron daemon，之後才執行 /usr/sbin/syslog-ng "$@" 。其中 "$@" 為 init.sh 接收到的參數，即 docker-compose.yml 中 command 指定的參數。

docker-compose.yml

version: '3'
services:
  logspout:
    image: gliderlabs/logspout:latest
    restart: always
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"
    command: syslog+udp://syslogng:514
  syslogng:
    image: balabit/syslog-ng:latest
    restart: always
    entrypoint: /syslogng/init.sh
    command: -F --no-caps
    volumes:
      - "./syslogng:/syslogng"
      - "/logs/:/var/log/syslogng/"
      - "./syslog-ng.conf:/etc/syslog-ng/syslog-ng.conf"
      # - "./rotate_and_flush.sh:/etc/cron.hourly/rotate_and_flush.sh"
      - "./syslogng-logratate.conf:/etc/logrotate.d/syslogng-logratate.conf"

執行 docker-compose up -d 重新啟動後，進到 syslogng 容器再次檢查：

find /proc -mindepth 2 -maxdepth 2 -name exe -exec ls -lh {} \; 2>/dev/null

可以發現這次有 cron 了：

lrwxrwxrwx 1 root root 0 Aug 17 11:12 /proc/1/exe -> /bin/bash
lrwxrwxrwx 1 root root 0 Aug 17 11:12 /proc/12/exe -> /usr/sbin/cron
lrwxrwxrwx 1 root root 0 Aug 17 11:12 /proc/13/exe -> /usr/sbin/syslog-ng
lrwxrwxrwx 1 root root 0 Aug 17 11:08 /proc/15/exe -> /bin/bash
lrwxrwxrwx 1 root root 0 Aug 17 11:53 /proc/306/exe -> /usr/bin/find

上面所有的code都放在這邊：