search

sergey-dryabzhinsky / nginx-rtmp-module

NGINX-based Media Streaming Server
http://nginx-rtmp.blogspot.com
BSD 2-Clause "Simplified" License
1.02k stars 214 forks source link

Crash when rtmp viewer disconnects #242

Closed MustafaMunir closed 7 years ago

MustafaMunir commented 7 years ago

I am using the rtmp module from dev branch with nginx-1.11.13 and observing worker process crash as soon as rtmp viewer stops.

Gstreamer streaming pipeline:

gst-launch-1.0 videotestsrc is-live=true ! queue ! videoconvert ! x264enc bitrate=360 tune=zerolatency key-int-max=8 ! video/x-h264, profile=baseline ! queue ! flvmux name=mux audiotestsrc is-live=true ! audioconvert ! voaacenc bitrate=128000 ! queue ! mux.   mux. ! rtmpsink location="rtmp://127.0.0.1:1935/myapp/live live=1"

Backtrace:

#0  0x0000000000429e4a in ngx_rbtree_delete (tree=0xeafc80 <ngx_event_timer_rbtree>, node=0x21a0c28) at src/core/ngx_rbtree.c:298
#1  0x0000000000478f3c in ngx_event_del_timer (ev=0x21a0c00) at src/event/ngx_event_timer.h:38
#2  0x000000000047fde7 in ngx_http_keepalive_handler (rev=0x21a0c00) at src/http/ngx_http_request.c:3199
#3  0x000000000045af4b in ngx_epoll_process_events (cycle=0x216a120, timer=269, flags=1) at src/event/modules/ngx_epoll_module.c:902
#4  0x00000000004491d1 in ngx_process_events_and_timers (cycle=0x216a120) at src/event/ngx_event.c:242
#5  0x000000000045859d in ngx_worker_process_cycle (cycle=0x216a120, data=0x0) at src/os/unix/ngx_process_cycle.c:749
#6  0x0000000000454c68 in ngx_spawn_process (cycle=0x216a120, proc=0x4584b6 <ngx_worker_process_cycle>, data=0x0, name=0x540783 "worker process", respawn=-3) at src/os/unix/ngx_process.c:198
#7  0x0000000000457351 in ngx_start_worker_processes (cycle=0x216a120, n=1, type=-3) at src/os/unix/ngx_process_cycle.c:358
#8  0x00000000004568f7 in ngx_master_process_cycle (cycle=0x216a120) at src/os/unix/ngx_process_cycle.c:130
#9  0x0000000000412621 in main (argc=3, argv=0x7ffdd13494c8) at src/core/nginx.c:375

Nginx Configuration: 

worker_processes  1;

error_log  /var/log/nginx/error.log debug;
worker_rlimit_core 500m;
working_directory /tmp/cores/;
pid /usr/local/nginx/logs/nginx.pid;

events {
    worker_connections  1024;
}

rtmp {
    respawn on;
    server {
        listen 1935;
        publish_time_fix off; # compatibility with GStreamer
        max_streams 512;

        application myapp {
            live on;
            publish_notify off;
        }
    }
}

http {
    server {
        listen      8080;

        location /stat {
            rtmp_stat all;
            rtmp_stat_stylesheet stat.xsl;
        }

        location /stat.xsl {
            root /home/ubuntu/work/streaming/nginx-rtmp-module/;
        }

        location /control {
            rtmp_control all;
        }

        location /rtmp-publisher {
            root /home/ubuntu/work/streaming/nginx-rtmp-module/test;
        }   

        location / {
            root /home/ubuntu/work/streaming/nginx-rtmp-module/test/www;
        }
    }
}

nginx -V

ubuntu@ip-172-31-30-159:/usr/local$ nginx/sbin/nginx -V
nginx version: nginx/1.11.13
built by gcc 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.4)
built with OpenSSL 1.0.2g  1 Mar 2016
TLS SNI support enabled
configure arguments: --with-http_ssl_module --add-module=../nginx-rtmp-module --with-debug --with-cc-opt='-O0 -g'

Debug Log:

