LoginSignup
27
21

More than 5 years have passed since last update.

@tmiki(TMIKI)

Supervisorで日次のログローテートを行う方法

Last updated at Posted at 2016-11-03

概要

非daemonプロセスをdaemon化するためのツールとして、D.J.BernsteinのDaemontoolsや、upstart、Supervisorなどがあります。Supervisorはとても便利なのですが、ログローテートはファイルサイズが規定値を超えた場合に行う方法しか設定できません。
この記事では、Supervisorで管理するログファイルを日次でローテートできるようにします。

この方法を簡単に説明すると下記のようになります。

  • ログファイルのローテートはSupervisor自身ではなくlogrotateコマンドを用いて行うようにする。
  • Supervisorの設定上は、単一のログファイルにログを書き出してローテートは行わないようにする。

なお、logrotateの設定においてcopytruncateは使いません。これは僅かながらログがロストする可能性があるからです。

Supervisorとは何か、といった基本的な事項は割愛します。
下記の記事が参考になるでしょう。
Supervisorで簡単にデーモン化

※2017/11/30更新
　CentOSのバージョンによって、/var/lib/logrotate.statusのパスが違う旨、追記しました。

設定する

検証する環境

今回は下記の環境で検証を行いました。

  • OS: CentOS 7.2
  • 検証用プログラム名: myapp
  • インストール先ディレクトリ: /opt/myapp
  • 検証用プログラムの実行ユーザ: app

まずはプログラム実行用のユーザであるappを作成します。
daemonとして実行するプロセスは、どうしてもroot権限が必要な場合以外は、一般ユーザの権限で動作させるのが基本です。

# appユーザを作成
$ sudo useradd -G app app

# appユーザのuidとgidを確認
$ id app
uid=1001(app) gid=1001(app) groups=1001(app)

検証用プログラムを作成します。これは、1秒ごとに日時を出力するだけのプログラムです。

# 検証用プログラムを配置するディレクトリを作成します。
$ sudo mkdir -p /opt/myapp/bin /opt/myapp/log

$ sudo vi /opt/myapp/bin/myapp.py
# 下記のソースを貼り付けます。
myapp.py
import time
import datetime

while True:
        now = datetime.datetime.now()
        print "{0:%Y/%m/%d %H:%M:%S}".format(now)
        time.sleep(1)

Supervisor

次にSupervisorの設定をします。
まずはインストールをします。CentOS7の場合は、epelリポジトリからインストールすることが可能です。

インストール
$ sudo yum install epel-release

$ sudo yum update
$ sudo yum install supervisor

管理対象プログラムの設定を行います。標準出力ログおよび標準エラー出力ログのlogfile_maxbytes及びlogfile_backupsを、いずれも0に設定することがポイントです。
これは、ログのファイルサイズ上限を無制限とすること、ログファイルのバックアップを作成しないことを意味します。

詳細な説明はConfiguration Files - [program:x] Section Settingsにあります。

$ sudo vi /etc/supervisord.d/myapp.ini
# 下記の内容を貼り付けます。
myapp.ini
[program:myapp]
command=/bin/python -u /opt/myapp/bin/myapp.py
autostart=true
autorestart=true
stdout_logfile=/opt/myapp/log/myapp_console.log
stderr_logfile=/opt/myapp/log/myapp_stderr.log
user=app
stdout_logfile_maxbytes=0
stderr_logfile_maxbytes=0
stdout_logfile_backups=0
stderr_logfile_backups=0

Supervisorプロセスを再起動してmyappの設定を読み込ませます。その後、myappが実行されていることを確認します。

# supervisordの再起動
$ sudo systemctl restart supervisord

# myappの動作確認。myappのステータスが"RUNNING"になっていることを確認します。
$ sudo supervisorctl
myapp                            RUNNING   pid 14033, uptime 0:00:32
supervisor> exit

# ログが1秒ごとに出力されていることを確認します。
$ tail -f /opt/myapp/log/myapp_console.log
2016/11/03 15:54:14
2016/11/03 15:54:15
2016/11/03 15:54:16
:
:

これでSupervisorの設定は完了です。

logrotate

次はlogrotateの設定を行います。myapp用の個別の設定ファイルを作ります。
ポイントはpostrotate句です。ここにはログファイルをローテートした後に実行するコマンドを指定します。
これは、supervisordプロセスにSIGUSR2シグナルを送出するコマンドを実行します。

Running Supervisor - Signalsに下記の説明がありますが、このシグナルはログファイルを一旦クローズし、オープンし直すということを行います。

SIGUSR2
supervisord will close and reopen the main activity log and all child log files.

$ sudo vi /etc/logrotate.d/myapp
# 下記の内容を貼り付けます。
myapp
/opt/myapp/log/myapp_*.log {
        daily
        dateext
        rotate 62
        delaycompress
        missingok
        postrotate
                /bin/kill -SIGUSR2 `cat /var/run/supervisord.pid` > /dev/null 2>/dev/null || true
        endscript
}

これでlogrotateの設定は完了です。

動作確認

myappを稼働させ続けて1日置けば動作確認ができますが、その場ですぐに確認したい場合は下記のようにします。

