webrtc-streamer
webrtc-streamer copied to clipboard
Published
20 hours ago •
mpromonet
mpromonet
Hangup on failed ice connection state
I'm having an issue where an unexpected hangup is called due the an ice connection state observation being failed. This is happening after the first ice candidate is sent from a remote peer to the server. Then all subsequent ice candidates return 500 Internal Server Error, since the peerConnection has closed. The problem is that it seems to be intermittent, but when the failure does happen, it happens after the first ice candidate is received.
Running the server with:
./webrtc-streamer -v -H 8000 -n axis -u rtsp://192.168.7.157/axis-media/media.3gp
Work around If I comment out the following lines, my connections are established reliably every time. https://github.com/mpromonet/webrtc-streamer/blob/master/inc/PeerConnectionManager.h#L239-L248
To Reproduce Steps to reproduce the behavior:
- Send offer with /api/call
- Handle answer and set remote description on client side
- Start sending ice candidates via /api/addIceCandidate
Desktop:
- OS: Ubuntu 18.04
Smartphone:
- Device: Essential PH1
- OS: Android 10
- Flutter webrtc
Here is an output of the server's log:
[027:098][18627] (HttpServerRequestHandler.cpp:61): uri:/api/call
[027:098][18627] (PeerConnectionManager.cpp:650): call video:axis audio: options:
[027:098][18627] (PeerConnectionManager.cpp:987): CreatePeerConnectionCreatePeerConnection webrtcPortRange:0:65535
[027:098][18627] (PeerConnectionManager.cpp:989): CreatePeerConnectionCreatePeerConnection peerid:18636ccef0a8b495
[027:098][18627] (PeerConnectionManager.h:170): PeerConnectionObserverCreatePeerConnection peerid:18636ccef0a8b495
[027:098][18575] (peer_connection_factory.cc:357): Using default network controller factory
[027:098][18575] (bitrate_prober.cc:72): Bandwidth probing enabled, set to inactive
[027:099][18575] (pacing_controller.cc:230): bwe:pacer_updated pacing_kbps=300 padding_budget_kbps=0
[027:099][18575] (aimd_rate_control.cc:113): Using aimd rate control with back off factor 0.85
[027:099][18575] (remote_bitrate_estimator_single_stream.cc:72): RemoteBitrateEstimatorSingleStream: Instantiating.
[027:099][18575] (remote_estimator_proxy.cc:50): Maximum interval between transport feedback RTCP messages (ms): 250
[027:100][18575] (webrtc_session_description_factory.cc:185): DTLS-SRTP enabled; sending DTLS identity request (key type: 1).
[027:100][18576] (openssl_key_pair.cc:38): Making key pair
[027:100][18627] (PeerConnectionManager.h:177): PeerConnectionObserverCreateDataChannel peerid:18636ccef0a8b495
[027:100][18576] (openssl_key_pair.cc:91): Returning key pair
[027:100][18576] (boringssl_certificate.cc:187): Making certificate for WebRTC
[027:100][18575] (peer_connection.cc:2078): Local and Remote descriptions must be applied to get the SSL Role of the SCTP transport.
[027:100][18575] (PeerConnectionManager.h:229): virtual void PeerConnectionManager::PeerConnectionObserver::OnRenegotiationNeeded() peerid:18636ccef0a8b495
[027:101][18576] (boringssl_certificate.cc:243): Returning certificate
[027:101][18575] (webrtc_session_description_factory.cc:491): Setting new certificate.
[027:101][18627] (PeerConnectionManager.cpp:676): nbStreams local:0 remote:0 localDescription:0
[027:102][18576] (p2p_transport_channel.cc:532): Set backup connection ping interval to 25000 milliseconds.
[027:102][18576] (p2p_transport_channel.cc:541): Set ICE receiving timeout to 2500 milliseconds
[027:102][18576] (p2p_transport_channel.cc:548): Set ping most likely connection to 0
[027:102][18576] (p2p_transport_channel.cc:555): Set stable_writable_connection_ping_interval to 2500
[027:102][18576] (p2p_transport_channel.cc:568): Set presume writable when fully relayed to 0
[027:102][18576] (p2p_transport_channel.cc:586): Set regather_on_failed_networks_interval to 300000
[027:102][18576] (p2p_transport_channel.cc:593): Set receiving_switching_delay to 1000
[027:102][18576] (jsep_transport_controller.cc:990): Creating DtlsSrtpTransport.
[027:102][18576] (dtls_srtp_transport.cc:62): Setting RTCP Transport on video transport 0
[027:102][18576] (dtls_srtp_transport.cc:67): Setting RTP Transport on video transport a8003180
[027:102][18576] (p2p_transport_channel.cc:532): Set backup connection ping interval to 25000 milliseconds.
[027:102][18576] (p2p_transport_channel.cc:541): Set ICE receiving timeout to 2500 milliseconds
[027:102][18576] (p2p_transport_channel.cc:548): Set ping most likely connection to 0
[027:102][18576] (p2p_transport_channel.cc:555): Set stable_writable_connection_ping_interval to 2500
[027:102][18576] (p2p_transport_channel.cc:568): Set presume writable when fully relayed to 0
[027:102][18576] (p2p_transport_channel.cc:586): Set regather_on_failed_networks_interval to 300000
[027:102][18576] (p2p_transport_channel.cc:593): Set receiving_switching_delay to 1000
[027:102][18576] (jsep_transport_controller.cc:990): Creating DtlsSrtpTransport.
[027:102][18576] (dtls_srtp_transport.cc:62): Setting RTCP Transport on data transport 0
[027:102][18576] (dtls_srtp_transport.cc:67): Setting RTP Transport on data transport a80060f0
[027:102][18576] (p2p_transport_channel.cc:477): Received remote ICE parameters: ufrag=g6Og, renomination enabled
[027:102][18576] (p2p_transport_channel.cc:477): Received remote ICE parameters: ufrag=g6Og, renomination enabled
[027:102][18576] (basic_ice_controller.cc:541): Sorting 0 available connections
[027:102][18576] (basic_ice_controller.cc:541): Sorting 0 available connections
[027:103][18575] (webrtc_video_engine.cc:642): CreateMediaChannel. Options: VideoOptions {}
[027:103][18575] (channel.cc:150): Created channel: {mid: video, media_type: video}
[027:103][18576] (rtp_demuxer.cc:144): Added sink = cbee8f38 for criteria {mid: video, rsid: <empty>, ssrcs: [], payload_types = []}
[027:103][18576] (webrtc_video_engine.cc:1819): OnReadyToSend: Not ready.
[027:104][18576] (peer_connection.cc:2381): Setting up data channel transport for mid=data
[027:104][18575] (sdp_offer_answer.cc:2474): Session: 8178979125915891486 Old state: stable New state: have-remote-offer
[027:104][18575] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:3 peerid:18636ccef0a8b495
[027:104][18575] (webrtc_video_engine.cc:1572): ResetUnsignaledRecvStream.
[027:104][18576] (rtp_demuxer.cc:240): Removed sink = cbee8f38 bindings
[027:104][18576] (rtp_demuxer.cc:144): Added sink = cbee8f38 for criteria {mid: video, rsid: <empty>, ssrcs: [], payload_types = []}
[027:104][18575] (channel.cc:1187): Setting remote video description for {mid: video, media_type: video}
[027:104][18575] (webrtc_video_engine.cc:883): SetSendParameters: {codecs: [VideoCodec[96:VP8], VideoCodec[97:rtx], VideoCodec[98:VP9], VideoCodec[99:rtx], VideoCodec[124:H264], VideoCodec[100:H264], VideoCodec[101:rtx], VideoCodec[127:red], VideoCodec[123:rtx], VideoCodec[125:ulpfec]], conference_mode: no, extensions: [{uri: urn:ietf:params:rtp-hdrext:toffset, id: 1}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time, id: 2}, {uri: urn:3gpp:video-orientation, id: 3}, {uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 4}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/playout-delay, id: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-content-type, id: 6}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-timing, id: 7}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/color-space, id: 8}], extmap-allow-mixed: false, max_bandwidth_bps: -1, mid: video}
[027:104][18575] (webrtc_video_engine.cc:891): Negotiated codec: VideoCodec[96:VP8]
[027:104][18575] (webrtc_video_engine.cc:891): Negotiated codec: VideoCodec[98:VP9]
[027:104][18575] (webrtc_video_engine.cc:891): Negotiated codec: VideoCodec[100:H264]
[027:104][18575] (webrtc_video_engine.cc:1040): SetFeedbackParameters on all the receive streams because the send codec or RTCP mode has changed.
[027:104][18576] (rtp_demuxer.cc:240): Removed sink = cbee8f38 bindings
[027:105][18576] (rtp_demuxer.cc:144): Added sink = cbee8f38 for criteria {mid: video, rsid: <empty>, ssrcs: [], payload_types = []}
[027:105][18576] (rtp_demuxer.cc:240): Removed sink = cbee8f38 bindings
[027:105][18576] (rtp_demuxer.cc:144): Added sink = cbee8f38 for criteria {mid: video, rsid: <empty>, ssrcs: [], payload_types = []}
[027:105][18575] (webrtc_video_engine.cc:1280): SetSend: false
[027:105][18575] (channel.cc:1072): Changing video state, send=0 for {mid: video, media_type: video}
[027:105][18575] (peer_connection.cc:2078): Local and Remote descriptions must be applied to get the SSL Role of the SCTP transport.
[027:105][18575] (call.cc:1232): UpdateAggregateNetworkState: aggregate_state remains at down
[027:105][18575] (rtp_transport_controller_send.cc:357): SignalNetworkState Down
[027:105][18627] (PeerConnectionManager.cpp:698): remote_description is ready
[027:105][18627] (PeerConnectionManager.cpp:1004): videourl:rtsp://192.168.7.157/axis-media/media.3gp
[027:105][18627] (livevideosource.h:53): LiveVideoSource::Start
[027:105][18575] (PeerConnectionManager.h:71): virtual void PeerConnectionManager::SetSessionDescriptionObserver::OnSuccess() Remote SDP:v=0
o=- 7582646689891582646 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE video data
a=msid-semantic: WMS
m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 124 100 101 127 123 125
c=IN IP4 0.0.0.0
a=rtcp:9 IN IP4 0.0.0.0
a=ice-ufrag:g6Og
a=ice-pwd:TnO/WCdx9gLmUeEc4i2cmr8c
a=ice-options:trickle renomination
a=fingerprint:sha-256 0C:BB:09:BC:89:F5:BC:DF:88:01:10:20:4C:BC:DF:8D:B6:F6:62:DF:D3:E1:CA:55:89:A6:08:A2:EB:D9:B4:5F
a=setup:actpass
a=mid:video
a=extmap:1 urn:ietf:params:rtp-hdrext:toffset
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:3 urn:3gpp:video-orientation
a=extmap:4 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
a=extmap:5 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay
a=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type
a=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-timing
a=extmap:8 http://www.webrtc.org/experiments/rtp-hdrext/color-space
a=recvonly
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 VP8/90000
a=rtcp-fb:96 goog-remb
a=rtcp-fb:96 transport-cc
a=rtcp-fb:96 ccm fir
a=rtcp-fb:96 nack
a=rtcp-fb:96 nack pli
a=rtpmap:97 rtx/90000
a=fmtp:97 apt=96
a=rtpmap:98 VP9/90000
a=rtcp-fb:98 goog-remb
a=rtcp-fb:98 transport-cc
a=rtcp-fb:98 ccm fir
a=rtcp-fb:98 nack
a=rtcp-fb:98 nack pli
a=rtpmap:99 rtx/90000
a=fmtp:99 apt=98
a=rtpmap:124 H264/90000
a=rtcp-fb:124 goog-remb
a=rtcp-fb:124 transport-cc
a=rtcp-fb:124 ccm fir
a=rtcp-fb:124 nack
a=rtcp-fb:124 nack pli
a=fmtp:124 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=640c1f
a=rtpmap:100 H264/90000
a=rtcp-fb:100 goog-remb
a=rtcp-fb:100 transport-cc
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f
a=rtpmap:101 rtx/90000
a=fmtp:101 apt=100
a=rtpmap:127 red/90000
a=rtpmap:123 rtx/90000
a=fmtp:123 apt=127
a=rtpmap:125 ulpfec/90000
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=ice-ufrag:g6Og
a=ice-pwd:TnO/WCdx9gLmUeEc4i2cmr8c
a=ice-options:trickle renomination
a=fingerprint:sha-256 0C:BB:09:BC:89:F5:BC:DF:88:01:10:20:4C:BC:DF:8D:B6:F6:62:DF:D3:E1:CA:55:89:A6:08:A2:EB:D9:B4:5F
a=setup:actpass
a=mid:data
a=sctp-port:5000
a=max-message-size:262144
[027:105][18627] (VideoDecoder.h:79): VideoDecoder::start
[027:105][18627] (rtspvideocapturer.cpp:19): RTSPVideoCapturer rtsp://192.168.7.157/axis-media/media.3gp
[027:105][18627] (PeerConnectionManager.cpp:1016): audiourl:axis
[027:105][18627] (CapturerFactory.h:246): audiourl: idx_audioDevice:-1/0
[027:105][18627] (PeerConnectionManager.cpp:1131): Adding Stream to map
Created new TCP socket 11 for connection
Connecting to 192.168.7.157, port 554 on socket 11...
[027:106][18627] (PeerConnectionManager.cpp:1171): Cannot create capturer audio:axis
[027:106][18575] (PeerConnectionManager.h:229): virtual void PeerConnectionManager::PeerConnectionObserver::OnRenegotiationNeeded() peerid:18636ccef0a8b495
[027:106][18627] (PeerConnectionManager.cpp:1188): stream added to PeerConnection
[027:107][18575] (media_session.cc:2808): Data is not supported in the answer.
[027:107][18575] (PeerConnectionManager.h:97): virtual void PeerConnectionManager::CreateSessionDescriptionObserver::OnSuccess(webrtc::SessionDescriptionInterface*) type:answer sdp:v=0
o=- 8178979125915891486 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE video data
a=msid-semantic: WMS axis||
m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 127 123 125
c=IN IP4 0.0.0.0
a=rtcp:9 IN IP4 0.0.0.0
a=ice-ufrag:j7od
a=ice-pwd:KQtgxbYB4hI+fh+YVBhIriEa
a=ice-options:trickle
a=fingerprint:sha-256 2F:62:B8:A7:0F:72:1B:60:1D:63:F2:2D:F1:F3:E1:F1:63:20:D9:D2:76:D5:42:13:A6:42:1E:C7:F6:5A:B2:5F
a=setup:active
a=mid:video
a=extmap:1 urn:ietf:params:rtp-hdrext:toffset
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:3 urn:3gpp:video-orientation
a=extmap:4 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
a=extmap:5 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay
a=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type
a=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-timing
a=extmap:8 http://www.webrtc.org/experiments/rtp-hdrext/color-space
a=sendonly
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 VP8/90000
a=rtcp-fb:96 goog-remb
a=rtcp-fb:96 transport-cc
a=rtcp-fb:96 ccm fir
a=rtcp-fb:96 nack
a=rtcp-fb:96 nack pli
a=rtpmap:97 rtx/90000
a=fmtp:97 apt=96
a=rtpmap:98 VP9/90000
a=rtcp-fb:98 goog-remb
a=rtcp-fb:98 transport-cc
a=rtcp-fb:98 ccm fir
a=rtcp-fb:98 nack
a=rtcp-fb:98 nack pli
a=fmtp:98 profile-id=0
a=rtpmap:99 rtx/90000
a=fmtp:99 apt=98
a=rtpmap:100 H264/90000
a=rtcp-fb:100 goog-remb
a=rtcp-fb:100 transport-cc
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f
a=rtpmap:101 rtx/90000
a=fmtp:101 apt=100
a=rtpmap:127 red/90000
a=rtpmap:123 rtx/90000
a=fmtp:123 apt=127
a=rtpmap:125 ulpfec/90000
a=ssrc-group:FID 1779450374 2153476749
a=ssrc:1779450374 cname:KaQQEzvzsPhMtg0R
a=ssrc:1779450374 msid:axis|| axis||_video
a=ssrc:1779450374 mslabel:axis||
a=ssrc:1779450374 label:axis||_video
a=ssrc:2153476749 cname:KaQQEzvzsPhMtg0R
a=ssrc:2153476749 msid:axis|| axis||_video
a=ssrc:2153476749 mslabel:axis||
a=ssrc:2153476749 label:axis||_video
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=ice-ufrag:j7od
a=ice-pwd:KQtgxbYB4hI+fh+YVBhIriEa
a=ice-options:trickle
a=fingerprint:sha-256 2F:62:B8:A7:0F:72:1B:60:1D:63:F2:2D:F1:F3:E1:F1:63:20:D9:D2:76:D5:42:13:A6:42:1E:C7:F6:5A:B2:5F
a=setup:active
a=mid:data
a=sctp-port:5000
a=max-message-size:262144
[027:107][18576] (dtls_srtp_transport.cc:62): Setting RTCP Transport on video transport 0
[027:107][18576] (dtls_srtp_transport.cc:67): Setting RTP Transport on video transport a8003180
[027:107][18576] (p2p_transport_channel.cc:466): Set ICE ufrag: j7od pwd: KQtgxbYB4hI+fh+YVBhIriEa on transport video
[027:107][18576] (dtls_transport.cc:367): DtlsTransport[video|1|__]: DTLS setup complete.
[027:107][18575] (channel.cc:541): Channel enabled: {mid: video, media_type: video}
[027:107][18575] (webrtc_video_engine.cc:1280): SetSend: false
[027:107][18575] (channel.cc:1072): Changing video state, send=0 for {mid: video, media_type: video}
[027:107][18575] (sdp_offer_answer.cc:2474): Session: 8178979125915891486 Old state: have-remote-offer New state: stable
[027:107][18575] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:0 peerid:18636ccef0a8b495
[027:107][18575] (channel.cc:1087): Setting local video description for {mid: video, media_type: video}
[027:108][18575] (webrtc_video_engine.cc:1340): AddSendStream: {id:axis||_video;ssrcs:[1779450374,2153476749];ssrc_groups:{semantics:FID;ssrcs:[1779450374,2153476749]};cname:KaQQEzvzsPhMtg0R;stream_ids:axis||;}
[027:108][18575] (webrtc_video_engine.cc:2229): RecreateWebRtcStream (send) because of SetCodec.
[027:108][18575] (paced_sender.cc:187): ProcessThreadAttached 0xcbee7140
[027:108][18575] (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
[027:108][18575] (video_stream_encoder.cc:2189): Automatic animation detection experiment is disabled.
[027:108][18753] (video_send_stream_impl.cc:246): VideoSendStreamInternal: {encoder_settings: { experiment_cpu_load_estimator: off}}, rtp: {ssrcs: [1779450374], rids: [], mid: 'video', rtcp_mode: RtcpMode::kReducedSize, max_packet_size: 1200, extmap-allow-mixed: false, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 4}, {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: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-content-type, id: 6}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-timing, id: 7}, {uri: urn:3gpp:video-orientation, id: 3}], lntf: {enabled: false}, nack: {rtp_history_ms: 1000}, ulpfec: {ulpfec_payload_type: 125, red_payload_type: 127, red_rtx_payload_type: 123}, payload_name: VP8, payload_type: 96, raw_payload: false, flexfec: {payload_type: -1, ssrc: 0, protected_media_ssrcs: []}, rtx: {ssrcs: [2153476749], payload_type: 97}, c_name: KaQQEzvzsPhMtg0R}, rtcp_report_interval_ms: 1000, send_transport: (Transport), render_delay_ms: 0, target_delay_ms: 0, suspend_below_min_bitrate: off}
[027:108][18758] (video_stream_encoder.cc:798): SetStartBitrate 300000
[027:108][18575] (call.cc:1232): UpdateAggregateNetworkState: aggregate_state remains at down
[027:108][18575] (rtp_transport_controller_send.cc:357): SignalNetworkState Down
[027:108][18758] (video_stream_encoder.cc:813): ConfigureEncoder requested.
[027:108][18575] (video_send_stream.cc:187): VideoSendStream::Stop
[027:109][18575] (webrtc_video_engine.cc:1380): SetLocalSsrc on all the receive streams because we added a send stream.
[027:109][18575] (channel.cc:700): Add send stream ssrc: 1779450374 into {mid: video, media_type: video}
[027:109][18575] (webrtc_video_engine.cc:1280): SetSend: false
[027:109][18575] (video_send_stream.cc:187): VideoSendStream::Stop
[027:109][18575] (channel.cc:1072): Changing video state, send=0 for {mid: video, media_type: video}
[027:109][18753] (video_send_stream_impl.cc:405): VideoSendStreamImpl::Stop
[027:109][18753] (video_send_stream_impl.cc:405): VideoSendStreamImpl::Stop
[027:109][18575] (webrtc_video_engine.cc:1299): SetVideoSend (ssrc= 1779450374, options: VideoOptions {is_screencast : false, }, source = (source))
[027:109][18758] (video_stream_encoder.cc:813): ConfigureEncoder requested.
...remote connection opened
Sending request: DESCRIBE rtsp://192.168.7.157/axis-media/media.3gp RTSP/1.0
CSeq: 2
User-Agent: LIVE555 Streaming Media v2019.12.05
Accept: application/sdp
[027:109][18576] (basic_port_allocator.cc:375): Start getting ports with turn_port_prune_policy 0
[027:110][18576] (basic_port_allocator.cc:111): Filtered out ignored networks:
[027:110][18576] (basic_port_allocator.cc:113): Net[lo:0:0:0:x:x:x:x:x/128:Loopback:id=4]
[027:110][18576] (basic_port_allocator.cc:113): Net[lo:127.0.0.x/8:Loopback:id=3]
[027:110][18576] (basic_port_allocator.cc:861): Network manager has started
[027:110][18576] (basic_port_allocator.cc:111): Filtered out ignored networks:
[027:110][18576] (basic_port_allocator.cc:113): Net[lo:0:0:0:x:x:x:x:x/128:Loopback:id=4]
[027:110][18576] (basic_port_allocator.cc:113): Net[lo:127.0.0.x/8:Loopback:id=3]
[027:110][18576] (basic_port_allocator.cc:776): Allocate ports on 2 networks
[027:110][18576] (basic_port_allocator.cc:1361): Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]: Allocation Phase=Udp
[027:110][18576] (port.cc:186): Port[a8034330::1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Port created with network cost 50
[027:110][18576] (basic_port_allocator.cc:1433): AllocationSequence: UDPPort will be handling the STUN candidate generation.
[027:110][18576] (basic_port_allocator.cc:885): Adding allocated port for video
[027:110][18576] (basic_port_allocator.cc:907): Port[a8034330:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Added port to allocator
[027:110][18576] (basic_port_allocator.cc:925): Port[a8034330:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Gathered candidate: Cand[:3385543298:1:udp:2122265343:[fdd4:1053:51ad:x:x:x:x:x]:39982:local::0:j7od:KQtgxbYB4hI+fh+YVBhIriEa:2:50:0]
[027:110][18576] (basic_port_allocator.cc:958): Port[a8034330:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Port ready.
[027:110][18576] (basic_ice_controller.cc:541): Sorting 0 available connections
[027:110][18576] (stun_port.cc:439): Port[a8034330:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Starting STUN host lookup for stun.l.google.com:19302
[027:110][18576] (basic_port_allocator.cc:1361): Net[enp0s5:192.168.7.x/24:Unknown:id=1]: Allocation Phase=Udp
[027:110][18576] (port.cc:186): Port[a8035890::1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Port created with network cost 50
[027:110][18576] (basic_port_allocator.cc:1433): AllocationSequence: UDPPort will be handling the STUN candidate generation.
[027:110][18576] (basic_port_allocator.cc:885): Adding allocated port for video
[027:110][18576] (basic_port_allocator.cc:907): Port[a8035890:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Added port to allocator
[027:110][18576] (basic_port_allocator.cc:925): Port[a8035890:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Gathered candidate: Cand[:3223486757:1:udp:2122194687:192.168.7.x:57009:local::0:j7od:KQtgxbYB4hI+fh+YVBhIriEa:1:50:0]
[027:110][18576] (basic_port_allocator.cc:958): Port[a8035890:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Port ready.
[027:110][18576] (basic_ice_controller.cc:541): Sorting 0 available connections
[027:110][18576] (stun_port.cc:439): Port[a8035890:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Starting STUN host lookup for stun.l.google.com:19302
[027:110][18576] (sctp_transport.cc:672): SctpTransport->OpenStream(...): Not adding data stream with sid=0 because stream is already open.
[027:110][18627] (HttpServerRequestHandler.cpp:82): code:200 answer:{
"sdp" : "v=0\r\no=- 8178979125915891486 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE video data\r\na=msid-semantic: WMS axis||\r\nm=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 127 123 125\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:j7od\r\na=ice-pwd:KQtgxbYB4hI+fh+YVBhIriEa\r\na=ice-options:trickle\r\na=fingerprint:sha-256 2F:62:B8:A7:0F:72:1B:60:1D:63:F2:2D:F1:F3:E1:F1:63:20:D9:D2:76:D5:42:13:A6:42:1E:C7:F6:5A:B2:5F\r\na=setup:active\r\na=mid:video\r\na=extmap:1 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:3 urn:3gpp:video-orientation\r\na=extmap:4 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01\r\na=extmap:5 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay\r\na=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type\r\na=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-timing\r\na=extmap:8 http://www.webrtc.org/experiments/rtp-hdrext/color-space\r\na=sendonly\r\na=rtcp-mux\r\na=rtcp-rsize\r\na=rtpmap:96 VP8/90000\r\na=rtcp-fb:96 goog-remb\r\na=rtcp-fb:96 transport-cc\r\na=rtcp-fb:96 ccm fir\r\na=rtcp-fb:96 nack\r\na=rtcp-fb:96 nack pli\r\na=rtpmap:97 rtx/90000\r\na=fmtp:97 apt=96\r\na=rtpmap:98 VP9/90000\r\na=rtcp-fb:98 goog-remb\r\na=rtcp-fb:98 transport-cc\r\na=rtcp-fb:98 ccm fir\r\na=rtcp-fb:98 nack\r\na=rtcp-fb:98 nack pli\r\na=fmtp:98 profile-id=0\r\na=rtpmap:99 rtx/90000\r\na=fmtp:99 apt=98\r\na=rtpmap:100 H264/90000\r\na=rtcp-fb:100 goog-remb\r\na=rtcp-fb:100 transport-cc\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 nack pli\r\na=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\r\na=rtpmap:101 rtx/90000\r\na=fmtp:101 apt=100\r\na=rtpmap:127 red/90000\r\na=rtpmap:123 rtx/90000\r\na=fmtp:123 apt=127\r\na=rtpmap:125 ulpfec/90000\r\na=ssrc-group:FID 1779450374 2153476749\r\na=ssrc:1779450374 cname:KaQQEzvzsPhMtg0R\r\na=ssrc:1779450374 msid:axis|| axis||_video\r\na=ssrc:1779450374 mslabel:axis||\r\na=ssrc:1779450374 label:axis||_video\r\na=ssrc:2153476749 cname:KaQQEzvzsPhMtg0R\r\na=ssrc:2153476749 msid:axis|| axis||_video\r\na=ssrc:2153476749 mslabel:axis||\r\na=ssrc:2153476749 label:axis||_video\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=ice-ufrag:j7od\r\na=ice-pwd:KQtgxbYB4hI+fh+YVBhIriEa\r\na=ice-options:trickle\r\na=fingerprint:sha-256 2F:62:B8:A7:0F:72:1B:60:1D:63:F2:2D:F1:F3:E1:F1:63:20:D9:D2:76:D5:42:13:A6:42:1E:C7:F6:5A:B2:5F\r\na=setup:active\r\na=mid:data\r\na=sctp-port:5000\r\na=max-message-size:262144\r\n",
"type" : "answer"
}
[027:110][18575] (PeerConnectionManager.h:65): virtual void PeerConnectionManager::SetSessionDescriptionObserver::OnSuccess() Local SDP:v=0
o=- 8178979125915891486 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE video data
a=msid-semantic: WMS axis||
m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 127 123 125
c=IN IP4 0.0.0.0
a=rtcp:9 IN IP4 0.0.0.0
a=ice-ufrag:j7od
a=ice-pwd:KQtgxbYB4hI+fh+YVBhIriEa
a=ice-options:trickle
a=fingerprint:sha-256 2F:62:B8:A7:0F:72:1B:60:1D:63:F2:2D:F1:F3:E1:F1:63:20:D9:D2:76:D5:42:13:A6:42:1E:C7:F6:5A:B2:5F
a=setup:active
a=mid:video
a=extmap:1 urn:ietf:params:rtp-hdrext:toffset
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:3 urn:3gpp:video-orientation
a=extmap:4 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
a=extmap:5 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay
a=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type
a=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-timing
a=extmap:8 http://www.webrtc.org/experiments/rtp-hdrext/color-space
a=sendonly
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 VP8/90000
a=rtcp-fb:96 goog-remb
a=rtcp-fb:96 transport-cc
a=rtcp-fb:96 ccm fir
a=rtcp-fb:96 nack
a=rtcp-fb:96 nack pli
a=rtpmap:97 rtx/90000
a=fmtp:97 apt=96
a=rtpmap:98 VP9/90000
a=rtcp-fb:98 goog-remb
a=rtcp-fb:98 transport-cc
a=rtcp-fb:98 ccm fir
a=rtcp-fb:98 nack
a=rtcp-fb:98 nack pli
a=fmtp:98 profile-id=0
a=rtpmap:99 rtx/90000
a=fmtp:99 apt=98
a=rtpmap:100 H264/90000
a=rtcp-fb:100 goog-remb
a=rtcp-fb:100 transport-cc
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f
a=rtpmap:101 rtx/90000
a=fmtp:101 apt=100
a=rtpmap:127 red/90000
a=rtpmap:123 rtx/90000
a=fmtp:123 apt=127
a=rtpmap:125 ulpfec/90000
a=ssrc-group:FID 1779450374 2153476749
a=ssrc:1779450374 cname:KaQQEzvzsPhMtg0R
a=ssrc:1779450374 msid:axis|| axis||_video
a=ssrc:1779450374 mslabel:axis||
a=ssrc:1779450374 label:axis||_video
a=ssrc:2153476749 cname:KaQQEzvzsPhMtg0R
a=ssrc:2153476749 msid:axis|| axis||_video
a=ssrc:2153476749 mslabel:axis||
a=ssrc:2153476749 label:axis||_video
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=ice-ufrag:j7od
a=ice-pwd:KQtgxbYB4hI+fh+YVBhIriEa
a=ice-options:trickle
a=fingerprint:sha-256 2F:62:B8:A7:0F:72:1B:60:1D:63:F2:2D:F1:F3:E1:F1:63:20:D9:D2:76:D5:42:13:A6:42:1E:C7:F6:5A:B2:5F
a=setup:active
a=mid:data
a=sctp-port:5000
a=max-message-size:262144
[027:111][18576] (stun_request.cc:274): Sent STUN request 1; resend delay = 250
[027:112][18576] (stun_request.cc:274): Sent STUN request 1; resend delay = 250
[027:112][18575] (PeerConnectionManager.cpp:1207): OnIceCandidate 0
[027:113][18575] (PeerConnectionManager.cpp:1216): candidate:3385543298 1 udp 2122265343 fdd4:1053:51ad:1:c162:b459:7daf:43c 39982 typ host generation 0 ufrag j7od network-id 2 network-cost 50
[027:113][18575] (PeerConnectionManager.cpp:1207): OnIceCandidate 0
[027:113][18575] (PeerConnectionManager.cpp:1216): candidate:3223486757 1 udp 2122194687 192.168.7.159 57009 typ host generation 0 ufrag j7od network-id 1 network-cost 50
[027:135][18576] (basic_port_allocator.cc:925): Port[a8035890:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Gathered candidate: Cand[:1097500561:1:udp:1685987071:208.100.163.x:57009:stun:192.168.7.159:57009:j7od:KQtgxbYB4hI+fh+YVBhIriEa:1:50:0]
[027:135][18576] (basic_port_allocator.cc:1069): Port[a8035890:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Port completed gathering candidates.
[027:135][18575] (PeerConnectionManager.cpp:1207): OnIceCandidate 0
[027:135][18575] (PeerConnectionManager.cpp:1216): candidate:1097500561 1 udp 1685987071 208.100.163.220 57009 typ srflx raddr 192.168.7.159 rport 57009 generation 0 ufrag j7od network-id 1 network-cost 50
[027:161][18576] (basic_port_allocator.cc:1361): Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]: Allocation Phase=Relay
[027:161][18576] (basic_port_allocator.cc:1494): AllocationSequence: Relay ports disabled, skipping.
[027:161][18576] (basic_port_allocator.cc:1361): Net[enp0s5:192.168.7.x/24:Unknown:id=1]: Allocation Phase=Relay
[027:161][18576] (basic_port_allocator.cc:1494): AllocationSequence: Relay ports disabled, skipping.
[027:211][18576] (basic_port_allocator.cc:1361): Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]: Allocation Phase=Tcp
[027:211][18576] (port.cc:186): Port[a803ac90::1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Port created with network cost 50
[027:211][18576] (basic_port_allocator.cc:885): Adding allocated port for video
[027:211][18576] (basic_port_allocator.cc:907): Port[a803ac90:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Added port to allocator
[027:211][18576] (tcp_port.cc:172): Preparing TCP address, current state: 2
[027:211][18576] (basic_port_allocator.cc:925): Port[a803ac90:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Gathered candidate: Cand[:2269689458:1:tcp:1518285567:[fdd4:1053:51ad:x:x:x:x:x]:39021:local::0:j7od:KQtgxbYB4hI+fh+YVBhIriEa:2:50:0]
[027:211][18576] (basic_port_allocator.cc:958): Port[a803ac90:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Port ready.
[027:211][18576] (basic_ice_controller.cc:541): Sorting 0 available connections
[027:211][18576] (basic_port_allocator.cc:1069): Port[a803ac90:video:1:0:local:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]]: Port completed gathering candidates.
[027:211][18576] (basic_port_allocator.cc:1361): Net[enp0s5:192.168.7.x/24:Unknown:id=1]: Allocation Phase=Tcp
[027:211][18576] (port.cc:186): Port[a8030450::1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Port created with network cost 50
[027:211][18575] (PeerConnectionManager.cpp:1207): OnIceCandidate 0
[027:211][18575] (PeerConnectionManager.cpp:1216): candidate:2269689458 1 tcp 1518285567 fdd4:1053:51ad:1:c162:b459:7daf:43c 39021 typ host tcptype passive generation 0 ufrag j7od network-id 2 network-cost 50
[027:211][18576] (basic_port_allocator.cc:885): Adding allocated port for video
[027:211][18576] (basic_port_allocator.cc:907): Port[a8030450:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Added port to allocator
[027:211][18576] (tcp_port.cc:172): Preparing TCP address, current state: 2
[027:211][18576] (basic_port_allocator.cc:925): Port[a8030450:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Gathered candidate: Cand[:2392948181:1:tcp:1518214911:192.168.7.x:54985:local::0:j7od:KQtgxbYB4hI+fh+YVBhIriEa:1:50:0]
[027:211][18576] (basic_port_allocator.cc:958): Port[a8030450:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Port ready.
[027:211][18576] (basic_ice_controller.cc:541): Sorting 0 available connections
[027:212][18576] (basic_port_allocator.cc:1069): Port[a8030450:video:1:0:local:Net[enp0s5:192.168.7.x/24:Unknown:id=1]]: Port completed gathering candidates.
[027:212][18575] (PeerConnectionManager.cpp:1207): OnIceCandidate 0
[027:212][18575] (PeerConnectionManager.cpp:1216): candidate:2392948181 1 tcp 1518214911 192.168.7.159 54985 typ host tcptype passive generation 0 ufrag j7od network-id 1 network-cost 50
[027:243][18617] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[027:249][18617] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[027:249][18576] (connection.cc:312): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|C--W|-|0|0|6520434904453244414|-]: Connection created
[027:249][18617] (PeerConnectionManager.cpp:518): ANSWER true
[027:249][18617] (HttpServerRequestHandler.cpp:82): code:200 answer:true
[027:249][18576] (tcp_port.cc:575): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|C--W|-|0|0|6520434904453244414|-]: Connecting from [fdd4:1053:51ad:x:x:x:x:x]:51355 to [0:0:0:x:x:x:x:x]:40397
[027:249][18576] (connection.cc:406): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|---W|-|0|0|6520434904453244414|-]: Change connected_ to 0
[027:249][18576] (p2p_transport_channel.cc:1406): Channel[video|1|__]: Created connection with origin: 2, total: 1
[027:249][18576] (connection.cc:790): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|---W|-|0|0|6520434904453244414|-]: UpdateState(), ms since last received response=27316521, ms since last received data=27316521, rtt=6000, pings_since_last_response=
[027:250][18576] (basic_ice_controller.cc:541): Sorting 1 available connections
[027:250][18576] (basic_ice_controller.cc:544): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|---W|-|0|0|6520434904453244414|-]
[027:250][18576] (p2p_transport_channel.cc:1860): Channel[video|1|__]: Transport channel state changed from 0 to 2
[027:250][18576] (jsep_transport_controller.cc:1168): video Transport 1 state changed. Check if state is complete.
[027:250][18576] (jsep_transport_controller.cc:1168): video Transport 1 state changed. Check if state is complete.
[027:250][18576] (tcp_port.cc:491): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|---W|-|0|0|6520434904453244414|-]: Connection closed with error 111
[027:250][18576] (connection.cc:753): Conn[a8029210:video:Net[enp0s5:fdd4:1053:51ad:x:x:x:x:x/64:Unknown:id=2]:87ry1d44:1:0:local:tcp:[fdd4:1053:51ad:x:x:x:x:x]:39021->56upS3H0:1:1518157055:local:tcp:[0:0:0:x:x:x:x:x]:40397|---W|-|0|0|6520434904453244414|-]: Connection destroyed
[027:250][18576] (connection.cc:1216): Connection deleted with number of pings sent: 0
[027:250][18575] (peer_connection.cc:1786): Changing standardized IceConnectionState 0 => 1
[027:250][18575] (peer_connection.cc:1767): Changing IceConnectionState 0 => 1
[027:250][18575] (PeerConnectionManager.h:238): virtual void PeerConnectionManager::PeerConnectionObserver::OnIceConnectionChange(webrtc::PeerConnectionInterface::IceConnectionState) state:1 peerid:18636ccef0a8b495
[027:250][18576] (p2p_transport_channel.cc:2055): Channel[video|1|__]: Removed connection a8029210 (0 remaining)
[027:250][18576] (p2p_transport_channel.cc:1860): Channel[video|1|__]: Transport channel state changed from 2 to 3
[027:250][18576] (jsep_transport_controller.cc:1168): video Transport 1 state changed. Check if state is complete.
[027:250][18576] (jsep_transport_controller.cc:1168): video Transport 1 state changed. Check if state is complete.
[027:250][18575] (peer_connection.cc:1767): Changing IceConnectionState 1 => 4
[027:250][18575] (PeerConnectionManager.h:238): virtual void PeerConnectionManager::PeerConnectionObserver::OnIceConnectionChange(webrtc::PeerConnectionInterface::IceConnectionState) state:4 peerid:18636ccef0a8b495
[027:250][18575] (peer_connection.cc:1786): Changing standardized IceConnectionState 1 => 4
[027:250][18761] (PeerConnectionManager.cpp:769): HANGUP CALLED
[027:250][18761] (PeerConnectionManager.cpp:771): hangUp 18636ccef0a8b495
[027:250][18761] (PeerConnectionManager.cpp:780): Remove PeerConnection peerid:18636ccef0a8b495
[027:250][18761] (PeerConnectionManager.cpp:797): hangUp stream is no more used axis||
[027:250][18761] (PeerConnectionManager.cpp:805): hangUp stream closed axis||
[027:251][18575] (webrtc_video_engine.cc:1299): SetVideoSend (ssrc= 1779450374, options: nullptr, source = nullptr)
[027:251][18575] (livevideosource.h:59): LiveVideoSource::stop
[027:260][18575] (VideoDecoder.h:86): VideoDecoder::stop
[027:260][18575] (PeerConnectionManager.h:229): virtual void PeerConnectionManager::PeerConnectionObserver::OnRenegotiationNeeded() peerid:18636ccef0a8b495
[027:260][18761] (PeerConnectionManager.h:188): virtual PeerConnectionManager::PeerConnectionObserver::~PeerConnectionObserver()
[027:261][18575] (webrtc_video_engine.cc:2574): VideoSendStream stats: 27316533, {input_fps: 0, encode_fps: 0, encode_ms: 0, encode_usage_perc: 0, target_bps: 0, media_bps: 0, suspended: false, bw_adapted_res: false, cpu_adapted_res: false, bw_adapted_fps: false, cpu_adapted_fps: false, #cpu_adaptations: 0, #quality_adaptations: 0}
[027:261][18575] (webrtc_video_engine.cc:1644): Call stats: 27316533, {send_bw_bps: 0, recv_bw_bps: 0, max_pad_bps: 0, pacer_delay_ms: 0, rtt_ms: -1}
[027:261][18575] (PeerConnectionManager.h:238): virtual void PeerConnectionManager::PeerConnectionObserver::OnIceConnectionChange(webrtc::PeerConnectionInterface::IceConnectionState) state:6 peerid:18636ccef0a8b495
[027:261][18575] (sdp_offer_answer.cc:2474): Session: 8178979125915891486 Old state: stable New state: closed
[027:261][18575] (PeerConnectionManager.h:235): virtual void PeerConnectionManager::PeerConnectionObserver::OnSignalingChange(webrtc::PeerConnectionInterface::SignalingState) state:5 peerid:18636ccef0a8b495
[027:261][18575] (channel.cc:550): Channel disabled: {mid: video, media_type: video}
[027:261][18575] (webrtc_video_engine.cc:1280): SetSend: false
[027:261][18575] (video_send_stream.cc:187): VideoSendStream::Stop
[027:261][18575] (channel.cc:1072): Changing video state, send=0 for {mid: video, media_type: video}
[027:261][18576] (rtp_demuxer.cc:240): Removed sink = cbee8f38 bindings
[027:261][18575] (video_send_stream.cc:187): VideoSendStream::Stop
[027:263][18753] (video_send_stream_impl.cc:405): VideoSendStreamImpl::Stop
[027:263][18753] (video_send_stream_impl.cc:405): VideoSendStreamImpl::Stop
[027:263][18753] (video_send_stream_impl.cc:405): VideoSendStreamImpl::Stop
[027:263][18753] (video_send_stream_impl.cc:315): ~VideoSendStreamInternal: {encoder_settings: { experiment_cpu_load_estimator: off}}, rtp: {ssrcs: [1779450374], rids: [], mid: 'video', rtcp_mode: RtcpMode::kReducedSize, max_packet_size: 1200, extmap-allow-mixed: false, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 4}, {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: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-content-type, id: 6}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-timing, id: 7}, {uri: urn:3gpp:video-orientation, id: 3}], lntf: {enabled: false}, nack: {rtp_history_ms: 1000}, ulpfec: {ulpfec_payload_type: 125, red_payload_type: 127, red_rtx_payload_type: 123}, payload_name: VP8, payload_type: 96, raw_payload: false, flexfec: {payload_type: -1, ssrc: 0, protected_media_ssrcs: []}, rtx: {ssrcs: [2153476749], payload_type: 97}, c_name: KaQQEzvzsPhMtg0R}, rtcp_report_interval_ms: 1000, send_transport: (Transport), render_delay_ms: 0, target_delay_ms: 0, suspend_below_min_bitrate: off}
[027:263][18575] (call.cc:1232): UpdateAggregateNetworkState: aggregate_state remains at down
[027:263][18575] (rtp_transport_controller_send.cc:357): SignalNetworkState Down
[027:263][18575] (send_statistics_proxy.cc:667): Frames encoded 0
WebRTC.Video.DroppedFrames.Capturer 0
WebRTC.Video.DroppedFrames.EncoderQueue 0
WebRTC.Video.DroppedFrames.Encoder 0
WebRTC.Video.DroppedFrames.Ratelimiter 0
WebRTC.Video.DroppedFrames.CongestionWindow 0
[027:263][18576] (peer_connection.cc:2408): Tearing down data channel transport for mid=data
[027:264][18576] (thread.cc:820): Waiting for the thread to join, but blocking calls have been disallowed
[027:264][18576] (thread.cc:820): Waiting for the thread to join, but blocking calls have been disallowed
[027:264][18575] (paced_sender.cc:187): ProcessThreadAttached 0x0
[027:265][18575] (paced_sender.cc:187): ProcessThreadAttached 0x0
[027:265][18575] (peer_connection.cc:516): Session: 8178979125915891486 is destroyed.
[027:265][18761] (PeerConnectionManager.cpp:820): hangUp p�[027:399][18619] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[027:401][18619] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[027:401][18619] (PeerConnectionManager.cpp:518): ANSWER null
[027:401][18619] (HttpServerRequestHandler.cpp:82): code:500 answer:Internal Server Error
[027:550][18616] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[027:551][18616] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[027:551][18616] (PeerConnectionManager.cpp:518): ANSWER null
[027:551][18616] (HttpServerRequestHandler.cpp:82): code:500 answer:Internal Server Error
[027:706][18615] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[027:708][18615] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[027:708][18615] (PeerConnectionManager.cpp:518): ANSWER null
[027:708][18615] (HttpServerRequestHandler.cpp:82): code:500 answer:Internal Server Error
[027:867][18614] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[027:869][18614] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[027:869][18614] (PeerConnectionManager.cpp:518): ANSWER null
[027:869][18614] (HttpServerRequestHandler.cpp:82): code:500 answer:Internal Server Error
[028:029][18612] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[028:029][18612] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[028:030][18612] (PeerConnectionManager.cpp:518): ANSWER null
[028:030][18612] (HttpServerRequestHandler.cpp:82): code:500 answer:Internal Server Error
[028:183][18613] (HttpServerRequestHandler.cpp:61): uri:/api/addIceCandidate
[028:186][18613] (PeerConnectionManager.cpp:498): PEERID 18636ccef0a8b495
[028:186][18613] (PeerConnectionManager.cpp:518): ANSWER null
[028:186][18613] (HttpServerRequestHandler.cpp:82): code:500 answer:Internal Server Error
Hi pickledgator,
Based on documentation https://hpbn.co/webrtc/ the connection should not be closed in case of state=failed. However hangup should be called when ice connection is closed, otherwise the WebRTC stream will not be closed when client is no more present.
Best Regards, Michel.
That makes sense. Removing the state=failed check in that if statement resolves the issue I was having as well.
Hi,
I made some tests but keeping only state=closed in the test doesnot detect if the webrtc consumer disappear. Probably need to understand more closely your problem.
Best Regards, Michel.