nginx rtmp moduleのログ出力を強化する

Cloudn途中で映像配信止まるがnginxのログ出力がイマイチで原因がよく掴めない。

エンコーダは動き続けているし、rtmp-moduleの側も、エンコーダからのPublishが始まったログしかなくて、何が起こっているのかさっぱり。

[29/Sep/2016:17:16:32 +0900] PUBLISH "live" "test" "" - 143403833 607 "" "FMLE/3.0 (compatible; FMSc/1.0)" (3h 45m 51s)

で、みつけたのがこの記事
https://github.com/arut/nginx-rtmp-module/wiki/Debug-log

cd nginx-X.Y.Z
./configure --add-module=/path/to/nginx-rtmp-module --with-debug ...

デバッグログを出せるらしい。では、一度インストールしたnginxを削除して、もう一度 –with-debugオプション付けて Makeinstallしてみる。

nginxのインストールから始める場合はこちら

まずはnginxを止める

/usr/sbin/nginx -s stop

uninstallだけど Makefileにuninstall:の項目がない。それに

install:
$(MAKE) -f objs/Makefile install

と書いてあるだけでフォルダ構成も書いてない。なので、インストール時のログを頼りに

sudo ./configure --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --add-module=../nginx-rtmp-module --prefix=/usr/local/nginx
nginx path prefix: "/usr/local/nginx"
nginx binary file: "/usr/sbin/nginx"
nginx configuration prefix: "/etc/nginx"
nginx configuration file: "/etc/nginx/nginx.conf"
nginx pid file: "/usr/local/nginx/logs/nginx.pid"
nginx error log file: "/usr/local/nginx/logs/error.log"
nginx http access log file: "/usr/local/nginx/logs/access.log"
nginx http client request body temporary files: "client_body_temp"
nginx http proxy temporary files: "proxy_temp"
nginx http fastcgi temporary files: "fastcgi_temp"
nginx http uwsgi temporary files: "uwsgi_temp"
nginx http scgi temporary files: "scgi_temp"

sudo rm -r /usr/local/nginx
sudo rm -r /etc/nginx
sudo rm /usr/sbin/nginx

を実行して、手動で関連ファイルを削除する。
※もちろん削除するまえに nginx.conf や、コンパイルしたvideojsや、htmlファイルはバックアップをとっておく

sudo make clean
sudo ./configure --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --add-module=../nginx-rtmp-module --with-debug --prefix=/usr/local/nginx
nginx path prefix: "/usr/local/nginx"
nginx binary file: "/usr/sbin/nginx"
nginx configuration prefix: "/etc/nginx"
nginx configuration file: "/etc/nginx/nginx.conf"
nginx pid file: "/usr/local/nginx/logs/nginx.pid"
nginx error log file: "/usr/local/nginx/logs/error.log"
nginx http access log file: "/usr/local/nginx/logs/access.log"
nginx http client request body temporary files: "client_body_temp"
nginx http proxy temporary files: "proxy_temp"
nginx http fastcgi temporary files: "fastcgi_temp"
nginx http uwsgi temporary files: "uwsgi_temp"
nginx http scgi temporary files: "scgi_temp"

sudo make install

バックアップしておいたnginxファイルを復元

sudo mv nginx.conf nginx.conf-
sudo cp /home/ubuntu/bakupnginx/nginx.conf .

nginxの詳細ログが吐かれるように変更

sudo vi nginx.conf
error_log logs/error.log debug;

rtmpとhlsの設定はこちらを参照

https://www.techlive.tokyo/archives/1304

配信用のディレクトリを作成

sudo mkdir /usr/local/nginx/html/live
sudo mkdir /usr/local/nginx/live/html/hls

以前作ったvideojsなどを再配置

sudo cp /home/ubuntu/bakupnginx/index.html /usr/local/nginx/html/live/
sudo cp -R /home/ubuntu/bakupnginx/videojs/ /usr/local/nginx/html/live/

nginx 起動

sudo /usr/sbin/nginx

明らかにログの量が増えてる

