epgrec UNA + mirakurunによる録画環境で数日に1回くらい録画が失敗する問題。前回、ログの出力内容からmirakurunのTSFilter.jsで問題が起きているところまでわかった。このクラスはstream.Duplexを継承していて、その継承元にbuffered writeのような処理がある模様。素直に考えれば何らかの事情でwriteが進まず、書き込むべきdataがbufferに貯まっていき、いずれoverflowに至ると。根本対策としてはwriteが滞ることの改善、それが無理ならbufferを大きくして枯渇までの時間を稼ぐ。
less /usr/local/var/log/mirakurun.stderr.log
:
2017-06-09T00:31:32.229+09:00 warn: TSFilter is overflowing the buffer...
2017-06-09T00:32:02.230+09:00 error: TSFilter will closing because reached time limit of overflowing the buffer...
write速度が遅延する原因としてありえそうなのは、録画処理の並列度が高く、単位時間当たりの書き込み量が多いとか。そう考えると番組表更新の時間帯によく停止していることについても説明が付く。とはいえ、番組表更新時のファイル書き出しはlocalのSSDディスク。それに対して録画時のファイル書き出しはremoteのGlusterFS。あまりI/Oがかち合う気もしないんだけどね。node.js側の処理のどこかで直列化してしまっているのだろうか。いずれにせよ、番組表更新時の地上波とBSの同時書き込みがlocalのSSDに集中しているのはいけてないので散らしておく。
epgrecのsettings/config.xml内にある
vi /usr/local/etc/mirakurun/server.yml
:
highWaterMark: 268435456
これだと最大8並列でバッファが膨張した時にメモリサイズは2GBになってしまう。mirakurunの最大プロセスサイズは256MBに設定されているので、ここまで大きくなることができない。processes.jsonを修正してプロセスサイズの最大値も引き上げておく。
vi /usr/lib/node_modules/mirakurun/processes.json
:
"node_args" : "--max_old_space_size=2048",
このままだとバッファは大きくしたものの、結局どこまで使っているかがわからないので、TSFilter.jsをいじって、既存のバッファサイズをロギングするように修正する。バッファを使っていないのにロギングされてもうっとおしいので、使用率が1%以上のときのみ。あまり頻繁にロギングされるのも嫌なので、ロギングのインターバルは1秒で。TSFilter.jsの_write()メソッドに以下のような処理を追加した。最初の_loggingTimerの定義は_overflowTimer定義の下辺りにでも。
vi /usr/lib/node_modules/mirakurun/lib/Mirakurun/TSFilter.js
:
this._overflowTimer = null;
this._loggingTimer = null;
:
_write(chunk, encoding, callback) {
if (Math.round(this._readableState.length*100/this.highWaterMark)>0 && (this._loggingTimer === null)) {
this._loggingTimer = log.info("bufchk id:%d buf:%d/%d(%d%)", this._targetNetworkId, this._readableState.length, this.highWaterMark, Math.round(this._readableState.length*100/this.highWaterMark));
setTimeout(() => { this._loggingTimer = null; }, 1000);
}
これでmirakurun_stdout.logの方にバッファサイズの報告がなされるようになった。しばらく運用していると256MBでもぎりぎりのときがあったので512MBに変更した。これだと複数のバッファが膨張した時にプロセスサイズを超える恐れがあるが、今まで複数のstreamにおいてバッファが膨張したことはほぼなかったので、おそらく大丈夫だろう。
これでmirakurunにおけるバッファ枯渇は起きなくなったが、それでもたまに録画失敗が。rivarunの方には問題ないので、リアルタイム・エンコーディングのためにpipeしているQSVのffmpeg処理に問題があると判断。rivarunをteeしてtsファイルとmp4ファイル(ffmpegのh264_qsv)に同時書き込みしていたのを別プロセス化することにした。rivarunは同じチャネルであれば、1つのrecpt1処理で複数のstreamを扱うことができるので、こういう時に便利。中断処理の修正が面倒だから1コマンドでやってただけ。epgrec UNAのReservation.class.phpを以下のように修正。
vi Reservation.class.php
:
$basename = basename($filename, $RECORD_MODE[$mode]['suffix'])
$cmd_ts = '/usr/bin/rivarun '.$slc_cmd['b25'].$device.$sid.' --ch '.$smf_type.'/'.$crec_->channel.' '.$duration.' "'.$add_dir.$basename'.ts" &'.$falldely;
fwrite($pipes[0], $cmd_ts."\n" );
$cmd_mp4 = '/usr/bin/rivarun '.$slc_cmd['b25'].$device.$sid.' --ch '.$smf_type.'/'.$crec_->channel.' '.$duration.' - | ffmpeg -y -v error -nostdin '.$monomode.'-i pipe:0 -f mp4 -preset medium -tune film -vcodec h264_qsv -s 1280x720 -vf yadif -vb 4500k -acodec aac -strict -2 -ac 2 -ar 48000 -ab 128k -threads 0 "'.$add_dir.$basename'.mp4"'.$falldely;
fwrite($pipes[0], $cmd_mp4."\n" );
このプロセス分離によって、最悪QSVエンコードが刺さっても録画処理が影響を受けることはなくなった。今でも何度かffmpegがハングることはあるが、録画処理が異常を起こすことは皆無となった。ふう、やっと一安心。QSVエンコードがハングってしまうとプロセスがkillできなくなってOS再起動するしかなくなるんだよな。ここもちょっと見直すかな。