search

arut / nginx-rtmp-module

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

CPU 100% in ngx_rtmp_relay_close #270

Open magicbear opened 11 years ago

magicbear commented 11 years ago

(gdb) 1394 for (cctx = &ctx->play; _cctx; cctx = &(_cctx)->next) { (gdb) 1395 (_cctx)->publish = NULL; (gdb) 1399 ngx_rtmp_finalize_session((_cctx)->session); (gdb) 1394 for (cctx = &ctx->play; _cctx; cctx = &(_cctx)->next) { (gdb) 1395 (*cctx)->publish = NULL; (gdb) c

the process is hold on this loop.

arut commented 11 years ago

Can you reproduce this?

arut commented 11 years ago

Need more info about the loop. How long is it? What are the elements?

magicbear commented 11 years ago

It happen only on pull servers (inc. local relay & remote relay). I have install this plugins in over then 20 servers, currently have about half of servers has happend this problem.

That may happen on server stream end. And

on debian 6.04 gdb) bt

0 0x00000000004ce4a5 in ngx_rtmp_relay_close (s=0x2d1f008) at ../nginx-rtmp-module-master//ngx_rtmp_relay_module.c:1353

1 0x00000000004ce6fe in ngx_rtmp_relay_close_stream (s=0x2d1f008, v=0x73dae0)

at ../nginx-rtmp-module-master//ngx_rtmp_relay_module.c:1407

2 0x00000000004d0068 in ngx_rtmp_exec_close_stream (s=0x2d1f008, v=0x73dae0) at ../nginx-rtmp-module-master//ngx_rtmp_exec_module.c:586

3 0x00000000004d1706 in ngx_rtmp_enotify_close_stream (s=0x2d1f008, v=0x73dae0)

at ../nginx-rtmp-module-master//ngx_rtmp_enotify_module.c:453

4 0x00000000004d351b in ngx_rtmp_notify_close_stream (s=0x2d1f008, v=0x73dae0)

at ../nginx-rtmp-module-master//ngx_rtmp_notify_module.c:1169

5 0x00000000004bd712 in ngx_rtmp_cmd_close_stream_init (s=0x2d1f008, h=, in=)

at ../nginx-rtmp-module-master//ngx_rtmp_cmd_module.c:408

6 0x00000000004bbdc6 in ngx_rtmp_amf_message_handler (s=0x2d1f008, h=0x56b8ad0, in=0x2b8c3c0)

at ../nginx-rtmp-module-master//ngx_rtmp_receive.c:437

7 0x00000000004b7f3b in ngx_rtmp_receive_message (s=0x2d1f008, h=0x56b8ad0, in=0x2b8c3c0)

at ../nginx-rtmp-module-master//ngx_rtmp_handler.c:789

8 0x00000000004b8c5e in ngx_rtmp_recv (rev=) at ../nginx-rtmp-module-master//ngx_rtmp_handler.c:454

9 0x0000000000439d45 in ngx_epoll_process_events (cycle=0x319bcf0, timer=, flags=)

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

10 0x000000000042f973 in ngx_process_events_and_timers (cycle=0x319bcf0) at src/event/ngx_event.c:249

11 0x0000000000437bc9 in ngx_worker_process_cycle (cycle=0x319bcf0, data=) at src/os/unix/ngx_process_cycle.c:853

12 0x00000000004351dc in ngx_spawn_process (cycle=0x319bcf0, proc=0x437ad1 , data=,

name=0x4db804 "worker process", respawn=1) at src/os/unix/ngx_process.c:189

13 0x000000000043860c in ngx_reap_children (cycle=0x319bcf0) at src/os/unix/ngx_process_cycle.c:649

14 ngx_master_process_cycle (cycle=0x319bcf0) at src/os/unix/ngx_process_cycle.c:192

15 0x000000000041890a in main (argc=, argv=0x7ffff1a572a8) at src/core/nginx.c:431

on Debian 7.0

1397 (*cctx)->publish = NULL; (gdb) bt

0 ngx_rtmp_relay_close (s=s@entry=0x1c6b640) at ../nginx-rtmp-module-master/ngx_rtmp_relay_module.c:1397

1 0x00000000004d8d99 in ngx_rtmp_relay_delete_stream (s=0x1c6b640, v=0x0) at ../nginx-rtmp-module-master/ngx_rtmp_relay_module.c:1431

2 0x00000000004dceb5 in ngx_rtmp_notify_disconnect (s=0x1c6b640) at ../nginx-rtmp-module-master/ngx_rtmp_notify_module.c:1323

3 0x00000000004bce85 in ngx_rtmp_fire_event (s=s@entry=0x1c6b640, evt=evt@entry=24, h=h@entry=0x0, in=in@entry=0x0) at ../nginx-rtmp-module-master/ngx_rtmp.c:804

4 0x00000000004bd001 in ngx_rtmp_close_session_handler (e=) at ../nginx-rtmp-module-master/ngx_rtmp_init.c:271

5 0x0000000000431e4a in ngx_event_process_posted (cycle=cycle@entry=0x1a78290, posted=0xa528c0) at src/event/ngx_event_posted.c:40

6 0x000000000043195d in ngx_process_events_and_timers (cycle=cycle@entry=0x1a78290) at src/event/ngx_event.c:276

7 0x0000000000438f0c in ngx_worker_process_cycle (cycle=cycle@entry=0x1a78290, data=data@entry=0x3) at src/os/unix/ngx_process_cycle.c:853

8 0x000000000043663b in ngx_spawn_process (cycle=cycle@entry=0x1a78290, proc=0x438e50 , data=0x3, name=0x4e846c "worker process", respawn=respawn@entry=4) at src/os/unix/ngx_process.c:189

9 0x000000000043a141 in ngx_reap_children (cycle=0x1a78290) at src/os/unix/ngx_process_cycle.c:649

10 ngx_master_process_cycle (cycle=cycle@entry=0x1a78290) at src/os/unix/ngx_process_cycle.c:192

11 0x00000000004172da in main (argc=, argv=) at src/core/nginx.c:431

(gdb)

arut commented 11 years ago

I meant this.

ctx->play is list head. The loop at ngx_rtmp_relay_module.c:1397 closes all connections attached to the publisher.

The list should end with NULL entry. That does not happen in your case. I think the list is looped. I need more info about the items, especially all (*cctx)->session objects. Please show me that in gdb.

arut commented 11 years ago

BTW setting session_relay on may fix the issue for you. However it's important to find the problem.

magicbear commented 11 years ago

I found that this is happen on nginx shutdown.

www-data 3731 24.5 0.0 1059072 23056 ? R Oct05 4454:35 nginx: worker process is shutting down

luksow commented 10 years ago

I confirm that problem's still there :( @magicbear @arut any hints?

songshaodong commented 9 years ago

I also happend this problem.

MattJustMatt commented 9 years ago

We have this issue as well. :(

Doridian commented 9 years ago

Here is how the list looks:

(gdb) print *ctx->play
$10 = {name = {len = 19, data = 0x7f852949b7c0 "mp4:source_7465.mp4)\205\177"}, url = {len = 0, data = 0x0}, log = {
    log_level = 0, file = 0x0, connection = 0, handler = 0x0, data = 0x0, writer = 0x0, wdata = 0x0, action = 0x0, 
    next = 0x0}, session = 0x7f852949a8c8, publish = 0x0, play = 0x0, next = 0x7f8529613da8, app = {len = 0, data = 0x0}, 
  tc_url = {len = 0, data = 0x0}, page_url = {len = 0, data = 0x0}, swf_url = {len = 0, data = 0x0}, flash_ver = {len = 0, 
    data = 0x0}, play_path = {len = 0, data = 0x0}, live = 0, start = 0, stop = 0, push_evt = {data = 0x7f852949a8c8, 
    write = 0, accept = 0, instance = 0, active = 0, disabled = 0, ready = 0, oneshot = 0, complete = 0, eof = 0, 
    error = 0, timedout = 0, timer_set = 0, delayed = 0, deferred_accept = 0, pending_eof = 0, posted = 0, available = 0, 
    handler = 0x7f85277d3520 <ngx_rtmp_relay_push_reconnect>, index = 0, log = 0x7f852949a870, timer = {key = 0, 
      left = 0x0, right = 0x0, parent = 0x0, color = 0 '\000', data = 0 '\000'}, queue = {prev = 0x0, next = 0x0}, 
    closed = 0, channel = 0, resolver = 0, cancelable = 0}, static_evt = 0x0, tag = 0x0, data = 0x0}
(gdb) print *ctx->play->next
$11 = {name = {len = 19, data = 0x7f85295b9ee0 "mp4:source_7465.mp4)\205\177"}, url = {len = 0, data = 0x0}, log = {
    log_level = 0, file = 0x0, connection = 0, handler = 0x0, data = 0x0, writer = 0x0, wdata = 0x0, action = 0x0, 
    next = 0x0}, session = 0x7f85295b8fe8, publish = 0x0, play = 0x0, next = 0x7f8529613da8, app = {len = 0, data = 0x0}, 
  tc_url = {len = 0, data = 0x0}, page_url = {len = 0, data = 0x0}, swf_url = {len = 0, data = 0x0}, flash_ver = {len = 0, 
    data = 0x0}, play_path = {len = 0, data = 0x0}, live = 0, start = 0, stop = 0, push_evt = {data = 0x7f85295b8fe8, 
    write = 0, accept = 0, instance = 0, active = 0, disabled = 0, ready = 0, oneshot = 0, complete = 0, eof = 0, 
    error = 0, timedout = 0, timer_set = 0, delayed = 0, deferred_accept = 0, pending_eof = 0, posted = 0, available = 0, 
    handler = 0x7f85277d3520 <ngx_rtmp_relay_push_reconnect>, index = 0, log = 0x7f85295b8f90, timer = {key = 0, 
      left = 0x0, right = 0x0, parent = 0x0, color = 0 '\000', data = 0 '\000'}, queue = {prev = 0x0, next = 0x0}, 
    closed = 0, channel = 0, resolver = 0, cancelable = 0}, static_evt = 0x0, tag = 0x0, data = 0x0}
(gdb)

As you can see ctx->play->next points right at itself with its own ->next

Doridian commented 9 years ago

Also the sessions

(gdb) print *ctx->play->session
$3 = {signature = 0, close = {data = 0x7f852949a8c8, write = 0, accept = 0, instance = 0, active = 0, disabled = 0, 
    ready = 0, oneshot = 0, complete = 0, eof = 0, error = 0, timedout = 0, timer_set = 0, delayed = 0, 
    deferred_accept = 0, pending_eof = 0, posted = 1, available = 0, 
    handler = 0x7f85277bbdf0 <ngx_rtmp_close_session_handler>, index = 0, log = 0x7f852949a870, timer = {key = 0, 
      left = 0x0, right = 0x0, parent = 0x0, color = 0 '\000', data = 0 '\000'}, queue = {
      prev = 0x7f852817b0b0 <ngx_posted_events>, next = 0x7f85295b9040}, closed = 0, channel = 0, resolver = 0, 
    cancelable = 0}, ctx = 0x7f852949b330, main_conf = 0x7f8529359038, srv_conf = 0x7f852935a540, 
  app_conf = 0x7f852935ae08, addr_text = 0x7f8529364c98, connected = 1, posted_dry_events = {prev = 0x7f852949a968, 
    next = 0x7f852949a968}, buflen = 2000, ack_size = 5000000, app = {len = 4, data = 0x7f852949b3d8 "beam"}, args = {
    len = 0, data = 0x7f852949b3e0 "WIN 17,0,0,134"}, flashver = {len = 14, data = 0x7f852949b3e0 "WIN 17,0,0,134"}, 
  swf_url = {len = 33, data = 0x7f852949b3f0 "https://beam.pro/img/jwplayer.swf~\304ё\245\t"}, tc_url = {len = 27, 
    data = 0x7f852949b418 "rtmp://dist2.beam.pro/beam/)\205\177"}, acodecs = 3575, vcodecs = 252, page_url = {len = 24, 
    data = 0x7f852949b438 "https://beam.pro/pahimar\001mp4:source_7465.mp4"}, hs_buf = 0x0, 
  hs_digest = 0x7f852949b3b8 "\325\n1\004\264\066$\367\f֣\346}\321\343_X\020\265qB\206/\253\255{\037$.\v\326<beam", 
  hs_old = 0, hs_stage = 5, epoch = 1427251693311, peer_epoch = 262790, base_time = 0, current_time = 6606659, ping_evt = {
    data = 0x7f8520b3ed90, write = 0, accept = 0, instance = 0, active = 0, disabled = 0, ready = 0, oneshot = 0, 
    complete = 0, eof = 0, error = 0, timedout = 1, timer_set = 1, delayed = 0, deferred_accept = 0, pending_eof = 0, 
    posted = 0, available = 0, handler = 0x7f85277bd5d0 <ngx_rtmp_ping>, index = 0, log = 0x7f852949a870, timer = {
      key = 1427253523347, left = 0x7f8527a6e940 <ngx_event_timer_sentinel>, 
      right = 0x7f8527a6e940 <ngx_event_timer_sentinel>, parent = 0x7f85295e45d0, color = 0 '\000', data = 0 '\000'}, 
    queue = {prev = 0x0, next = 0x0}, closed = 0, channel = 0, resolver = 0, cancelable = 0}, ping_active = 0, 
  ping_reset = 1, auto_pushed = 0, relay = 0, static_relay = 0, in_streams = 0x7f85295ec470, in_csid = 0, 
  in_chunk_size = 128, in_pool = 0x7f8529777e90, in_bytes = 939, in_last_ack = 0, in_old_pool = 0x0, 
  in_chunk_size_changing = 0, connection = 0x7f8520b3ed90, timeout = 60000, out_bytes = 186546695, out_pos = 155, 
  out_last = 155, out_chain = 0x0, out_bpos = 0x7f85297b9b9c "", out_buffer = 0, out_queue = 256, out_cork = 32, 
  out = 0x7f852949ab20}
(gdb) print *ctx->play->next->session
$4 = {signature = 0, close = {data = 0x7f85295b8fe8, write = 0, accept = 0, instance = 0, active = 0, disabled = 0, 
    ready = 0, oneshot = 0, complete = 0, eof = 0, error = 0, timedout = 0, timer_set = 0, delayed = 0, 
    deferred_accept = 0, pending_eof = 0, posted = 1, available = 0, 
    handler = 0x7f85277bbdf0 <ngx_rtmp_close_session_handler>, index = 0, log = 0x7f85295b8f90, timer = {key = 0, 
      left = 0x0, right = 0x0, parent = 0x0, color = 0 '\000', data = 0 '\000'}, queue = {prev = 0x7f852949a920, 
      next = 0x7f852817b0b0 <ngx_posted_events>}, closed = 0, channel = 0, resolver = 0, cancelable = 0}, 
  ctx = 0x7f85295b9a50, main_conf = 0x7f8529359038, srv_conf = 0x7f852935a540, app_conf = 0x7f852935ae08, 
  addr_text = 0x7f8529364c98, connected = 1, posted_dry_events = {prev = 0x7f85295b9088, next = 0x7f85295b9088}, 
  buflen = 2000, ack_size = 5000000, app = {len = 4, data = 0x7f85295b9af8 "beam"}, args = {len = 0, 
    data = 0x7f85295b9b00 "WIN 17,0,0,134"}, flashver = {len = 14, data = 0x7f85295b9b00 "WIN 17,0,0,134"}, swf_url = {
    len = 33, data = 0x7f85295b9b10 "https://beam.pro/img/jwplayer.swf~\304ё\245\t"}, tc_url = {len = 27, 
    data = 0x7f85295b9b38 "rtmp://dist2.beam.pro/beam/)\205\177"}, acodecs = 3575, vcodecs = 252, page_url = {len = 24, 
    data = 0x7f85295b9b58 "https://beam.pro/pahimar\001mp4:source_7465.mp4"}, hs_buf = 0x0, 
  hs_digest = 0x7f85295b9ad8 "X۴\263Zs\\NE\353߸\363\211\001\aw]:\223\211ٰ\326ja\274!=\226\340\215beam", hs_old = 0, 
  hs_stage = 5, epoch = 1427248737404, peer_epoch = 181467686, base_time = 0, current_time = 6606659, ping_evt = {
    data = 0x7f8520b3e958, write = 0, accept = 0, instance = 0, active = 0, disabled = 0, ready = 0, oneshot = 0, 
    complete = 0, eof = 0, error = 0, timedout = 1, timer_set = 1, delayed = 0, deferred_accept = 0, pending_eof = 0, 
    posted = 0, available = 0, handler = 0x7f85277bd5d0 <ngx_rtmp_ping>, index = 0, log = 0x7f85295b8f90, timer = {
      key = 1427253507452, left = 0x7f8529775090, right = 0x7f8529454320, parent = 0x7f85295d86b0, color = 0 '\000', 
      data = 0 '\000'}, queue = {prev = 0x0, next = 0x0}, closed = 0, channel = 0, resolver = 0, cancelable = 0}, 
  ping_active = 0, ping_reset = 1, auto_pushed = 0, relay = 0, static_relay = 0, in_streams = 0x7f8529613630, in_csid = 0, 
  in_chunk_size = 128, in_pool = 0x7f8529614620, in_bytes = 1164, in_last_ack = 0, in_old_pool = 0x0, 
  in_chunk_size_changing = 0, connection = 0x7f8520b3e958, timeout = 60000, out_bytes = 299304085, out_pos = 240, 
  out_last = 240, out_chain = 0x0, out_bpos = 0x7f85297b9b9c "", out_buffer = 0, out_queue = 256, out_cork = 32, 
  out = 0x7f85295b9240}