録画サーバでChinachuのログローテーションできないときがある。と、その対応

録画サーバを日々運用していると、期待通りに動かなくなることがあります。原因を調べたり、原因となる障害を取り除いたりしていると、色々なノウハウがたまってきますね。

事象

以下で書いたように録画の開始と終了をslackに通知しています。実装はChinachuのログを監視して、任意のキーワードが出力されるとslackに通知するというものです。

しかし、このslack通知が動作しなくなるのです。対処しないと2日でも3日でもslackへの通知はされません。

chinachuでの録画開始、録画終了をslackに連携する - 東京生まれHOUSE MUSIC育ち

原因

原因はChinachuのログがうまくローテーションできていないのが原因でした。

以下のファイルが肥大化するため、ローテーションしています。このローテーションがうまく動かなくて、ログ監視ができていないというのがわかりました。監視対象となるファイルが0バイトで、ログが書かれていなかったのです。

/usr/local/var/log/chinachu-operator.stdout.log

対処として実際にやってみたこと

実際にやってみたのは、Chinachuの再起動です。以下のコマンドで再起動しました。そしたら、ちゃんとslackへの通知ができるようになりました。

pm2 restart chinachu-wui chinachu-operator

再発したら、試してみたいこと

ログローテートがうまく動いていないので、Chinachuを再起動するのではなく、ログローテートをちゃんと動かせばいいのではないかと思いました。

pm2 listすると、以下のようにpm2-logrotateが表示されます。（状態確認）

# pm2 list
lqqqqqqqqqqqqqqqqqqqwqqqqqqwqqqqqqqqwqqqwqqqqqwqqqqqqqqqqqqk
x Name              x mode x status x ? x cpu x memory     x
tqqqqqqqqqqqqqqqqqqqnqqqqqqnqqqqqqqqnqqqnqqqqqnqqqqqqqqqqqqu
x chinachu-operator x fork x online x 1 x 0%  x 36.0 MB    x
x chinachu-wui      x fork x online x 1 x 0%  x 134.8 MB   x
x mirakurun-server  x fork x online x 0 x 0%  x 184.4 MB   x
mqqqqqqqqqqqqqqqqqqqvqqqqqqvqqqqqqqqvqqqvqqqqqvqqqqqqqqqqqqj
 Module activated
lqqqqqqqqqqqqqqqwqqqqqqqqwqqqqqwqqqqqqqqqqqqqk
x Module        x status x cpu x mem         x
tqqqqqqqqqqqqqqqnqqqqqqqqnqqqqqnqqqqqqqqqqqqqu
x pm2-logrotate x online x 0%  x 48.941 MB   x
mqqqqqqqqqqqqqqqvqqqqqqqqvqqqqqvqqqqqqqqqqqqqj
 Use `pm2 show ` to get more details about an app

次に、pm2 show pm2-logrotateすると、以下のように表示されます。（状態確認）

# pm2 show pm2-logrotate
 Describing process with id 0 - name pm2-logrotate
lqqqqqqqqqqqqqqqqqqqwqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqk
x status            x online                                                             x
x name              x pm2-logrotate                                                      x
x restarts          x 0                                                                  x
x uptime            x 9D                                                                 x
x script path       x /root/.pm2/modules/pm2-logrotate/node_modules/pm2-logrotate/app.js x
x script args       x N/A                                                                x
x error log path    x /root/.pm2/logs/pm2-logrotate-error-0.log                          x
x out log path      x /root/.pm2/logs/pm2-logrotate-out-0.log                            x
x pid path          x /root/.pm2/pids/pm2-logrotate-0.pid                                x
x interpreter       x node                                                               x
x interpreter args  x N/A                                                                x
x script id         x 0                                                                  x
x exec cwd          x /root/.pm2/modules/pm2-logrotate/node_modules/pm2-logrotate        x
x exec mode         x fork_mode                                                          x
x node.js version   x 8.11.3                                                             x
x watch & reload    x ?                                                                  x
x unstable restarts x 0                                                                  x
x created at        x 2018-07-01T13:35:54.671Z                                           x
mqqqqqqqqqqqqqqqqqqqvqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqj
Process configuration
lqqqqqqqqqqqqqqqqwqqqqqqqqqqqqqqqqqqqqqk
x rotateModule   x true                x
x rotateInterval x 0 0 * * *           x
x workerInterval x 30                  x
x dateFormat     x YYYY-MM-DD_HH-mm-ss x
x compress       x false               x
x retain         x 30                  x
x max_size       x 10M                 x
mqqqqqqqqqqqqqqqqvqqqqqqqqqqqqqqqqqqqqqj
 Actions available