2017/05/12 03:43:11 [debug] 10505#0: *27 recv: eof:0, avail:1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: fd:11 129 of 129
2017/05/12 03:43:11 [debug] 10505#0: *27 reusing formerly read data: 17
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP bheader fmt=3 csid=4
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP mheader fmt=3 video (9) time=64366+5 mlen=993 len=640 msid=1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: eof:0, avail:1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: fd:11 129 of 129
2017/05/12 03:43:11 [debug] 10505#0: *27 reusing formerly read data: 17
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP bheader fmt=3 csid=4
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP mheader fmt=3 video (9) time=64366+5 mlen=993 len=768 msid=1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: eof:0, avail:1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: fd:11 129 of 129
2017/05/12 03:43:11 [debug] 10505#0: *27 reusing formerly read data: 17
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP bheader fmt=3 csid=4
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP mheader fmt=3 video (9) time=64366+5 mlen=993 len=896 msid=1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: eof:0, avail:1
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: fd:11 81 of 129
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP recv video (9) csid=4 timestamp=64371 mlen=993 msid=1 nbufs=8
2017/05/12 03:43:11 [debug] 10505#0: *27 nhandlers: 5
2017/05/12 03:43:11 [debug] 10505#0: *27 calling handler 0
2017/05/12 03:43:11 [debug] 10505#0: *27 calling handler 1
2017/05/12 03:43:11 [debug] 10505#0: *27 calling handler 2
2017/05/12 03:43:11 [debug] 10505#0: *27 live: video packet timestamp=64371
2017/05/12 03:43:11 [debug] 10505#0: *27 RTMP prep video (9) fmt=1 csid=7 timestamp=33 mlen=993 msid=1 nbufs=1
2017/05/12 03:43:11 [debug] 10505#0: *27 calling handler 3
2017/05/12 03:43:11 [debug] 10505#0: *27 calling handler 4
2017/05/12 03:43:11 [debug] 10505#0: *27 recv: eof:0, avail:0
2017/05/12 03:43:11 [debug] 10505#0: timer delta: 0
2017/05/12 03:43:11 [debug] 10505#0: worker cycle
2017/05/12 03:43:11 [debug] 10505#0: epoll timer: 1
2017/05/12 03:43:11 [debug] 10505#0: timer delta: 2
2017/05/12 03:43:11 [debug] 10505#0: *30 event timer del: -1: 1494560591124
2017/05/12 03:43:11 [notice] 10503#0: signal 17 (SIGCHLD) received
2017/05/12 03:43:11 [alert] 10503#0: worker process 10505 exited on signal 11 (core dumped)
2017/05/12 03:43:11 [debug] 10503#0: shmtx forced unlock
2017/05/12 03:43:11 [debug] 10503#0: wake up, sigio 0
2017/05/12 03:43:11 [debug] 10503#0: reap children
2017/05/12 03:43:11 [debug] 10503#0: child: 0 10505 e:0 t:1 d:0 r:1 j:0
2017/05/12 03:43:11 [debug] 10503#0: channel 3:8
2017/05/12 03:43:11 [notice] 10503#0: start worker process 10565
2017/05/12 03:43:11 [debug] 10503#0: sigsuspend
2017/05/12 03:43:11 [debug] 10565#0: add cleanup: 00000000019FB908
2017/05/12 03:43:11 [debug] 10565#0: malloc: 00000000019CAAF0:8
2017/05/12 03:43:11 [debug] 10565#0: notify eventfd: 10
2017/05/12 03:43:11 [debug] 10565#0: testing the EPOLLRDHUP flag: success
2017/05/12 03:43:11 [debug] 10565#0: malloc: 00000000019E7190:6144
2017/05/12 03:43:11 [debug] 10565#0: malloc: 00007F51A3740010:237568
2017/05/12 03:43:11 [debug] 10565#0: malloc: 0000000001A01AE0:98304
2017/05/12 03:43:11 [debug] 10565#0: malloc: 0000000001A19AF0:98304
2017/05/12 03:43:11 [debug] 10565#0: epoll add event: fd:6 op:1 ev:00002001
2017/05/12 03:43:11 [debug] 10565#0: epoll add event: fd:7 op:1 ev:00002001
2017/05/12 03:43:11 [debug] 10565#0: epoll add event: fd:8 op:1 ev:00002001
2017/05/12 03:43:11 [debug] 10565#0: setproctitle: "nginx: worker process"
2017/05/12 03:43:11 [debug] 10565#0: worker cycle
2017/05/12 03:43:11 [debug] 10565#0: epoll timer: -1
2017/05/12 03:43:11 [debug] 10565#0: epoll: fd:7 ev:0001 d:00007F51A37400F8
2017/05/12 03:43:11 [debug] 10565#0: accept on 0.0.0.0:8080, ready: 0
2017/05/12 03:43:11 [debug] 10565#0: posix_memalign: 00000000019E89A0:512 @16
2017/05/12 03:43:11 [debug] 10565#0: *32 accept: 203.42.113.14:51254 fd:3
2017/05/12 03:43:11 [debug] 10565#0: *32 event timer add: 3: 60000:1494560651379
2017/05/12 03:43:11 [debug] 10565#0: *32 reusable connection: 1
2017/05/12 03:43:11 [debug] 10565#0: *32 epoll add event: fd:3 op:1 ev:80002001
2017/05/12 03:43:11 [debug] 10565#0: timer delta: 238
2017/05/12 03:43:11 [debug] 10565#0: worker cycle
2017/05/12 03:43:11 [debug] 10565#0: epoll timer: 60000

Can you spot anything wrong in configuration or any guidance regarding areas to investigate would be very helpful

MustafaMunir commented 7 years ago

I have noted that before the following commit this crash was not happening.

commit 542106e4de1a3417b7987eade1cbc071dd2bd05e
Merge: 9121b34 ebe697b
Author: Sergey <sergey.dryabzhinsky@gmail.com>
Date:   Sat Apr 15 21:08:29 2017 +0300

    Merge pull request #199 from sergey-dryabzhinsky/drop-all-connections-on-reload

    Add event-based handle of reload/exit signal
marcoeg commented 7 years ago

This may be related to #241 "crash -- in a docker container (and not only)".

tanabi commented 7 years ago

I'm getting this as well, and reverting to commit 9121b34bdcf684147a80bb3e9f0d7241f7375f5c (the one before the commit noted by MustafaMunir) resolved the problem. So there's something toxic in that commit I think :)

sergey-dryabzhinsky commented 7 years ago

Reverted #199. Really weird shit.