Server: nginx/1.8.0
Date: Thu, 29 Sep 2016 22:32:42 GMT
Content-Type: text/html
Content-Length: 168
Connection: keep-alive

2016/09/30 07:32:42 [debug] 1178#0: *1 write new buf t:1 f:0 0000000001C88360, pos 0000000001C88360, size: 154 file: 0, size: 0
2016/09/30 07:32:42 [debug] 1178#0: *1 http write filter: l:0 f:0 s:154
2016/09/30 07:32:42 [debug] 1178#0: *1 http output filter "/live/hls/test.m3u8?"
2016/09/30 07:32:42 [debug] 1178#0: *1 http copy filter: "/live/hls/test.m3u8?"
2016/09/30 07:32:42 [debug] 1178#0: *1 http postpone filter "/live/hls/test.m3u8?" 0000000001C90280
2016/09/30 07:32:42 [debug] 1178#0: *1 write old buf t:1 f:0 0000000001C88360, pos 0000000001C88360, size: 154 file: 0, size: 0
2016/09/30 07:32:42 [debug] 1178#0: *1 write new buf t:0 f:0 0000000000000000, pos 00000000006E0F60, size: 116 file: 0, size: 0
2016/09/30 07:32:42 [debug] 1178#0: *1 write new buf t:0 f:0 0000000000000000, pos 00000000006E16A0, size: 52 file: 0, size: 0
2016/09/30 07:32:42 [debug] 1178#0: *1 http write filter: l:1 f:0 s:322
2016/09/30 07:32:42 [debug] 1178#0: *1 http write filter limit 0
2016/09/30 07:32:42 [debug] 1178#0: *1 writev: 322 of 322
2016/09/30 07:32:42 [debug] 1178#0: *1 http write filter 0000000000000000
2016/09/30 07:32:42 [debug] 1178#0: *1 http copy filter: 0 "/live/hls/test.m3u8?"
2016/09/30 07:32:42 [debug] 1178#0: *1 http finalize request: 0, "/live/hls/test.m3u8?" a:1, c:1
2016/09/30 07:32:42 [debug] 1178#0: *1 set http keepalive handler
2016/09/30 07:32:42 [debug] 1178#0: *1 http close request
2016/09/30 07:32:42 [debug] 1178#0: *1 http log handler
2016/09/30 07:32:42 [debug] 1178#0: *1 free: 0000000001C8F2B0, unused: 0
2016/09/30 07:32:42 [debug] 1178#0: *1 free: 0000000001C88340, unused: 3425
2016/09/30 07:32:42 [debug] 1178#0: *1 free: 0000000001C8EEA0
2016/09/30 07:32:42 [debug] 1178#0: *1 hc free: 0000000000000000 0
2016/09/30 07:32:42 [debug] 1178#0: *1 hc busy: 0000000000000000 0
2016/09/30 07:32:42 [debug] 1178#0: *1 reusable connection: 1
2016/09/30 07:32:42 [debug] 1178#0: *1 event timer add: 12: 65000:1475188427326
2016/09/30 07:32:42 [debug] 1178#0: *1 post event 0000000001CB8788
2016/09/30 07:32:42 [debug] 1178#0: timer delta: 15
2016/09/30 07:32:42 [debug] 1178#0: posted event 0000000001CB8788
2016/09/30 07:32:42 [debug] 1178#0: *1 delete posted event 0000000001CB8788
2016/09/30 07:32:42 [debug] 1178#0: *1 http keepalive handler
2016/09/30 07:32:42 [debug] 1178#0: *1 malloc: 0000000001C8EEA0:1024
2016/09/30 07:32:42 [debug] 1178#0: *1 recv: fd:12 -1 of 1024
2016/09/30 07:32:42 [debug] 1178#0: *1 recv() not ready (11: Resource temporarily unavailable)
2016/09/30 07:32:42 [debug] 1178#0: *1 free: 0000000001C8EEA0
2016/09/30 07:32:42 [debug] 1178#0: worker cycle
2016/09/30 07:32:42 [debug] 1178#0: epoll timer: 55895

さぁ、これから原因究明だ‼