nginx-rtmp-module
nginx-rtmp-module copied to clipboard
publishing broken (SIGCHLD)
I am using nginx 1.9.7 on a raspberry pi 2 on debian jessie. Publishing appears to be broken. I've tried ffmpeg and OBS, both had connection errors.
It worked with aruts branch (v1.1.7), but I'm not having any luck with this one (v1.1.7.9).
rtmp.conf
rtmp {
server {
listen 1935;
chunk_size 4096;
application live2 {
live on;
dash on;
dash_path /mnt/ramdisk/dash;
dash_fragment 10s;
}
application live {
live on;
record off;
publish_notify on;
play_restart on;
}
}
}
ffmpeg verbose output:
Opening an output file: rtmp://192.168.3.211/live/test.
Parsing...
Parsed protocol: 0
Parsed host : 192.168.3.211
Parsed app : live
RTMP_Connect1, ... connected, handshaking
HandShake: Type Answer : 03
HandShake: Server Uptime : 49550062
HandShake: FMS Version : 0.0.0.0
HandShake: Handshaking finished....
RTMP_Connect1, handshaked
RTMP_SendPacket: fd=516, size=89
0000: 03 00 00 00 00 00 59 14 00 00 00 00 ......Y.....
0000: 02 00 07 63 6f 6e 6e 65 63 74 00 3f f0 00 00 00 ...connect.?....
0010: 00 00 00 03 00 03 61 70 70 02 00 04 6c 69 76 65 ......app...live
0020: 00 04 74 79 70 65 02 00 0a 6e 6f 6e 70 72 69 76 ..type...nonpriv
0030: 61 74 65 00 05 74 63 55 72 6c 02 00 19 72 74 6d ate..tcUrl...rtm
0040: 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 33 2e 32 31 p://192.168.3.21
0050: 31 2f 6c 69 76 65 00 00 09 1/live...
Invoking connect
RTMP_ReadPacket: fd=516
RTMP_ReadPacket, failed to read RTMP packet header
rtmp://192.168.3.211/live/test: Unknown error occurred
debug.log
2015/11/29 23:29:45 [debug] 28376#0: epoll: fd:6 ev:0001 d:018EE6A0
2015/11/29 23:29:45 [debug] 28376#0: accept on 0.0.0.0:1935, ready: 0
2015/11/29 23:29:45 [debug] 28376#0: posix_memalign: 01851150:4096 @16
2015/11/29 23:29:45 [debug] 28376#0: *1 accept: 192.168.3.199:55381 fd:12
2015/11/29 23:29:45 [info] 28376#0: *1 client connected '192.168.3.199'
2015/11/29 23:29:45 [debug] 28376#0: *1 setting chunk_size=128
2015/11/29 23:29:45 [debug] 28376#0: *1 posix_memalign: 01852180:4096 @16
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: start server handshake
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: allocating buffer
2015/11/29 23:29:45 [debug] 28376#0: *1 recv: fd:12 -1 of 1537
2015/11/29 23:29:45 [debug] 28376#0: *1 recv() not ready (11: Resource temporarily unavailable)
2015/11/29 23:29:45 [debug] 28376#0: *1 event timer add: 12: 60000:1432266987
2015/11/29 23:29:45 [debug] 28376#0: *1 epoll add event: fd:12 op:1 ev:80002001
2015/11/29 23:29:45 [debug] 28376#0: timer delta: 13915
2015/11/29 23:29:45 [debug] 28376#0: worker cycle
2015/11/29 23:29:45 [debug] 28376#0: epoll timer: 60000
2015/11/29 23:29:45 [debug] 28376#0: epoll: fd:12 ev:0001 d:018EE808
2015/11/29 23:29:45 [debug] 28376#0: *1 event timer del: 12: 1432266987
2015/11/29 23:29:45 [debug] 28376#0: *1 recv: fd:12 1537 of 1537
2015/11/29 23:29:45 [debug] 28376#0: *1 epoll del event: fd:12 op:2 ev:00000000
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: stage 2
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: peer version=0.0.0.0 epoch=49609406
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: old-style challenge
2015/11/29 23:29:45 [debug] 28376#0: *1 send: fd:12 1537 of 1537
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: stage 3
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: old-style response
2015/11/29 23:29:45 [debug] 28376#0: *1 send: fd:12 1536 of 1536
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: stage 4
2015/11/29 23:29:45 [debug] 28376#0: *1 recv: fd:12 -1 of 1536
2015/11/29 23:29:45 [debug] 28376#0: *1 recv() not ready (11: Resource temporarily unavailable)
2015/11/29 23:29:45 [debug] 28376#0: *1 event timer add: 12: 60000:1432266988
2015/11/29 23:29:45 [debug] 28376#0: *1 epoll add event: fd:12 op:1 ev:80002001
2015/11/29 23:29:45 [debug] 28376#0: timer delta: 1
2015/11/29 23:29:45 [debug] 28376#0: worker cycle
2015/11/29 23:29:45 [debug] 28376#0: epoll timer: 60000
2015/11/29 23:29:45 [debug] 28376#0: epoll: fd:12 ev:0001 d:018EE808
2015/11/29 23:29:45 [debug] 28376#0: *1 event timer del: 12: 1432266988
2015/11/29 23:29:45 [debug] 28376#0: *1 recv: fd:12 1536 of 1536
2015/11/29 23:29:45 [debug] 28376#0: *1 epoll del event: fd:12 op:2 ev:00000000
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: stage 5
2015/11/29 23:29:45 [debug] 28376#0: *1 handshake: done
2015/11/29 23:29:45 [debug] 28376#0: *1 event timer add: 12: 60000:1432266992
2015/11/29 23:29:45 [debug] 28376#0: *1 ping: wait 60000ms
2015/11/29 23:29:45 [debug] 28376#0: *1 recv: fd:12 -1 of 146
2015/11/29 23:29:45 [debug] 28376#0: *1 recv() not ready (11: Resource temporarily unavailable)
2015/11/29 23:29:45 [debug] 28376#0: *1 epoll add event: fd:12 op:1 ev:80002001
2015/11/29 23:29:45 [debug] 28376#0: timer delta: 4
2015/11/29 23:29:45 [debug] 28376#0: worker cycle
2015/11/29 23:29:45 [debug] 28376#0: epoll timer: 60000
2015/11/29 23:29:45 [debug] 28376#0: epoll: fd:12 ev:0001 d:018EE808
2015/11/29 23:29:45 [debug] 28376#0: *1 recv: fd:12 101 of 146
2015/11/29 23:29:45 [debug] 28376#0: *1 RTMP bheader fmt=0 csid=3
2015/11/29 23:29:45 [debug] 28376#0: *1 RTMP mheader fmt=0 amf_cmd (20) time=0+0 mlen=89 len=0 msid=0
2015/11/29 23:29:45 [debug] 28376#0: *1 RTMP recv amf_cmd (20) csid=3 timestamp=0 mlen=89 msid=0 nbufs=1
2015/11/29 23:29:45 [debug] 28376#0: *1 nhandlers: 1
2015/11/29 23:29:45 [debug] 28376#0: *1 calling handler 0
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 02 '?'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 07 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (7) 63 6F 6E 6E 65 63 74 'connect'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF func 'connect' passed to handler 0/1
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 00 '?'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (8) 3F F0 00 00 00 00 00 00 '????????'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 03 '?'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 03 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (3) 61 70 70 'app'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 02 '?'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 04 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (4) 6C 69 76 65 'live'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 04 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (4) 74 79 70 65 'type'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 02 '?'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 0A '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (10) XX XX XX XX XX XX XX XX XX XX '??????????'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 05 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (5) 74 63 55 72 6C 'tcUrl'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 02 '?'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 19 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (25) 72 74 6D 70 3A 2F 2F 31 39 32 2E 31 36 38 2E 33 2E 32 31 31 2F 6C 69 76 65 'rtmp://192.168.3.211/live'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (2) 00 00 '??'
2015/11/29 23:29:45 [debug] 28376#0: *1 AMF read (1) 09 '?'
2015/11/29 23:29:45 [info] 28376#0: *1 connect: app='live' args='' flashver='' swf_url='' tc_url='rtmp://192.168.3.211/live' page_url='' acodecs=0 vcodecs=0 object_encoding=0, client: 192.168.3.199, server: 0.0.0.0:1935
2015/11/29 23:29:45 [notice] 28375#0: signal 17 (SIGCHLD) received
2015/11/29 23:29:45 [alert] 28375#0: worker process 28376 exited on signal 11
2015/11/29 23:29:45 [debug] 28375#0: shmtx forced unlock
2015/11/29 23:29:45 [debug] 28375#0: wake up, sigio 0
2015/11/29 23:29:45 [debug] 28375#0: reap children
2015/11/29 23:29:45 [debug] 28375#0: child: 0 28376 e:0 t:1 d:0 r:1 j:0
2015/11/29 23:29:45 [debug] 28375#0: pass close channel s:0 pid:28376 to:28377
2015/11/29 23:29:45 [debug] 28375#0: channel 3:8
2015/11/29 23:29:45 [debug] 28377#0: epoll: fd:10 ev:0001 d:018EE6A0
2015/11/29 23:29:45 [notice] 28375#0: start worker process 28387
2015/11/29 23:29:45 [debug] 28377#0: channel handler
2015/11/29 23:29:45 [debug] 28375#0: pass channel s:0 pid:28387 fd:3 to s:1 pid:28377 fd:9
2015/11/29 23:29:45 [debug] 28377#0: channel: 16
2015/11/29 23:29:45 [debug] 28375#0: child: 1 28377 e:0 t:0 d:0 r:1 j:0
2015/11/29 23:29:45 [debug] 28377#0: channel command: 2
2015/11/29 23:29:45 [debug] 28375#0: sigsuspend
2015/11/29 23:29:45 [debug] 28377#0: close channel s:0 pid:28376 our:28376 fd:3
2015/11/29 23:29:45 [debug] 28377#0: channel: 16
2015/11/29 23:29:45 [debug] 28377#0: channel command: 1
2015/11/29 23:29:45 [debug] 28377#0: get channel s:0 pid:28387 fd:3
2015/11/29 23:29:45 [notice] 28375#0: signal 29 (SIGIO) received
2015/11/29 23:29:45 [debug] 28377#0: channel: -2
2015/11/29 23:29:45 [debug] 28375#0: wake up, sigio 0
2015/11/29 23:29:45 [debug] 28377#0: timer delta: 13953
2015/11/29 23:29:45 [debug] 28375#0: sigsuspend
2015/11/29 23:29:45 [debug] 28377#0: epoll timer: 46047
2015/11/29 23:29:45 [debug] 28387#0: notify eventfd: 12
2015/11/29 23:29:45 [debug] 28387#0: eventfd: 13
2015/11/29 23:29:45 [debug] 28387#0: malloc: 0184F130:8192
2015/11/29 23:29:45 [debug] 28387#0: malloc: 018EE6A0:122880
2015/11/29 23:29:45 [debug] 28387#0: malloc: 0190C6A8:49152
2015/11/29 23:29:45 [debug] 28387#0: malloc: 019186B0:49152
2015/11/29 23:29:45 [debug] 28387#0: epoll add event: fd:6 op:1 ev:00002001
2015/11/29 23:29:45 [debug] 28387#0: epoll add event: fd:7 op:1 ev:00002001
2015/11/29 23:29:45 [debug] 28387#0: epoll add event: fd:8 op:1 ev:00002001
2015/11/29 23:29:45 [debug] 28387#0: setproctitle: "nginx: worker process"
2015/11/29 23:29:45 [debug] 28387#0: worker cycle
2015/11/29 23:29:45 [debug] 28387#0: epoll timer: -1
Do you have worker_processes 1;
in nginx config? Or more than one?
Like @up, you have more than one worker process without auto-push.
worker_processes
was set to 4.
I've tried setting it to 1, but debug shows the same output.
With what you try to publish? Via FFmpeg? What command options you pass?
ffmpeg, using
ffmpeg -v debug -re -i test.mkv -c:v libx264 -c:a aac -ar 44100 -ac 1 -f flv -strict -2 rtmp://192.168.3.211/live/test
I have tested this again on a amd64 machine with the same configuration, same build and it works without errors.
Might be a problem on arm platforms.
Any luck with latest nginx, nginx-rtmp master on Pi2?
yes, publishing works again with nginx 1.9.12 and master (12595a21aa48858fc0db7a4ddf78d4cf6670c093) on debian jessie on the raspberry 2
the issue can be closed if you want to
Ok. Thank you for testing.
Can you check latest master? Reverted some onMetaData code.
publishing still works, but clients can only connect before publishing starts, not after.
once publish started I can't connect to the stream anymore, be it a flash player or ffplay. it keeps playing for already connected clients though.
ffplay gives up after some time
RTMP_ReadPacket, failed to read RTMP packet header
rtmp://192.168.3.211/live/test: Unknown error occurred
there's no indication of what's happening in nginxs debug log.
here is ffplays debug output
Parsing... :
Parsed protocol: 0
Parsed host : 192.168.3.211
Parsed app : live
RTMP_Connect1, ... connected, handshaking
HandShake: Type Answer : 03
HandShake: Server Uptime : 56014694
HandShake: FMS Version : 0.0.0.0
HandShake: Handshaking finished....
RTMP_Connect1, handshaked
RTMP_SendPacket: fd=648, size=169
0000: 03 00 00 00 00 00 a9 14 00 00 00 00 ............
0000: 02 00 07 63 6f 6e 6e 65 63 74 00 3f f0 00 00 00 ...connect.?....
0010: 00 00 00 03 00 03 61 70 70 02 00 04 6c 69 76 65 ......app...live
0020: 00 05 74 63 55 72 6c 02 00 19 72 74 6d 70 3a 2f ..tcUrl...rtmp:/
0030: 2f 31 39 32 2e 31 36 38 2e 33 2e 32 31 31 2f 6c /192.168.3.211/l
0040: 69 76 65 00 04 66 70 61 64 01 00 00 0c 63 61 70 ive..fpad....cap
0050: 61 62 69 6c 69 74 69 65 73 00 40 2e 00 00 00 00 abilities.@.....
0060: 00 00 00 0b 61 75 64 69 6f 43 6f 64 65 63 73 00 ....audioCodecs.
0070: 40 a8 ee 00 00 00 00 00 00 0b 76 69 64 65 6f 43 @.........videoC
0000: c3 .
0000: 6f 64 65 63 73 00 40 6f 80 00 00 00 00 00 00 0d odecs.@o........
0010: 76 69 64 65 6f 46 75 6e 63 74 69 6f 6e 00 3f f0 videoFunction.?.
0020: 00 00 00 00 00 00 00 00 09 .........
Invoking connect
RTMP_ReadPacket: fd=648
0000: 02 00 00 00 00 00 04 05 00 00 00 00 ............
0000: 00 4c 4b 40 .LK@
HandleServerBW: server BW = 5000000
RTMP_ReadPacket: fd=648
0000: 02 00 00 00 00 00 05 06 00 00 00 00 ............
0000: 00 4c 4b 40 02 .LK@.
HandleClientBW: client BW = 5000000 2
RTMP_ReadPacket: fd=648
0000: 02 00 00 00 00 00 04 01 00 00 00 00 ............
0000: 00 00 10 00 ....
HandleChangeChunkSize, received: chunk size change to 4096
RTMP_ReadPacket: fd=648
0000: 03 00 00 00 00 00 be 14 00 00 00 00 ............
0000: 02 00 07 5f 72 65 73 75 6c 74 00 3f f0 00 00 00 ..._result.?....
0010: 00 00 00 03 00 06 66 6d 73 56 65 72 02 00 0d 46 ......fmsVer...F
0020: 4d 53 2f 33 2c 30 2c 31 2c 31 32 33 00 0c 63 61 MS/3,0,1,123..ca
0030: 70 61 62 69 6c 69 74 69 65 73 00 40 3f 00 00 00 pabilities.@?...
0040: 00 00 00 00 00 09 03 00 05 6c 65 76 65 6c 02 00 .........level..
0050: 06 73 74 61 74 75 73 00 04 63 6f 64 65 02 00 1d .status..code...
0060: 4e 65 74 43 6f 6e 6e 65 63 74 69 6f 6e 2e 43 6f NetConnection.Co
0070: 6e 6e 65 63 74 2e 53 75 63 63 65 73 73 00 0b 64 nnect.Success..d
0080: 65 73 63 72 69 70 74 69 6f 6e 02 00 15 43 6f 6e escription...Con
0090: 6e 65 63 74 69 6f 6e 20 73 75 63 63 65 65 64 65 nection succeede
00a0: 64 2e 00 0e 6f 62 6a 65 63 74 45 6e 63 6f 64 69 d...objectEncodi
00b0: 6e 67 00 00 00 00 00 00 00 00 00 00 00 09 ng............
RTMP_ClientPacket, received: invoke 190 bytes
(object begin)
Property: <Name: no-name., STRING: _result>
Property: <Name: no-name., NUMBER: 1.00>
Property: <Name: no-name., OBJECT>
(object begin)
Property: <Name: fmsVer, STRING: FMS/3,0,1,123>
Property: <Name: capabilities, NUMBER: 31.00>
(object end)
Property: <Name: no-name., OBJECT>
(object begin)
Property: <Name: level, STRING: status>
Property: <Name: code, STRING: NetConnection.Connect.Success>
Property: <Name: description, STRING: Connection succeeded.>
Property: <Name: objectEncoding, NUMBER: 0.00>
(object end)
(object end)
HandleInvoke, server invoking <_result>
HandleInvoke, received result for method call <connect>
RTMP_SendPacket: fd=648, size=4
0000: 02 00 00 00 00 00 04 05 00 00 00 00 ............
0000: 00 4c 4b 40 .LK@
sending ctrl. type: 0x0003
RTMP_SendPacket: fd=648, size=10
0000: 42 00 00 00 00 00 0a 04 B.......
0000: 00 03 00 00 00 00 00 00 01 2c .........,
RTMP_SendPacket: fd=648, size=25
0000: 43 00 00 00 00 00 19 14 C.......
0000: 02 00 0c 63 72 65 61 74 65 53 74 72 65 61 6d 00 ...createStream.
0010: 40 00 00 00 00 00 00 00 05 @........
Invoking createStream
RTMP_ReadPacket: fd=648
0000: 03 00 00 00 00 00 1d 14 00 00 00 00 ............
0000: 02 00 07 5f 72 65 73 75 6c 74 00 40 00 00 00 00 ..._result.@....
0010: 00 00 00 05 00 3f f0 00 00 00 00 00 00 .....?.......
RTMP_ClientPacket, received: invoke 29 bytes
(object begin)
Property: <Name: no-name., STRING: _result>
Property: <Name: no-name., NUMBER: 2.00>
Property: NULL
Property: <Name: no-name., NUMBER: 1.00>
(object end)
HandleInvoke, server invoking <_result>
HandleInvoke, received result for method call <createStream>
SendPlay, seekTime=0, stopTime=0, sending play: test
RTMP_SendPacket: fd=648, size=33
0000: 08 00 00 00 00 00 21 14 01 00 00 00 ......!.....
0000: 02 00 04 70 6c 61 79 00 40 08 00 00 00 00 00 00 ...play.@.......
0010: 05 02 00 04 74 65 73 74 00 00 00 00 00 00 00 00 ....test........
0020: 00 .
Invoking play
sending ctrl. type: 0x0003
RTMP_SendPacket: fd=648, size=10
0000: c2 .
0000: 00 03 00 00 00 01 00 00 0b b8 ..........
RTMP_ReadPacket: fd=648
RTMPSockBuf_Fill, recv returned -1. GetSockError(): 10060 (Unknown error)
RTMP_ReadPacket, failed to read RTMP packet header
RTMP_SendPacket: fd=648, size=34
0000: 43 00 00 00 00 00 22 14 C.....".
0000: 02 00 0c 64 65 6c 65 74 65 53 74 72 65 61 6d 00 ...deleteStream.
0010: 40 10 00 00 00 00 00 00 05 00 3f f0 00 00 00 00 @.........?.....
0020: 00 00 ..
Invoking deleteStream
rtmp://192.168.3.211/live/test: Unknown error occurred
clients can only connect before publishing starts, not after
That's really strange. Publisher sill working in that time?
I'll try that on my Pi2. But it take some time.
I did some more testing, this seems to be unrelated that it runs on a raspberry. my amd64 machine has the same problem.
no client can connect after publishing started. if you stop and restart publishing when clients still try to connect they suddenly connect fine and start receiving. using master (2d4613c90687ad9947f5b68a67480f65e10c6911) on both.
It seems nginx 1.9.12 is acting up. I've tried all commits down to 8c5139650d3ea9e5cf5f1acd0c4ce7dbe208d965 on nginx 1.9.12. Clients could no longer connect after publishing started. It sometimes took a few minutes before it starts happening.
8c5139650d3ea9e5cf5f1acd0c4ce7dbe208d965 works on nginx 1.9.10 but 1.9.12 will not let anyone connect anymore.
I've tested latest master (2d4613c90687ad9947f5b68a67480f65e10c6911) on 1.9.10 and 1.9.12 and both had the same symptoms.
I tested this on a amd64 machine and the raspberry pi.
I've just tried nginx 1.9.10 on 8c5139650d3ea9e5cf5f1acd0c4ce7dbe208d965 again. Clients again can no longer connect after around 3 minutes of a stream getting published. Weirdly enough this setup was working for the last month without changing configs. I have no idea what's going on or what else to test.
Did you tried latest dev
branch?
I've been using the dev branch for a few months now without any issues regarding this. Though I didn't test it on a raspberry pi anymore since I've changed setups, only on the amd64 machine.
Not sure when it started working again, I downgraded and didn't update for a while before updating nginx and trying out master/dev
Concerning raspberry pi/ARM - if it was big-endian (which I don't know for sure), then you probably hit the the same issue I got on bigendian MIPS. Pull Request #308 should deal with that at least for RTMP protocol (not sure about HLS and DASH). I also got SIGCHLD in some situations.