search

mpromonet / webrtc-streamer

WebRTC streamer for V4L2 capture devices, RTSP sources and Screen Capture
https://webrtcstreamer.agreeabletree-365b9a90.canadacentral.azurecontainerapps.io/?layout=2x2
The Unlicense
2.97k stars 602 forks source link

dies in layout mode #451

Closed tedder closed 2 years ago

tedder commented 3 years ago

Hi, I'm testing with 5 RTSP cameras and using Docker. It consistently dies, though it doesn't if I don't use 'layout', even if I click and enable all cameras. Here's a sample of how Docker exits:

streamer    | [032:746][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:3 peerid:0.15974289637730443
streamer    | [032:746][15] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [032:746][15] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [032:746][15] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [032:746][15] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | Assertion 'm' failed at pulse/thread-mainloop.c:176, function pa_threaded_mainloop_lock(). Aborting.

Here's another example:

streamer    | [044:252][12] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [044:253][12] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [044:252][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:0 peerid:0.2147050088895872
streamer    | Assertion 'pthread_mutex_destroy(&m->mutex) == 0' failed at pulsecore/mutex-posix.c:83, function pa_mutex_free(). Aborting.
streamer    | pa_write() failed while trying to wake up the mainloop: Broken pipe

And another one:

streamer    | [010:665][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:3 peerid:0.29119104727942235
streamer    | [010:666][21] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [010:666][21] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [010:666][18] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [010:666][18] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [010:666][18] (audio_device_impl.cc:341): Audio device initialization failed.

The errors seem inconsistent. On this last one I was able to reload the page and see all the videos, then I reloaded again and the container died.

streamer    | [024:169][1] (PeerConnectionManager.h:229): virtual void PeerConnectionManager::PeerConnectionObserver::OnRenegotiationNeeded() peerid:0.3127358063491874
streamer    | [024:169][47] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [024:169][47] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [024:169][47] (PeerConnectionManager.cpp:1154): Cannot create capturer audio:driveway3
streamer    | Assertion 'pthread_mutex_lock(&m->mutex) == 0' failed at pulsecore/mutex-posix.c:90, function pa_mutex_lock(). Aborting.

With Docker run I was able to reload about 5 times before it died. I'm running this in a docker-compose container with the following relevant settings:

    network_mode: host
    command: '-a 0 -vvv -o'

I removed the -o and it loaded. After a few reloads of the browser it failed:

streamer    | [029:210][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:3 peerid:0.6254799866732232
streamer    | [029:212][36] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [029:212][36] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [029:212][36] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [029:212][36] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [029:212][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:3 peerid:0.9697528098050592
streamer    | [029:213][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:3 peerid:0.460787311359395
streamer    | [029:214][36] (PeerConnectionManager.cpp:1154): Cannot create capturer audio:frontporch2
streamer    | [029:214][35] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [029:214][35] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [029:215][33] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [029:215][33] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [029:215][34] (audio_device_pulse_linux.cc:1584): PA context has already existed
streamer    | [029:215][34] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [029:215][33] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | Assertion 'pa_close(fds[0]) == 0' failed at pulsecore/core-util.c:2500, function pa_close_pipe(). Aborting.
streamer    | [029:215][33] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | free(): invalid size

Here's another crash:

streamer    | [012:826][1] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:0 peerid:0.5631968699466039
streamer    | [012:826][19] (PeerConnectionManager.cpp:1154): Cannot create capturer audio:basement1
streamer    | [012:826][17] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [012:827][17] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [012:827][22] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [012:827][22] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [012:827][18] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [012:827][18] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [012:827][22] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [012:827][17] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [012:827][22] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [012:827][17] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1

It would appear there are PulseAudio problems.

I've tried removing -a 0 and still get errors. I've also tried running with v0.6.3 and v0.6.4

I'm hoping you can help point me in the right direction with this.

mpromonet commented 3 years ago

Hi,

Some improvements to do... Don't forget that getopt for an argument that is optional with a default value like for audiolayer "a::" doesnot allow to add a space, then -a 0 is not equivalent to -a0, it gives 2 parameter -a and 0 that is interpretated as an url.

Best Regards, Michel.

tedder commented 3 years ago

aha, yep, I can see that -a in the logs:

streamer    | [014:617][8] (connection.cc:790): Conn[bc01c070:0:Net[eth0:172.19.0.x/16:Ethernet:id=1]:XTbchQMu:1:0:local:udp:172.19.0.x:36828->7PHoQeIi:1:1845501695:prflx:udp:172.19.0.x:49707|CRWS|S|1|0|7926369428982087166|0]: UpdateState(), ms since last received response=1002, ms since last received data=8147, rtt=100, pings_since_last_response=

I hadn't been seeing a camera named '1' before. Was docker-compose not updating the container? eep. If so that's a big fail on my part.

So, I reviewed and am using 'docker-compose up' instead of simply 'restart'. I can tell it works because using -vvv causes -C to not be passed in by default- e.g., I need -vvv -C /app/config.json.

On the bright side(?) I'm still getting errors. Here's the tail of the log as it crashes. I'm not setting -a at all here.

streamer    | [041:377][18] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://192.168.2.37:554/streaming/channels/1
streamer    | [041:377][18] (PeerConnectionManager.cpp:1004): audiourl:driveway3
streamer    | [041:377][18] (audio_device_impl.cc:332): Init
streamer    | Received a complete DESCRIBE[041:377][18] (audio_device_pulse_linux.cc:1571): mainloop running!
streamer    |  response:
streamer    | RTSP/1.0 200 OK
streamer    | CSeq: 2
streamer    | Content-Type: application/sdp
streamer    | Content-Length: 517
streamer    | 
streamer    | v=0
streamer    | o=- 0 0 IN IP4 127.0.0.1
streamer    | s=H.264 Video,leco stream
streamer    | c=IN IP4 0.0.0.0
streamer    | t=0 0
streamer    | a=tool:prv
streamer    | a=control:*
streamer    | m=video 0 RTP/AVP 96
streamer    | b=AS:134
streamer    | a=rtpmap:96 H264/90000
streamer    | a=fmtp:96 packetization-mode=1;profile-level-id=276400;sprop-parameter-sets=J2QAKq0AzoB4AiflmoCAgPgAAAMACAAAAwDxgYABDzwADLbv/+BQ,KO48sA==
streamer    | a=control:trackID=0
streamer    | m=audio 0 RTP/AVP 97
streamer    | b=AS:131
streamer    | a=rtpmap:97 MPEG4-GENERIC/16000/1
streamer    | a=fmtp:97 profile-level-id=1;mode=AAC-hbr;sizelength=13;indexlength=3;indexdeltalength=3; config=1408
streamer    | a=control:trackID=1
streamer    | 
streamer    | 
streamer    | Created new TCP socket 27[041:378][19] (VideoDecoder.h:79): VideoDecoder::start
streamer    | [041:378][1] (sctp_data_channel.cc:718): Sent CONTROL message on channel 0
streamer    | [041:378][1] (PeerConnectionManager.h:144): virtual void PeerConnectionManager::DataChannelObserver::OnStateChange() channel:ServerDataChannel state:open
streamer    | [041:378][19] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://cam:camview1@192.168.2.39:554/cam/realmonitor?channel=1&subtype=0
streamer    |  for connection
streamer    | [041:378][19] (PeerConnectionManager.cpp:1004): audiourl:frontporch2
streamer    | Connecting to 192.168.2.37, port 554[041:378][19] (audio_device_impl.cc:332): Init
streamer    | [041:378][19] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    |  on socket [041:378][19] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | 27...
streamer    | [041:378][82] (video_stream_encoder.cc:2001): OnBitrateUpdated, bitrate 282640 stable bitrate = 282640 link allocation bitrate = 282640 packet loss 0 rtt 0
streamer    | [041:378][82] (video_stream_encoder.cc:2026): Video suspend state changed to: not suspended
streamer    | [041:378][76] (bitrate_allocator.cc:523): UpdateAllocationLimits : total_requested_min_bitrate: 0 bps, total_requested_padding_bitrate: 0 bps, total_requested_max_bitrate: 10000 kbps
streamer    | [041:378][18] (audio_device_pulse_linux.cc:1305): context state cb
streamer    | [041:378][18] (audio_device_pulse_linux.cc:1315): no state
streamer    | Created new TCP socket 21 for connection
streamer    | Connecting to 192.168.2.39, port 554 on socket 21...
streamer    | [041:378][18] (audio_device_pulse_linux.cc:1305): context state cb
streamer    | [041:378][18] (audio_device_pulse_linux.cc:1319): failed
streamer    | [041:378][18] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [041:378][18] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [041:378][9] (usrsctp_transport.cc:1165): UsrsctpTransport->OnPacketRead(...):  length=300, started: 1
streamer    | [041:378][9] (usrsctp_transport.cc:199): 
streamer    | I 18:53:34.073593 0000 13 88 13 88 4d 86 f0 ce 9b b8 81 3c 0a 00 00 c8 4b 41 4d 45 2d 42 53 44 20 31 2e 31 00 00 00 00 2e 42 5f 61 00 00 00 00 b3 17 01 00 00 00 00 00 60 ea 00 00 f7 f7 c4 e4 92 f1 b6 c7 ab c7 6c 02 4d 86 f0 ce 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 00 13 88 13 88 00 00 01 00 01 01 01 00 00 00 00 00 01 00 00 1e 02 6c c7 ab 00 02 00 00 04 00 08 00 fa b8 09 c9 c0 00 00 04 80 08 00 06 c0 82 00 00 02 00 00 e8 4d 86 f0 ce 00 02 00 00 04 00 08 00 a8 44 db 89 c0 00 00 04 80 08 00 06 c0 82 00 00 75 27 18 23 b0 c2 2f 8f a4 b7 41 bb 81 26 f7 8a 34 a7 8a 97 00 03 00 2d fa b8 09 c9 00 01 00 00 00 00 00 32 03 00 00 00 00 00 00 00 00 11 00 00 43 6c 69 65 6e 74 44 61 74 61 43 68 61 6e 6e 65 6c 00 00 00 00 03 00 25 fa b8 09 ca 00 01 00 01 00 00 00 33 6c 6f 63 61 6c 20 63 68 61 6e 6e 65 6c 20 6f 70 65 6e 6e 65 64 00 00 00 # SCTP_PACKET
streamer    | 
streamer    | [041:378][18] (audio_device_pulse_linux.cc:1688): PulseAudio terminated
streamer    | [041:378][18] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [041:378][18] (audio_device_impl.cc:730): RecordingDevices
streamer    | [041:378][18] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [041:378][18] (PeerConnectionManager.cpp:1119): Adding Stream to map

and on the next run, no settings changed but the logs are much different. I'm guessing the logs are somewhat async?

streamer    | [132:335][9] (p2p_transport_channel.cc:1324): Failed to resolve ICE candidate hostname 556c6938-1ffd-4005-8513-7273cda640c4.local with error -3
streamer    | [132:335][1] (video_send_stream_impl.cc:244): VideoSendStreamImpl: {encoder_settings: { experiment_cpu_load_estimator: off}}, rtp: {ssrcs: [1523020865], rids: [], mid: '1', rtcp_mode: RtcpMode::kReducedSize, max_packet_size: 1200, extmap-allow-mixed: true, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time, id: 2}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/color-space, id: 8}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/playout-delay, id: 12}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-content-type, id: 11}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-timing, id: 7}, {uri: urn:3gpp:video-orientation, id: 13}, {uri: urn:ietf:params:rtp-hdrext:sdes:mid, id: 4}, {uri: urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id, id: 6}, {uri: urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id, id: 5}], lntf: {enabled: false}, nack: {rtp_history_ms: 1000}, ulpfec: {ulpfec_payload_type: 123, red_payload_type: 124, red_rtx_payload_type: 119}, payload_name: VP8, payload_type: 96, raw_payload: false, flexfec: {payload_type: -1, ssrc: 0, protected_media_ssrcs: []}, rtx: {ssrcs: [3169397977], payload_type: 97}, c_name: jl1Hnx0I67Jdlrkc}, rtcp_report_interval_ms: 1000, send_transport: (Transport), render_delay_ms: 0, target_delay_ms: 0, suspend_below_min_bitrate: off}
streamer    | [132:335][1] (call.cc:1354): UpdateAggregateNetworkState: aggregate_state remains at down
streamer    | [132:335][1] (rtp_transport_controller_send.cc:361): SignalNetworkState Down
streamer    | [132:335][1] (webrtc_video_engine.cc:1380): SetLocalSsrc on all the receive streams because we added a send stream.
streamer    | [132:335][1] (channel.cc:675): Add send stream ssrc: 1523020865 into {mid: 1, media_type: video}
streamer    | [132:335][1] (webrtc_video_engine.cc:1280): SetSend: false
streamer    | [132:335][1] (channel.cc:974): Changing video state, send=0 for {mid: 1, media_type: video}
streamer    | [132:335][89] (video_stream_encoder.cc:819): ConfigureEncoder requested.
streamer    | [132:335][89] (video_stream_encoder.cc:804): SetStartBitrate 300000
streamer    | Received 760 new bytes of response data.
streamer    | Received a complete DESCRIBE response:
streamer    | RTSP/1.0 200 OK
streamer    | CSeq: 2
streamer    | Content-Type: application/sdp
streamer    | Content-Base: rtsp://192.168.2.38:554/streaming/channels/1/
streamer    | Content-Length: 619
streamer    | 
streamer    | v=0
streamer    | o=- 1633607747478677 1633607747478677 IN IP4 192.168.2.38
streamer    | s=Media Presentation
streamer    | e=NONE
streamer    | b=AS:5050
streamer    | t=0 0
streamer    | a=control:rtsp://192.168.2.38:554/streaming/channels/1/
streamer    | m=video 0 RTP/AVP 96
streamer    | c=IN IP4 0.0.0.0
streamer    | b=AS:5000
streamer    | a=recvonly
streamer    | a=x-dimensions:3840,2160
streamer    | a=control:rtsp://192.168.2.38:554/streaming/channels/1/trackID=1
streamer    | a=rtpmap:96 H264/90000
streamer    | a=fmtp:96 profile-level-id=420029; packetization-mode=1; sprop-parameter-sets=Z01AM42NQB4AIf/gLcBAQFAAAD6AAAnEDoYACZHrvLjQwAEyPXeXCg==,aO44gA==
streamer    | a=Media_header:MEDIAINFO=494D4B48010200000400000100000000000000000000000000000000000000000000000000000000;
streamer    | a=appversion:1.0
streamer    | 
streamer    | Sending request: SETUP rtsp://192.168.2.38:554/streaming/channels/1/trackID=1 RTSP/1.0
streamer    | CSeq: 3
streamer    | User-Agent: LIVE555 Streaming Media v2021.08.24
streamer    | Transport: RTP/AVP/TCP;unicast;interleaved=0-1
streamer    | 
streamer    |