lqqqqqqqqqqqqqqqqqqqk
x list watched logs x
x list all logs     x
mqqqqqqqqqqqqqqqqqqqj
 Trigger via: pm2 trigger pm2-logrotate 

 Code metrics value
lqqqqqqqqqqqqqqqqqqwqqqqqqqqqk
x Loop delay       x 0.88ms  x
x Active requests  x 0       x
x Active handles   x 6       x
x Global logs size x 5.51 KB x
x Files count      x 24      x
mqqqqqqqqqqqqqqqqqqvqqqqqqqqqj
 Add your own code metrics: http://bit.ly/code-metrics
 Use `pm2 logs pm2-logrotate [--lines 1000]` to display logs
 Use `pm2 monit` to monitor CPU and Memory usage pm2-logrotate

再起動として、「pm2 restart pm2-logrotate」をすればいいのではないかと考えます。

以下の結果は試しにpm2 restart pm2-logrotateしてみた結果です。

# pm2 restart pm2-logrotate
Use --update-env to update environment variables
[PM2] Applying action restartProcessId on app [pm2-logrotate](ids: 0)
[PM2] [pm2-logrotate](0) ?
lqqqqqqqqqqqqqqqqqqqwqqqqwqqqqqqwqqqqqqwqqqqqqqqwqqqqqqqqqwqqqqqqqqwqqqqqwqqqqqqqqqqqqwqqqqqqwqqqqqqqqqqk
x App name          x id x mode x pid  x status x restart x uptime x cpu x mem        x user x watching x
tqqqqqqqqqqqqqqqqqqqnqqqqnqqqqqqnqqqqqqnqqqqqqqqnqqqqqqqqqnqqqqqqqqnqqqqqnqqqqqqqqqqqqnqqqqqqnqqqqqqqqqqu
x chinachu-operator x 3  x fork x 7173 x online x 1       x 36h    x 0%  x 37.0 MB    x root x disabled x
x chinachu-wui      x 2  x fork x 7124 x online x 1       x 36h    x 0%  x 135.5 MB   x root x disabled x
x mirakurun-server  x 1  x fork x 1150 x online x 0       x 9D     x 0%  x 159.0 MB   x root x disabled x
mqqqqqqqqqqqqqqqqqqqvqqqqvqqqqqqvqqqqqqvqqqqqqqqvqqqqqqqqqvqqqqqqqqvqqqqqvqqqqqqqqqqqqvqqqqqqvqqqqqqqqqqj
 Module activated
lqqqqqqqqqqqqqqqwqqqqqqqqqwqqqqqqqqqqqqwqqqqqqqqwqqqqqqqqqwqqqqqwqqqqqqqqqqqqwqqqqqqk
x Module        x version x target PID x status x restart x cpu x memory     x user x
tqqqqqqqqqqqqqqqnqqqqqqqqqnqqqqqqqqqqqqnqqqqqqqqnqqqqqqqqqnqqqqqnqqqqqqqqqqqqnqqqqqqu
x pm2-logrotate x N/A     x N/A        x online x 1       x 24% x 4.023 MB   x root x
mqqqqqqqqqqqqqqqvqqqqqqqqqvqqqqqqqqqqqqvqqqqqqqqvqqqqqqqqqvqqqqqvqqqqqqqqqqqqvqqqqqqj
 Use `pm2 show ` to get more details about an app

pm2 restart pm2-logrotateしても、以下のファイルサイズは変更されませんでした。

期待したのは、再起動すると、強制的にログローテートされて新しくファイルが作られることでした。ログが切り替わらなければ、もしかしたら効果は無いのかも。。。

/usr/local/var/log/chinachu-operator.stdout.log