まず、logrotateの管理ファイルを変更します。/var/lib/logrotate.statusには、対象となるログがいつローテートされたかが記録され、管理されています。
myapp用のログファイルのローテート時刻として数日前の時刻を設定します。

$ vi /var/lib/logrotate.status

# 下記の行を最下行に追加します。
"/opt/myapp/log/myapp_console.log" 2016-10-10-15:0:0

上記の編集が完了したら、logrotateコマンドを実行し、ログファイルをローテートさせます。

# ログファイルをローテートさせます
$ sudo /usr/sbin/logrotate /etc/logrotate.conf

ログファイルがローテートされ、ローテート後のファイルにログが出力されていることを確認します。

# ログがローテートされていることを確認します。
$ cd /opt/myapp/log/
$ ls -lA
total 12
-rw-r--r--. 1 root root 3440 Nov  3 16:25 myapp_console.log
-rw-r--r--. 1 root root 4960 Nov  3 16:22 myapp_console.log-20161103
-rw-r--r--. 1 root root    0 Nov  3 15:02 myapp_stderr.log

# ローテート後のファイルにログが追記されていることを確認します。
$ tail -f myapp_console.log

なお、CentOS 7であっても、バージョンによって/var/lib/logrotate.statusのパスが違うようです。
少なくともCentOS 7.4(確認したのは7.4.1708)では、/var/lib/logrotate/logrotate.statusになっています。

解説

ログファイルのローテート時に、supervisordにSIGUSR2シグナルを送出するのは何故でしょうか。
これは、Supervisorのログ書き出しの方法、UNIX系のファイルシステムの仕組みを理解する必要があります。

まず、現在書き込まれているログファイルに対してmvコマンドを実行し、リネームした場合の挙動を見てみましょう。

# 現在のログファイルを確認
$ cd /opt/myapp/log
$ ls -li
total 28
201434730 -rw-r--r--. 1 root root 18760 Nov  3 16:38 myapp_console.log
201434481 -rw-r--r--. 1 root root  4960 Nov  3 16:22 myapp_console.log-20161103
201434726 -rw-r--r--. 1 root root     0 Nov  3 15:02 myapp_stderr.log

# ログファイルをリネーム
$ sudo mv myapp_console.log myapp_console.log.bak
$ ls -li
total 28
201434481 -rw-r--r--. 1 root root  4960 Nov  3 16:22 myapp_console.log-20161103
201434730 -rw-r--r--. 1 root root 20320 Nov  3 16:39 myapp_console.log.bak
201434726 -rw-r--r--. 1 root root     0 Nov  3 15:02 myapp_stderr.log

# リネーム後のファイルを参照し、ログが書き込まれ続けていることを確認。
$ tail -f myapp_console.log.bak
2016/11/03 16:40:40
2016/11/03 16:40:41
2016/11/03 16:40:42
:
:

ログファイルをリネームしたにもかかわらず、そのままログが追記され続けていることが確認できます。
仕組みは下記の通りとなります。

  • ファイルシステムの仕組み
    • UNIX系のOSでは、ファイルはi-nodeというUniqueなIDで管理される。
    • 各プロセスからのファイル読み書きはi-nodeに対して行われる。一旦、プロセスからオープンされたファイルは、ファイル名が変更されてもそのプロセスからの読み書きに影響はない。
  • Supervisorのログ書き出しの仕様
    • Supervisorは各管理対象プログラムのログファイルをオープンし続け、必要都度追記していく。
    • Supervisorからのログ書き込みは、一旦オープンしたファイルに対して行われるため、ファイル名が変更されようともその影響を受けない。

先ほどの動作確認で、lsコマンドに-iオプションを指定しました。これは当該ファイルのi-node番号を表示させるオプションです。
myapp_console.logのi-nodeは201434730であることが分かります。また、mvコマンドでファイル名を変更した後も、同じi-nodeが保持されていることが分かります。

では、supervisordにSIGUSR2を送出してみましょう。新たにログファイルが作成され、これに書き込まれることが確認できます。
下記の例では、i-nodeが201434728として、myapp_console.logが新たに作成されています

# supervisordにSIGUSR2シグナルを送出
$ sudo kill -SIGUSR2 `cat /var/run/supervisord.pid`

# 新たなログファイルのi-nodeを確認
$ ls -li
total 52
201434728 -rw-r--r--. 1 root root  1320 Nov  3 16:55 myapp_console.log
201434481 -rw-r--r--. 1 root root  4960 Nov  3 16:22 myapp_console.log-20161103
201434730 -rw-r--r--. 1 root root 37040 Nov  3 16:54 myapp_console.log.bak
201434726 -rw-r--r--. 1 root root     0 Nov  3 15:02 myapp_stderr.log

# ログが追記され続けていることを確認
$ tail -f myapp_console.log
2016/11/03 16:56:16
2016/11/03 16:56:17
2016/11/03 16:56:18
2016/11/03 16:56:19
:
:

その他

Supervisorは、一旦オープンしたファイルにログを書き出し続けることが分かりました。では書出し中のファイルを削除するとどうなるでしょうか。
結論から言うと、Supervisorの動作には何ら影響はありません。

詳細な仕組みはまた別の記事にまとめます。

27
21
2

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
27
21