and a third run, no settings changed.

streamer    | [151:387][11] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://192.168.2.35:554/streaming/channels/1
streamer    | [151:387][11] (PeerConnectionManager.cpp:1004): audiourl:driveway2
streamer    | [151:387][11] (audio_device_impl.cc:332): Init
streamer    | [151:387][14] (VideoDecoder.h:79): VideoDecoder::start
streamer    | Created new TCP socket 21 for connection
streamer    | Connecting to 192.168.2.40, port 554 on socket 21...
streamer    | [151:387][14] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://cam:camview1@192.168.2.40:554/live0
streamer    | [151:388][14] (PeerConnectionManager.cpp:1004): audiourl:basement1
streamer    | [151:388][14] (audio_device_impl.cc:332): Init
streamer    | [151:388][14] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [151:388][14] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [151:386][12] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://192.168.2.37:554/streaming/channels/1
streamer    | [151:388][12] (PeerConnectionManager.cpp:1004): audiourl:driveway3
streamer    | [151:388][12] (audio_device_impl.cc:332): Init
streamer    | [151:388][12] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [151:388][12] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [151:388][11] (audio_device_pulse_linux.cc:1571): mainloop running!
streamer    | [151:388][11] (audio_device_pulse_linux.cc:1305): context state cb
streamer    | [151:388][11] (audio_device_pulse_linux.cc:1315): no state
streamer    | [151:388][11] (audio_device_pulse_linux.cc:1305): context state cb
streamer    | [151:388][11] (audio_device_pulse_linux.cc:1319): failed
streamer    | [151:388][11] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [151:388][11] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [151:388][11] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [151:388][11] (audio_device_impl.cc:730): RecordingDevices
streamer    | [151:388][11] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [151:388][12] (audio_device_pulse_linux.cc:1688): PulseAudio terminated
streamer    | [151:388][12] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [151:388][12] (audio_device_impl.cc:730): RecordingDevices
streamer    | [151:388][12] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [151:388][12] (PeerConnectionManager.cpp:1119): Adding Stream to map
streamer    | [151:388][11] (PeerConnectionManager.cpp:1119): Adding Stream to map
streamer    | [151:388][9] (p2p_transport_channel.cc:1324): Failed to resolve ICE candidate hostname 1f7db4dd-eac5-491b-9f43-ed84b07b7db8.local with error -3
streamer    | Created new TCP socket 20 for connection
streamer    | Connecting to 192.168.2.35, port 554 on socket 20...
streamer    | [151:388][9] (p2p_transport_channel.cc:586): Set backup connection ping interval to 25000 milliseconds.
streamer    | [151:388][9] (p2p_transport_channel.cc:595): Set ICE receiving timeout to 2500 milliseconds
streamer    | [151:388][9] (p2p_transport_channel.cc:602): Set ping most likely connection to 0
streamer    | [151:388][9] (p2p_transport_channel.cc:609): Set stable_writable_connection_ping_interval to 2500
streamer    | [151:388][9] (p2p_transport_channel.cc:622): Set presume writable when fully relayed to 0
streamer    | [151:388][9] (p2p_transport_channel.cc:640): Set regather_on_failed_networks_interval to 300000
streamer    | [151:388][9] (p2p_transport_channel.cc:647): Set receiving_switching_delay to 1000
streamer    | [151:388][9] (jsep_transport_controller.cc:1058): Creating DtlsSrtpTransport.
streamer    | [151:388][9] (dtls_srtp_transport.cc:63): Setting RTCP Transport on 0 transport 0
streamer    | [151:388][9] (dtls_srtp_transport.cc:68): Setting RTP Transport on 0 transport b40364b0
streamer    | Assertion 'pthread_mutex_lock(&m->mutex) == 0' failed at pulsecore/mutex-posix.c:90, function pa_mutex_lock(). Aborting.
streamer    | [151:388][9] (p2p_transport_channel.cc:586): Set backup connection ping interval to 25000 milliseconds.
streamer    | [151:388][9] (p2p_transport_channel.cc:595): Set ICE receiving timeout to 2500 milliseconds
streamer    | [151:388][9] (p2p_transport_channel.cc:602): Set ping most likely connection to 0
streamer    | [151:388][9] (p2p_transport_channel.cc:609): Set stable_writable_connection_ping_interval to 2500
streamer    | [151:388][9] (p2p_transport_channel.cc:622): Set presume writable when fully relayed to 0
streamer    | [151:388][9] (p2p_transport_channel.cc:640): Set regather_on_failed_networks_interval to 300000
streamer    | [151:388][9] (p2p_transport_channel.cc:647): Set receiving_switching_delay to 1000
streamer    | [151:388][9] (jsep_transport_controller.cc:1058): Creating DtlsSrtpTransport.

