Open marcoeg opened 7 years ago
Without nginx ping, after the crash (simultaneous on both containers and after a play request) the log is providing a more useful trace:
root@cfb6d0aee5c8:/# cat /var/log/nginx/debug.log
2017/04/25 23:57:36 [notice] 1#0: using the "epoll" event method
2017/04/25 23:57:36 [notice] 1#0: nginx/1.11.13
2017/04/25 23:57:36 [notice] 1#0: built by gcc 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.4)
2017/04/25 23:57:36 [notice] 1#0: OS: Linux 4.4.59-boot2docker
2017/04/25 23:57:36 [notice] 1#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576
2017/04/25 23:57:36 [notice] 1#0: start worker processes
2017/04/25 23:57:36 [notice] 1#0: start worker process 5
2017/04/25 23:57:43 [info] 5#0: *1 client connected '10.255.0.4'
2017/04/25 23:57:43 [info] 5#0: *1 connect: app='src' args='' flashver='' swf_url='' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:43 [debug] 5#0: *1 live: onFCPublish: stream='74DA386E1AB9:a2f0d6:2'
2017/04/25 23:57:43 [info] 5#0: *1 createStream, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:43 [info] 5#0: *1 publish: name='74DA386E1AB9:a2f0d6:2' args='' type=live silent=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:43 [info] 5#0: *1 relay: got metadata from @setDataFrame invocation from publisher., client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:49 [info] 5#0: *2 client connected '10.255.0.4'
2017/04/25 23:57:49 [info] 5#0: *2 connect: app='src' args='' flashver='' swf_url='' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:49 [debug] 5#0: *2 live: onFCPublish: stream='74DA386E1AB9:a2f0d6:3'
2017/04/25 23:57:49 [info] 5#0: *2 createStream, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:49 [info] 5#0: *2 publish: name='74DA386E1AB9:a2f0d6:3' args='' type=live silent=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:49 [info] 5#0: *2 relay: got metadata from @setDataFrame invocation from publisher., client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:57 [info] 5#0: *3 client connected '10.255.0.4'
2017/04/25 23:57:57 [info] 5#0: *3 connect: app='src' args='' flashver='' swf_url='' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:57 [debug] 5#0: *3 live: onFCPublish: stream='74DA386E1AB9:a2f0d6:5'
2017/04/25 23:57:57 [info] 5#0: *3 createStream, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:57 [info] 5#0: *3 publish: name='74DA386E1AB9:a2f0d6:5' args='' type=live silent=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:57:57 [info] 5#0: *3 relay: got metadata from @setDataFrame invocation from publisher., client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:58:59 [info] 5#0: *4 client connected '10.255.0.4'
2017/04/25 23:58:59 [info] 5#0: *4 connect: app='src' args='' flashver='LNX 25,0,0,148' swf_url='http://releases.flowplayer.org/swf/flowplayer-3.2.18.swf' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=3575 vcodecs=252 object_encoding=3, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:58:59 [info] 5#0: *4 createStream, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:58:59 [info] 5#0: *4 play: name='74DA386E1AB9:a2f0d6:1' args='' start=-1000 duration=0 reset=0 silent=0, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:58:59 [debug] 5#0: *4 log: ngx_rtmp_log_play
2017/04/25 23:58:59 [debug] 5#0: *4 log: ngx_rtmp_log_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 notify: ngx_rtmp_notify_play
2017/04/25 23:58:59 [debug] 5#0: *4 notify: ngx_rtmp_notify_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 exec: ngx_rtmp_exec_play
2017/04/25 23:58:59 [debug] 5#0: *4 exec: ngx_rtmp_exec_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 relay: ngx_rtmp_relay_play
2017/04/25 23:58:59 [debug] 5#0: *4 relay: ngx_rtmp_relay_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 play: ngx_rtmp_play_play
2017/04/25 23:58:59 [debug] 5#0: *4 play: ngx_rtmp_play_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 live: ngx_rtmp_live_play
2017/04/25 23:58:59 [debug] 5#0: *4 live: ngx_rtmp_live_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 access: ngx_rtmp_access_play
2017/04/25 23:58:59 [debug] 5#0: *4 access: ngx_rtmp_access_play: next
2017/04/25 23:58:59 [debug] 5#0: *4 cmd: ngx_rtmp_cmd_play
2017/04/25 23:59:12 [info] 5#0: *4 disconnect, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:59:12 [info] 5#0: *4 deleteStream, client: 10.255.0.4, server: 0.0.0.0:12345
2017/04/25 23:59:12 [notice] 1#0: signal 17 (SIGCHLD) received
2017/04/25 23:59:12 [alert] 1#0: worker process 5 exited on signal 11 (core dumped)
2017/04/25 23:59:12 [notice] 1#0: start worker process 16
root@cfb6d0aee5c8:/#
Try removing the colon from the stream names.
-- Michael McConnell WINK Streaming; email: michael@winkstreaming.com mailto:michael@winkstreaming.com phone: +1 312 281-5433 x 7400 cell: +506 8706-2389 skype: wink-michael web: http://winkstreaming.com http://winkstreaming.com/
On Apr 25, 2017, at 6:03 PM, Marco Graziano notifications@github.com wrote:
Without nginx ping, after the crash (simultaneous on both containers and after a play request) the log is providing a more useful trace:
root@cfb6d0aee5c8:/# cat /var/log/nginx/debug.log 2017/04/25 23:57:36 [notice] 1#0: using the "epoll" event method 2017/04/25 23:57:36 [notice] 1#0: nginx/1.11.13 2017/04/25 23:57:36 [notice] 1#0: built by gcc 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.4) 2017/04/25 23:57:36 [notice] 1#0: OS: Linux 4.4.59-boot2docker 2017/04/25 23:57:36 [notice] 1#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576 2017/04/25 23:57:36 [notice] 1#0: start worker processes 2017/04/25 23:57:36 [notice] 1#0: start worker process 5 2017/04/25 23:57:43 [info] 5#0: 1 client connected '10.255.0.4' 2017/04/25 23:57:43 [info] 5#0: 1 connect: app='src' args='' flashver='' swf_url='' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:43 [debug] 5#0: 1 live: onFCPublish: stream='74DA386E1AB9:a2f0d6:2' 2017/04/25 23:57:43 [info] 5#0: 1 createStream, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:43 [info] 5#0: 1 publish: name='74DA386E1AB9:a2f0d6:2' args='' type=live silent=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:43 [info] 5#0: 1 relay: got metadata from @setDataFrame invocation from publisher., client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:49 [info] 5#0: 2 client connected '10.255.0.4' 2017/04/25 23:57:49 [info] 5#0: 2 connect: app='src' args='' flashver='' swf_url='' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:49 [debug] 5#0: 2 live: onFCPublish: stream='74DA386E1AB9:a2f0d6:3' 2017/04/25 23:57:49 [info] 5#0: 2 createStream, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:49 [info] 5#0: 2 publish: name='74DA386E1AB9:a2f0d6:3' args='' type=live silent=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:49 [info] 5#0: 2 relay: got metadata from @setDataFrame invocation from publisher., client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:57 [info] 5#0: 3 client connected '10.255.0.4' 2017/04/25 23:57:57 [info] 5#0: 3 connect: app='src' args='' flashver='' swf_url='' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:57 [debug] 5#0: 3 live: onFCPublish: stream='74DA386E1AB9:a2f0d6:5' 2017/04/25 23:57:57 [info] 5#0: 3 createStream, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:57 [info] 5#0: 3 publish: name='74DA386E1AB9:a2f0d6:5' args='' type=live silent=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:57:57 [info] 5#0: 3 relay: got metadata from @setDataFrame invocation from publisher., client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:58:59 [info] 5#0: 4 client connected '10.255.0.4' 2017/04/25 23:58:59 [info] 5#0: 4 connect: app='src' args='' flashver='LNX 25,0,0,148' swf_url='http://releases.flowplayer.org/swf/flowplayer-3.2.18.swf' tc_url='rtmp://192.168.99.100:12345/src' page_url='' acodecs=3575 vcodecs=252 object_encoding=3, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:58:59 [info] 5#0: 4 createStream, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:58:59 [info] 5#0: 4 play: name='74DA386E1AB9:a2f0d6:1' args='' start=-1000 duration=0 reset=0 silent=0, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:58:59 [debug] 5#0: 4 log: ngx_rtmp_log_play 2017/04/25 23:58:59 [debug] 5#0: 4 log: ngx_rtmp_log_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 notify: ngx_rtmp_notify_play 2017/04/25 23:58:59 [debug] 5#0: 4 notify: ngx_rtmp_notify_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 exec: ngx_rtmp_exec_play 2017/04/25 23:58:59 [debug] 5#0: 4 exec: ngx_rtmp_exec_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 relay: ngx_rtmp_relay_play 2017/04/25 23:58:59 [debug] 5#0: 4 relay: ngx_rtmp_relay_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 play: ngx_rtmp_play_play 2017/04/25 23:58:59 [debug] 5#0: 4 play: ngx_rtmp_play_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 live: ngx_rtmp_live_play 2017/04/25 23:58:59 [debug] 5#0: 4 live: ngx_rtmp_live_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 access: ngx_rtmp_access_play 2017/04/25 23:58:59 [debug] 5#0: 4 access: ngx_rtmp_access_play: next 2017/04/25 23:58:59 [debug] 5#0: 4 cmd: ngx_rtmp_cmd_play 2017/04/25 23:59:12 [info] 5#0: 4 disconnect, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:59:12 [info] 5#0: *4 deleteStream, client: 10.255.0.4, server: 0.0.0.0:12345 2017/04/25 23:59:12 [notice] 1#0: signal 17 (SIGCHLD) received 2017/04/25 23:59:12 [alert] 1#0: worker process 5 exited on signal 11 (core dumped) 2017/04/25 23:59:12 [notice] 1#0: start worker process 16 root@cfb6d0aee5c8:/# — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/sergey-dryabzhinsky/nginx-rtmp-module/issues/241#issuecomment-297199688, or mute the thread https://github.com/notifications/unsubscribe-auth/AE8hYXy5k0zd_IdahiPe7_AYk27HpxkCks5rzonVgaJpZM4NILNu.
@winkmichael: interesting suggestion, but I have been using the colon in the video keys and it is not the problem.
Actually, the crash is not because the ngnix container runs in a swarm. I started the same image in a single docker container on the VM not in a swarm and it crashed as well.
This is the Dockerfile:
FROM buildpack-deps:xenial
# Versions of Nginx and nginx-rtmp-module to use
#ENV NGINX_VERSION nginx-1.11.5
ENV NGINX_VERSION nginx-1.11.13
# Install dependencies
RUN apt-get update && \
apt-get install -y ca-certificates openssl libssl-dev libpcre3 libpcre3-dev git libav-tools gdb && \
rm -rf /var/lib/apt/lists/*
# Download and decompress Nginx
RUN mkdir -p /tmp/build/nginx && \
cd /tmp/build/nginx && \
wget -O ${NGINX_VERSION}.tar.gz https://nginx.org/download/${NGINX_VERSION}.tar.gz && \
tar -zxf ${NGINX_VERSION}.tar.gz
# https://github.com/sergey-dryabzhinsky/nginx-rtmp-module/archive/dev.zip
RUN cd /tmp/build && \
git clone https://github.com/sergey-dryabzhinsky/nginx-rtmp-module.git && \
cd nginx-rtmp-module
# Build and install Nginx - ~/nginx-1.11.5$ ./configure --with-http_ssl_module --with-http_stub_status_module --add-module=../nginx-rtmp-module
# The default puts everything under /usr/local/nginx, so it's needed to change
#~/nginx-1.11.5$ ./configure --with-http_ssl_module --with-http_stub_status_module --add-module=../nginx-rtmp-module
# it explicitly. Not just for order but to have it in the PATH
RUN cd /tmp/build/nginx/${NGINX_VERSION} && \
./configure \
--sbin-path=/usr/local/sbin/nginx \
# --conf-path=/etc/nginx/nginx.conf \
--error-log-path=/var/log/nginx/error.log \
--pid-path=/var/run/nginx/nginx.pid \
--lock-path=/var/lock/nginx/nginx.lock \
--http-log-path=/var/log/nginx/access.log \
--http-client-body-temp-path=/tmp/nginx-client-body \
--with-http_stub_status_module \
--with-http_ssl_module \
--with-debug \
--add-module=/tmp/build/nginx-rtmp-module && \
make -j $(getconf _NPROCESSORS_ONLN) && \
make install && \
mkdir /var/lock/nginx /video /video/chunked && \
chmod 777 /video /video/chunked && \
cp /tmp/build/nginx-rtmp-module/stat.xsl /usr/local/nginx && \
rm -rf /tmp/build
# Forward logs to Docker
RUN ln -sf /dev/stdout /var/log/nginx/access.log && \
ln -sf /dev/stderr /var/log/nginx/error.log
# Set up config file
#COPY nginx.conf /etc/nginx/nginx.conf
COPY nginx.conf /usr/local/nginx/conf
EXPOSE 12345
CMD ["nginx", "-g", "daemon off;"]
The docker image is on the Docker hub:
Try to use only 1 worker per nginx.
@sergey it is already 1 worker.
user root;
env PATH;
worker_processes 1;
pid /var/run/nginx/nginx.pid;
worker_rlimit_core 500M;
working_directory /;
error_log /var/log/nginx/debug.log debug;
rtmp_auto_push off;
events {
worker_connections 1024;
}
http {
include /usr/local/nginx/conf/mime.types;
default_type application/octet-stream;
sendfile on;
keepalive_timeout 65;
server {
listen 80;
server_name localhost;
# rtmp stat
location /stat {
rtmp_stat all;
rtmp_stat_stylesheet stat.xsl;
}
location /stat.xsl {
# you can move stat.xsl to a different location
root /usr/local/nginx;
}
# rtmp stat
location /stat.xml {
rtmp_stat all;
}
# rtmp control
location /control {
rtmp_control all;
}
error_page 500 502 503 504 /50x.html;
location = /50x.html {
root html;
}
}
}
rtmp {
server {
listen 12345;
chunk_size 4096;
ping 30s;
application src {
allow play all;
live on;
interleave on;
record_unique on;
record all;
record_interval 5m;
record_path /video/chunked;
}
}
}
I have pushed the latest image to docker hub.
To replicate:
$ docker run -d -p 12345:12345 -p 80:80 marcoeg/rtmp:2.0
$ ffmpeg -re -i 74DA386E1AB9.flv -c:v copy -c:a copy -f flv rtmp://localhost:12345/src/74DA386E1AB92
$ rtmpdump -r rtmp://localhost:12345/src/74DA386E1AB9 > /dev/null
Stopping rtmpdump causes nginx to crash consistently.
...
2017/04/26 15:38:02 [debug] 7#0: *1 write: 11, 0000000002D3E1F1, 128, 8341416
2017/04/26 15:38:02 [debug] 7#0: *1 write: 11, 0000000002D3E2E9, 128, 8341544
2017/04/26 15:38:02 [debug] 7#0: *1 write: 11, 0000000002D3E3E1, 35, 8341672
2017/04/26 15:38:02 [debug] 7#0: *1 write: 11, 00007FFE469496A0, 4, 8341707
2017/04/26 15:38:02 [debug] 7#0: *1 calling handler 2
2017/04/26 15:38:02 [debug] 7#0: *1 live: video packet timestamp=65299
2017/04/26 15:38:02 [debug] 7#0: *1 RTMP prep video (9) fmt=1 csid=7 timestamp=33 mlen=3107 msid=1 nbufs=1
2017/04/26 15:38:02 [debug] 7#0: *1 calling handler 3
2017/04/26 15:38:02 [debug] 7#0: *1 calling handler 4
2017/04/26 15:38:02 [debug] 7#0: *1 recv: eof:0, avail:0
2017/04/26 15:38:02 [debug] 7#0: timer delta: 1
2017/04/26 15:38:02 [debug] 7#0: worker cycle
2017/04/26 15:38:02 [debug] 7#0: epoll timer: 1
2017/04/26 15:38:02 [debug] 7#0: timer delta: 2
2017/04/26 15:38:02 [debug] 7#0: *6 event timer del: -1: 1493221082921
2017/04/26 15:38:03 [notice] 1#0: signal 17 (SIGCHLD) received
2017/04/26 15:38:03 [alert] 1#0: worker process 7 exited on signal 11 (core dumped)
2017/04/26 15:38:03 [debug] 1#0: shmtx forced unlock
2017/04/26 15:38:03 [debug] 1#0: wake up, sigio 0
2017/04/26 15:38:03 [debug] 1#0: reap children
2017/04/26 15:38:03 [debug] 1#0: child: 0 7 e:0 t:1 d:0 r:1 j:0
2017/04/26 15:38:03 [debug] 1#0: channel 3:8
2017/04/26 15:38:03 [notice] 1#0: start worker process 20
For what is worth, using v1.1.7-228-g9c71ce6 rather than the head of the tree does not crash nginx.
commit 9c71ce676198b0a75920bb485727b4f2f0cbdc7e
Merge: dc76eb2 d86287f
Author: Sergey <sergey.dryabzhinsky@gmail.com>
Date: Wed Nov 30 03:23:10 2016 +0300
Merge pull request #202 from fserreau/dev
Fixed record from infinite loop
I am using the rtmp module with nginx 1.11.13 built into a docker container from source (dev branch).
When running two containers in two VMs configured as a swarm, I get an almost simultaneous crash of the two nginx, after about 90 seconds of streaming 5 video sources to the swarm with ffmpeg from the host running the VMs:
Notice the streams are all to the same IP address of one of the VMs (with different names) and the docker load balancer nicely distributes 3 streams to one container and 2 to the other.
This is the backtrace (same for both):
These are the last few lines of the debug log:
This is a configuration that is running well on a single instance on AWS. I suspect something may go wrong with the docker swarm internal load balancer. I am prepared to try running the containers in an overlay network with a custom proxy.
Any assistance would be greatly appreciated.