arut / nginx-rtmp-module

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

RTMP module, random crashes (core dump included) #326

Closed zenios closed 10 years ago

zenios commented 10 years ago

I have been experiencing random worker crashes that are not replicated with the same time.

I think it is related to on_play and on_play_done events when it happens, all clients are disconnected when the worker dies.

nginx-rtmp version 1.1.2 nginx version 1.5.8 Attached are the config files and core dump

From Error log: 2014/01/20 14:01:18 [notice] 26452#0: signal 17 (SIGCHLD) received 2014/01/20 14:01:18 [alert] 26452#0: worker process 26453 exited on signal 11 Download core and config here https://anonfiles.com/file/882ed00d1696f05f6010f0a47c18f1d9

arut commented 10 years ago

Core is useless without the binary. Could you post gdb backtrace and error/debug log?

zenios commented 10 years ago

warning: Could not load shared library symbols for linux-vdso.so.1. Do you need "set solib-search-path" or "set sysroot"? [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `nginx: w'. Program terminated with signal 11, Segmentation fault.

0 ngx_rtmp_hls_flush_audio (s=s@entry=0x1a0b3e0) at /opt/nginx-rtmp-module/hls/ngx_rtmp_hls_module.c:1420

1420 if (!ctx->opened) { (gdb) bt

0 ngx_rtmp_hls_flush_audio (s=s@entry=0x1a0b3e0) at /opt/nginx-rtmp-module/hls/ngx_rtmp_hls_module.c:1420

1 0x000000000049d441 in ngx_rtmp_hls_stream_eof (s=0x1a0b3e0, v=0x7fff4c807260) at /opt/nginx-rtmp-module/hls/ngx_rtmp_hls_module.c:1836

2 0x00000000004a015e in ngx_rtmp_dash_stream_eof (s=0x1a0b3e0, v=0x7fff4c807260) at /opt/nginx-rtmp-module/dash/ngx_rtmp_dash_module.c:1227

3 0x000000000047fa50 in ngx_rtmp_user_message_handler (s=0x1a0b3e0, h=, in=)

at /opt/nginx-rtmp-module/ngx_rtmp_receive.c:142

4 0x000000000047c45e in ngx_rtmp_receive_message (s=s@entry=0x1a0b3e0, h=h@entry=0x1b41c60, in=in@entry=0x1b43c60)

at /opt/nginx-rtmp-module/ngx_rtmp_handler.c:792

5 0x000000000047cba7 in ngx_rtmp_recv (rev=) at /opt/nginx-rtmp-module/ngx_rtmp_handler.c:457

6 0x0000000000426896 in ngx_epoll_process_events (cycle=0x1427480, timer=, flags=)

at src/event/modules/ngx_epoll_module.c:691

7 0x000000000041dc42 in ngx_process_events_and_timers (cycle=cycle@entry=0x1427480) at src/event/ngx_event.c:248

8 0x0000000000424e91 in ngx_worker_process_cycle (cycle=0x1427480, data=) at src/os/unix/ngx_process_cycle.c:816

9 0x0000000000423566 in ngx_spawn_process (cycle=cycle@entry=0x1427480, proc=proc@entry=0x424da2 , data=data@entry=0x0,

name=name@entry=0x4a6b56 "worker process", respawn=respawn@entry=-3) at src/os/unix/ngx_process.c:198

10 0x00000000004240b8 in ngx_start_worker_processes (cycle=cycle@entry=0x1427480, n=1, type=type@entry=-3) at src/os/unix/ngx_process_cycle.c:364

11 0x00000000004257bd in ngx_master_process_cycle (cycle=cycle@entry=0x1427480) at src/os/unix/ngx_process_cycle.c:136

12 0x00000000004076c3 in main (argc=, argv=) at src/core/nginx.c:407

As for the error log I prefer not to attach it since it contains sensitive information but below you will find some logs before and after the error.

2014/01/20 17:40:35 [info] 26979#0: 3740 client connected '1.2.3.4' 2014/01/20 17:40:35 [info] 26979#0: 3740 connect: app='local' args='' flashver='' swf_url='' tc_url='rtmp://mynginxserver/local' page_url='' acodecs=3191 vcodecs=252 object_encoding=0, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:35 [info] 26979#0: 3740 createStream, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:35 [info] 26979#0: 3740 play: name='channel1' args='' start=0 duration=0 reset=0 silent=0, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:35 [info] 26979#0: 3740 notify: play '127.0.0.1:99/start', client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:35 [info] 26979#0: 3740 relay: create pull name='channel1' app='' playpath='' url='encoder3/live', client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3740 deleteStream, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3740 notify: play_done '127.0.0.1:99/stop', client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3740 disconnect, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3740 deleteStream, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3743 client connected '1.2.3.4' 2014/01/20 17:40:38 [info] 26979#0: 3732 disconnect, client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3732 deleteStream, client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3732 notify: play_done '127.0.0.1:99/stop', client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:38 [info] 26979#0: 3737 disconnect, client: encoder1/live, server: ngx-relay 2014/01/20 17:40:38 [info] 26979#0: 3737 deleteStream, client: encoder1/live, server: ngx-relay 2014/01/20 17:40:38 [info] 26979#0: 3743 connect: app='local' args='' flashver='' swf_url='' tc_url='rtmp://mynginxserver/local' page_url='' acodecs=3191 vcodecs=252 object_encoding=0, client: 1.2.3.4, server: 0.0.0.0:1935 2014/01/20 17:40:39 [notice] 26978#0: signal 17 (SIGCHLD) received 2014/01/20 17:40:39 [alert] 26978#0: worker process 26979 exited on signal 11 (core dumped) 2014/01/20 17:40:39 [notice] 26978#0: start worker process 27467 2014/01/20 17:40:39 [info] 27467#0: 3745 client connected '4.5.6.7' 2014/01/20 17:40:39 [info] 27467#0: 3745 connect: app='encoder0' args='' flashver='' swf_url='' tc_url='rtmp://mynginxserver/encoder0' page_url='' acodecs=3191 vcodecs=252 object_encoding=0, client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:39 [info] 27467#0: 3745 createStream, client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:39 [info] 27467#0: 3746 client connected '87.228.155.189' 2014/01/20 17:40:40 [info] 27467#0: 3745 play: name='channel2' args='' start=0 duration=0 reset=0 silent=0, client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:40 [info] 27467#0: 3745 notify: play '127.0.0.1:99/start', client: 4.5.6.7, server: 0.0.0.0:1935 2014/01/20 17:40:40 [info] 27467#0: 3745 relay: create pull name='channel2' app='' playpath='' url='encoder0/live', client: 4.5.6.7, server: 0.0.0.0:1935

I do not have a debug log because until i catch the error, log file will get huge with debug logs on

arut commented 10 years ago

fixed! please try again thanks @paranomos

zenios commented 10 years ago

Thanks for fixing the problem.My question though is since ctx was NULL wasn't this supposed to happen on first user disconnection?Why did it happen at random times?

zenios commented 10 years ago

Also even though the first problem was fixed.It looks there is another problem.

Program terminated with signal 11, Segmentation fault.

0 ngx_rtmp_hls_close_fragment (s=s@entry=0x1e453f0)

at /opt/nginx-rtmp-module/hls/ngx_rtmp_hls_module.c:749

749 if (!ctx->opened) { (gdb) bt

0 ngx_rtmp_hls_close_fragment (s=s@entry=0x1e453f0)

at /opt/nginx-rtmp-module/hls/ngx_rtmp_hls_module.c:749

1 0x000000000049d459 in ngx_rtmp_hls_stream_eof (s=0x1e453f0,

v=0x7fff3213f760) at /opt/nginx-rtmp-module/hls/ngx_rtmp_hls_module.c:1838

2 0x00000000004a016e in ngx_rtmp_dash_stream_eof (s=0x1e453f0,

v=0x7fff3213f760)
at /opt/nginx-rtmp-module/dash/ngx_rtmp_dash_module.c:1227

3 0x000000000047fa50 in ngx_rtmp_user_message_handler (s=0x1e453f0,

h=<optimized out>, in=<optimized out>)
at /opt/nginx-rtmp-module/ngx_rtmp_receive.c:142

4 0x000000000047c45e in ngx_rtmp_receive_message (s=s@entry=0x1e453f0,

h=h@entry=0x1e461d0, in=in@entry=0x1e44190)
at /opt/nginx-rtmp-module/ngx_rtmp_handler.c:792

5 0x000000000047cba7 in ngx_rtmp_recv (rev=)

at /opt/nginx-rtmp-module/ngx_rtmp_handler.c:457

6 0x0000000000426896 in ngx_epoll_process_events (cycle=0x1cc6480,

timer=<optimized out>, flags=<optimized out>)
at src/event/modules/ngx_epoll_module.c:691

7 0x000000000041dc42 in ngx_process_events_and_timers (

cycle=cycle@entry=0x1cc6480) at src/event/ngx_event.c:248

8 0x0000000000424e91 in ngx_worker_process_cycle (cycle=0x1cc6480,

data=<optimized out>) at src/os/unix/ngx_process_cycle.c:816

9 0x0000000000423566 in ngx_spawn_process (cycle=cycle@entry=0x1cc6480,

Maybe this has to changed to if (ctx == NULL || !ctx->opened) like the previous commit?

zenios commented 10 years ago

And one final question.Why does hls module comes in play since its disabled from the configuration?

arut commented 10 years ago

Fixed the crash, thanks.

It's not random, it should happen every time RTMP STREAM EOF is received by an application with no HLS enabled.

HLS module handles events in rtmp module even if you don't use it. There's not much overhead about it.