Given it only happens with a 'layout', I'm guessing that's when the streamer is reencoding?

I tried adding -o to the command. It ran successfully until I reloaded the page:

streamer    | [050:487][17] (livevideosource.h:53): LiveVideoSource::Start
streamer    | Sending request: SETUP rtsp://192.168.2.35:554/streaming/channels/1/trackID=1 RTSP/1.0
streamer    | CSeq: 3
streamer    | User-Agent: LIVE555 Streaming Media v2021.08.24
streamer    | Transport: RTP/AVP/TCP;unicast;interleaved=0-1
streamer    | 
streamer    | 
streamer    | [050:487][17] (VideoDecoder.h:79): VideoDecoder::start
streamer    | [050:487][17] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://192.168.2.37:554/streaming/channels/1
streamer    | [050:487][17] (PeerConnectionManager.cpp:1004): audiourl:driveway3
streamer    | [050:487][17] (audio_device_impl.cc:332): Init
streamer    | Created new TCP socket 18 for connection
streamer    | Connecting to 192.168.2.37, port 554 on socket 18...
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1571): mainloop running!
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1305): context state cb
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1315): no state
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1305): context state cb
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1319): failed
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1605): failed to connect context, error=-1
streamer    | [050:487][17] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | [050:487][19] (PeerConnectionManager.cpp:688): remote_description is ready
streamer    | [050:487][19] (PeerConnectionManager.cpp:992): videourl:rtsp://192.168.2.38:554/streaming/channels/1
streamer    | [050:487][19] (livevideosource.h:53): LiveVideoSource::Start
streamer    | [050:487][19] (VideoDecoder.h:79): VideoDecoder::start
streamer    | [050:487][19] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://192.168.2.38:554/streaming/channels/1
streamer    | [050:487][19] (PeerConnectionManager.cpp:1004): audiourl:backyard1
streamer    | [050:487][19] (audio_device_impl.cc:332): Init
streamer    | [050:487][19] (audio_device_pulse_linux.cc:1555): PA mainloop has already existed
streamer    | [050:487][19] (audio_device_pulse_linux.cc:145): failed to initialize PulseAudio
streamer    | Created new TCP socket 23 for connection
streamer    | Connecting to 192.168.2.38, port 554 on socket 23...
streamer    | [050:487][17] (audio_device_pulse_linux.cc:1688): PulseAudio terminated
streamer    | [050:487][17] (audio_device_impl.cc:341): Audio device initialization failed.
streamer    | [050:487][17] (audio_device_impl.cc:730): RecordingDevices
streamer    | [050:487][17] (CapturerFactory.h:275): audiourl: idx_audioDevice:-1/-1
streamer    | [050:487][17] (PeerConnectionManager.cpp:1119): Adding Stream to map
streamer    | pa_write() failed while trying to wake up the mainloop: Bad file descriptor
streamer    | Assertion 't' failed at pulsecore/thread-posix.c:136, function pa_thread_join(). Aborting.

restarting it, no changes:

streamer    | [002:966][1] (webrtc_video_engine.cc:1340): AddSendStream: {id:6aad7ec4-e3f5-4332-9c36-d1bc86fcba1b;ssrcs:[219751150,2106351166];ssrc_groups:{semantics:FID;ssrcs:[219751150,2106351166]};cname:b2dTg6p392r2NJZ5;stream_ids:driveway3||tcp60;}
streamer    | [002:966][1] (webrtc_video_engine.cc:2260): RecreateWebRtcStream (send) because of SetCodec.
streamer    | [002:966][1] (paced_sender.cc:187): ProcessThreadAttached 0xa6d9d680
streamer    | [002:966][1] (alr_experiment.cc:79): Using ALR experiment settings: pacing factor: 1, max pacer queue length: 2875, ALR bandwidth usage percent: 80, ALR start budget level percent: 40, ALR end budget level percent: -60, ALR experiment group ID: 3
streamer    | [002:966][1] (video_stream_encoder.cc:2173): Automatic animation detection experiment is disabled.
streamer    | [002:966][13] (HttpServerRequestHandler.cpp:61): uri:/api/call
streamer exited with code 139

and again:

streamer    | [003:152][9] (p2p_transport_channel.cc:531): Received remote ICE parameters: ufrag=ALa+, renomination disabled
streamer    | [003:152][9] (basic_ice_controller.cc:541): Sorting 0 available connections
streamer    | [003:152][9] (basic_ice_controller.cc:541): Sorting 0 available connections
streamer    | [003:152][9] (basic_ice_controller.cc:541): Sorting 0 available connections
streamer    | webrtc-streamer: ../nptl/pthread_mutex_lock.c:438: __pthread_mutex_lock_full: Assertion `robust || (oldval & FUTEX_OWNER_DIED) == 0' failed.
streamer exited with code 139

Hoping these logs are useful.

tedder commented 3 years ago

Seeing the mutex fail gave me an idea, I set -N1 and everything worked. That means my full command is -vvv -C /app/config.json -o -N1.

I'm now running with less verbosity (-v) and those settings and testing thread counts. It seems that N needs to be less than the number of cameras- I mean, I have 5 RTSP inputs and -N5 or -N16 will crash. But -N4 does not, and obviously -N1, -N3 etc work too.

mpromonet commented 2 years ago

Hi Ted,

It is difficult to follow your tests, -N change the number of thread used by the http server. This may have impact on called that are done in the http thread. Running under a debugger may help you to identify the call that raised the assert.

Best Regards, Michel.

tedder commented 2 years ago

I understand what you mean, Michel, a debugger would help. But think about why I used -N and what the meaning is- given a mutex failed, it stands to reason there's a thread contention issue. What it shows is that if I have M cameras, the number of threads must be set to M-1, any more will fail.

Feel free to close, but it's a note that might be combined with future issues that show threading problems.

mpromonet commented 2 years ago

Hi Ted,

I just try to understand the problem you described, I know there is thread management errors (between the WebRTC thread & http threads). This is why using -N1 makes all http invocation use the same thread (which is not the WebRTC signaling thread), but I don't reproduce the educated guess you made between the number of stream and the number of http threads. Maybe WebRTC SDK changes...

Best Regards, Michel.