caffeinetv / libcaffeine

A library for broadcasting to Caffeine.tv
https://www.caffeine.tv
GNU General Public License v2.0
16 stars 5 forks source link

Streaming via libcaffeine/linux randomly fails #94

Open jpietek opened 4 years ago

jpietek commented 4 years ago

Streaming via libcaffeine (over linux) results with a random frontend error, js console:

received error { "message": "unable to encode json response: json: error calling MarshalJSON for type json.RawMessage: invalid character 'x' in string escape code" }

Even though the backend webrtc streaming app seems to work fine, executing sendVideo and sendAudio methods in appropriate threads with encode_fps ~= input_fps etc.

[023:066] [22884] (Api.cpp:599): Broadcast heartbeat succeeded
[023:077] [22884] (Api.cpp:169): Request complete           
[023:740] [22916] (Api.cpp:708): Http response [200]
[023:748] [22916] (Api.cpp:169): Request complete                                                
[028:091] [22853] (webrtcvideoengine.cc:2114): VideoSendStream stats: 11251778786, {input_fps: 24, encode_fps: 23, encode_ms: 10, encode_usage_perc: 32, target_bps: 2000000, media_bps: 19617
52, suspended: false, bw_adapted: false} {ssrc: 3165156980, width: 1280, height: 720, key: 9, delta: 489, total_bps: 2013760, retransmit_bps: 0, avg_delay_ms: -1633143627, max_delay_ms: 0, c
um_loss: 0, max_ext_seq: 9633, nack: 0, fir: 7, pli: 7}                          
[028:091] [22853] (webrtcvideoengine.cc:2588): VideoReceiveStream stats: 11251778786, {ssrc: 2016621461, total_bps: 0, width: 0, height: 0, key: 0, delta: 0, network_fps: 0, decode_fps: 0, r
ender_fps: 0, decode_ms: 0, max_decode_ms: 0, cur_delay_ms: 0, targ_delay_ms: 0, jb_delay_ms: 0, min_playout_delay_ms: 0, discarded: 0, sync_offset_ms: 2147483647, cum_loss: 0, max_ext_seq:
0, nack: 0, fir: 0, pli: 0} 

The main part of the client app is as follows:

   // Starting a broadcast
    caff_InstanceHandle instance = caff_createInstance();
    caff_Result result;
    if(nullIfEmpty(config.token) != nullptr) {
       result = caff_refreshAuth(instance, config.token.c_str());
    } else {
       result = caff_signIn(instance, config.username.c_str(), config.password.c_str(), nullIfEmpty(config.otp));
    }
    if (result != caff_ResultSuccess) {
       std::cerr << "sign-in failed: " << caff_resultString(result) << std::endl;
       return (int) result;
    }

    std::cerr << "after sign in" << std::endl;

    std::string refresh_token = caff_getRefreshToken(instance);
    std::cout << refresh_token << std::endl; 

    if(config.login_only) {
       return 0;
    }

    result = caff_startBroadcast(instance, NULL, config.title.c_str(), config.rating, nullIfEmpty(config.game_id), started, failed);

    std::cerr << "after start broadcast" << std::endl;

    ready.wait();

    std::cerr << "after wait for started. starting threads" << std::endl;

    signal(SIGINT, &stop_handler);
    signal(SIGTERM, &stop_handler);

    int start = time(nullptr);

    std::thread video([&] {
    std::vector<uint8_t> video_buffer(config.video_frame_size);
        std::ifstream video_input;
        video_input.open(config.video_pipe, std::ios::binary);
        size_t frame = 1;

        std::cerr << time(nullptr) - start << "before audio open" << std::endl;

        while (dowork && video_input.read((char*)&video_buffer[0], config.video_frame_size))  {
            size_t timestamp = frame * config.fps_den * 1000000 / config.fps_num;
            //std::cerr << time(nullptr) - start << "send video" << std::endl;
            caff_sendVideo(instance, config.video_format, &video_buffer[0], config.video_frame_size, config.width, config.height, timestamp);

            frame++;
        }
        video_input.close();
    });

    std::thread audio([&] {
        std::vector<uint8_t> audio_buffer(config.audio_frame_size);
        std::ifstream audio_input;
        audio_input.open(config.audio_pipe, std::ios::binary);
        std::cerr << "after audio open" << std::endl;
        while (dowork && audio_input.read((char*)&audio_buffer[0], config.audio_frame_size)) {
            //std::cerr << time(nullptr) - start << "send audio" << std::endl;
            caff_sendAudio(instance, &audio_buffer[0], config.audio_samples_in_frame);
        }
        audio_input.close();
    });

    std::cerr << "before threads join" << std::endl;

    video.join();
    audio.join();

    std::cerr << "after threads join" << std::endl;

    caff_endBroadcast(instance);
    caff_freeInstance(&instance);

    std::cerr << "finished" << std::endl;
    return 0;
}

And the streaming log, which seems fine:

./caffeine_client test
[000:000] [8220] (Caffeine.cpp:127): Libcaffeine initialized
[000:001] [8220] (audio_processing_impl.cc:428): Capture post processor activated: 0
Render pre processor activated: 0
[000:001] [8220] (webrtcvoiceengine.cc:211): WebRtcVoiceEngine::WebRtcVoiceEngine
[000:001] [8220] (webrtcvideoengine.cc:553): WebRtcVideoEngine::WebRtcVideoEngine()
[000:001] [8223] (webrtcvoiceengine.cc:234): WebRtcVoiceEngine::Init
[000:002] [8223] (webrtcvoiceengine.cc:241): Supported send codecs in order of preference:
[000:002] [8223] (webrtcvoiceengine.cc:244): opus/48000/2 { minptime=10 useinbandfec=1 } (111)
[000:002] [8223] (webrtcvoiceengine.cc:244): ISAC/16000/1 (103)
[000:002] [8223] (webrtcvoiceengine.cc:244): ISAC/32000/1 (104)
[000:002] [8223] (webrtcvoiceengine.cc:244): G722/8000/1 (9)
[000:002] [8223] (webrtcvoiceengine.cc:244): ILBC/8000/1 (102)
[000:002] [8223] (webrtcvoiceengine.cc:244): PCMU/8000/1 (0)
[000:002] [8223] (webrtcvoiceengine.cc:244): PCMA/8000/1 (8)
[000:002] [8223] (webrtcvoiceengine.cc:244): CN/32000/1 (106)
[000:002] [8223] (webrtcvoiceengine.cc:244): CN/16000/1 (105)
[000:002] [8223] (webrtcvoiceengine.cc:244): CN/8000/1 (13)
[000:002] [8223] (webrtcvoiceengine.cc:244): telephone-event/48000/1 (110)
[000:002] [8223] (webrtcvoiceengine.cc:244): telephone-event/32000/1 (112)
[000:002] [8223] (webrtcvoiceengine.cc:244): telephone-event/16000/1 (113)
[000:002] [8223] (webrtcvoiceengine.cc:244): telephone-event/8000/1 (126)
[000:002] [8223] (webrtcvoiceengine.cc:247): Supported recv codecs in order of preference:
[000:002] [8223] (webrtcvoiceengine.cc:250): opus/48000/2 { minptime=10 useinbandfec=1 } (111)
[000:002] [8223] (webrtcvoiceengine.cc:250): ISAC/16000/1 (103)
[000:008] [8223] (webrtcvoiceengine.cc:250): ISAC/32000/1 (104)
[000:008] [8223] (webrtcvoiceengine.cc:250): G722/8000/1 (9)
[000:008] [8223] (webrtcvoiceengine.cc:250): ILBC/8000/1 (102)
[000:008] [8223] (webrtcvoiceengine.cc:250): PCMU/8000/1 (0)
[000:008] [8223] (webrtcvoiceengine.cc:250): PCMA/8000/1 (8)
[000:008] [8223] (webrtcvoiceengine.cc:250): CN/32000/1 (106)
[000:008] [8223] (webrtcvoiceengine.cc:250): CN/16000/1 (105)
[000:008] [8223] (webrtcvoiceengine.cc:250): CN/8000/1 (13)
[000:008] [8223] (webrtcvoiceengine.cc:250): telephone-event/48000/1 (110)
[000:011] [8223] (webrtcvoiceengine.cc:250): telephone-event/32000/1 (112)
[000:011] [8223] (webrtcvoiceengine.cc:250): telephone-event/16000/1 (113)
[000:011] [8223] (webrtcvoiceengine.cc:250): telephone-event/8000/1 (126)
[000:011] [8223] (adm_helpers.cc:43): Unable to set playout device.
[000:011] [8223] (webrtcvoiceengine.cc:324): WebRtcVoiceEngine::ApplyOptions: AudioOptions {aec: true, agc: true, ns: true, hf: true, swap: false, audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, typing: true, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: true, }
[000:011] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 0
[000:011] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[000:011] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[000:011] [8223] (apm_helpers.cc:114): Echo control set to 1 with mode 0
[000:011] [8223] (apm_helpers.cc:124): EC metrics set to 1
[000:011] [8223] (apm_helpers.cc:81): AGC set to 1 with mode 0
[000:011] [8223] (apm_helpers.cc:149): NS set to 1
[000:011] [8223] (webrtcvoiceengine.cc:507): Stereo swapping enabled? 0
[000:011] [8223] (webrtcvoiceengine.cc:512): NetEq capacity is 50
[000:011] [8223] (webrtcvoiceengine.cc:518): NetEq fast mode? 0
[000:011] [8223] (webrtcvoiceengine.cc:525): Typing detection is enabled? 1
[000:011] [8223] (apm_helpers.cc:163): VAD set to 1 for typing detection.
[000:011] [8223] (webrtcvoiceengine.cc:536): Delay agnostic aec is enabled? 0
[000:011] [8223] (webrtcvoiceengine.cc:546): Extended filter aec is enabled? 0
[000:011] [8223] (webrtcvoiceengine.cc:556): Experimental ns is enabled? 0
[000:011] [8223] (webrtcvoiceengine.cc:562): Intelligibility Enhancer is enabled? 0
[000:011] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 1
[000:011] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[000:011] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[001:632] [8220] (Serialization.cpp:32): Skipping empty process name
[001:633] [8220] (Serialization.cpp:32): Skipping empty process name
[001:633] [8220] (Serialization.cpp:32): Skipping empty process name
[001:634] [8220] (Serialization.cpp:32): Skipping empty process name
[001:634] [8220] (Serialization.cpp:32): Skipping empty process name
[001:635] [8220] (Serialization.cpp:32): Skipping empty process name
[001:635] [8220] (Serialization.cpp:32): Skipping empty process name
[001:635] [8220] (Serialization.cpp:32): Skipping empty process name
[001:649] [8220] (Api.cpp:169): Request complete
[002:271] [8220] (Api.cpp:361): Http response [200]
[002:272] [8220] (Api.cpp:385): Credentials refresh complete
[002:278] [8220] (Api.cpp:169): Request complete
[002:869] [8220] (Api.cpp:456): Got user details
[002:876] [8220] (Api.cpp:169): Request complete
after sign in
dedd9b8a2ec4b8c7f16efbda063da25a073c23708bf26c5a4ebce578ffb0eb2b.CAID4D74313A040546A6A26A66C9F0D5BD96
[003:456] [8220] (Api.cpp:169): Request complete
after start broadcast
[003:457] [8223] (peerconnectionfactory.cc:479): Using default network controller factory
[003:457] [8223] (alr_experiment.cc:65): Using ALR experiment settings: pacing factor: 1, max pacer queue length: 2875, ALR start bandwidth usage percent: 80, ALR end budget level percent: 40, ALR end budget level percent: -60, ALR experiment group ID: 3
[003:457] [8223] (bitrate_prober.cc:64): Bandwidth probing enabled, set to inactive
[003:457] [8223] (rtp_transport_controller_send.cc:48): Using Legacy SSCC
[003:457] [8223] (aimd_rate_control.cc:108): Using aimd rate control with back off factor 0.85
[003:457] [8223] (delay_based_bwe.cc:103): Using Trendline filter for delay change estimation with window size 20
[003:457] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[003:457] [8223] (delay_based_bwe.cc:311): BWE Setting start bitrate to: 300000
[003:457] [8223] (paced_sender.cc:362): ProcessThreadAttached 0x0x7f5bb0030b50
[003:457] [8223] (cpu_info.cc:46): Available number of cores: 2
[003:457] [8223] (aimd_rate_control.cc:108): Using aimd rate control with back off factor 0.85
[003:457] [8223] (remote_bitrate_estimator_single_stream.cc:55): RemoteBitrateEstimatorSingleStream: Instantiating.
[003:458] [8222] (opensslidentity.cc:45): Making key pair
[003:458] [8222] (opensslidentity.cc:93): Returning key pair
[003:458] [8222] (opensslcertificate.cc:58): Making certificate for WebRTC
[003:459] [8222] (opensslcertificate.cc:105): Returning certificate
[003:459] [8223] (delay_based_bwe.cc:311): BWE Setting start bitrate to: 2000000
[003:460] [8222] (p2ptransportchannel.cc:456): Set backup connection ping interval to 25000 milliseconds.
[003:460] [8222] (p2ptransportchannel.cc:465): Set ICE receiving timeout to 2500 milliseconds
[003:460] [8222] (p2ptransportchannel.cc:472): Set ping most likely connection to 0
[003:460] [8222] (p2ptransportchannel.cc:479): Set stable_writable_connection_ping_interval to 2500
[003:460] [8222] (p2ptransportchannel.cc:492): Set presume writable when fully relayed to 0
[003:460] [8222] (p2ptransportchannel.cc:501): Set regather_on_failed_networks_interval to 300000
[003:460] [8222] (p2ptransportchannel.cc:520): Set receiving_switching_delay to 1000
[003:460] [8222] (dtlssrtptransport.cc:60): Setting RTCP Transport on audio transport 0
[003:460] [8222] (dtlssrtptransport.cc:65): Setting RTP Transport on audio transport 0x7f5bac003590
[003:460] [8222] (p2ptransportchannel.cc:456): Set backup connection ping interval to 25000 milliseconds.
[003:460] [8222] (p2ptransportchannel.cc:465): Set ICE receiving timeout to 2500 milliseconds
[003:460] [8222] (p2ptransportchannel.cc:472): Set ping most likely connection to 0
[003:460] [8222] (p2ptransportchannel.cc:479): Set stable_writable_connection_ping_interval to 2500
[003:460] [8222] (p2ptransportchannel.cc:492): Set presume writable when fully relayed to 0
[003:460] [8222] (p2ptransportchannel.cc:501): Set regather_on_failed_networks_interval to 300000
[003:460] [8222] (p2ptransportchannel.cc:520): Set receiving_switching_delay to 1000
[003:460] [8222] (dtlssrtptransport.cc:60): Setting RTCP Transport on video transport 0
[003:460] [8222] (dtlssrtptransport.cc:65): Setting RTP Transport on video transport 0x7f5bac0051c0
[003:460] [8222] (p2ptransportchannel.cc:393): Set ICE ufrag: 9JaF pwd: 4jw8zp0oJ1WiQvkbxmL+Xc8s on transport audio
[003:460] [8222] (p2ptransportchannel.cc:393): Set ICE ufrag: 9JaF pwd: 4jw8zp0oJ1WiQvkbxmL+Xc8s on transport video
[003:460] [8223] (webrtcvoiceengine.cc:1501): Setting voice channel options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, }
[003:460] [8223] (webrtcvoiceengine.cc:324): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, }
[003:460] [8223] (webrtcvoiceengine.cc:512): NetEq capacity is 50
[003:460] [8223] (webrtcvoiceengine.cc:518): NetEq fast mode? 0
[003:460] [8223] (webrtcvoiceengine.cc:536): Delay agnostic aec is enabled? 0
[003:460] [8223] (webrtcvoiceengine.cc:546): Extended filter aec is enabled? 0
[003:460] [8223] (webrtcvoiceengine.cc:556): Experimental ns is enabled? 0
[003:460] [8223] (webrtcvoiceengine.cc:562): Intelligibility Enhancer is enabled? 0
[003:460] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 1
[003:460] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[003:460] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[003:460] [8223] (webrtcvoiceengine.cc:1519): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, }
[003:461] [8223] (channel.cc:113): Created channel for audio
[003:461] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[003:461] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[003:461] [8223] (webrtcvideoengine.cc:564): CreateChannel. Options: VideoOptions {}
[003:461] [8223] (channel.cc:113): Created channel for video
[003:461] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[003:461] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[003:461] [8224] (peerconnection.cc:3503): Session: 7003261807692848151 Old state: kStable New state: kHaveLocalOffer
[003:461] [8223] (channel.cc:786): Setting local voice description
[003:461] [8223] (webrtcvoiceengine.cc:1360): WebRtcVoiceMediaChannel::SetRecvParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[103:ISAC:16000:0:1], AudioCodec[104:ISAC:32000:0:1], AudioCodec[9:G722:8000:0:1], AudioCodec[102:ILBC:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1], AudioCodec[106:CN:32000:0:1], AudioCodec[105:CN:16000:0:1], AudioCodec[13:CN:8000:0:1], AudioCodec[110:telephone-event:48000:0:1], AudioCodec[112:telephone-event:32000:0:1], AudioCodec[113:telephone-event:16000:0:1], AudioCodec[126:telephone-event:8000:0:1]], extensions: [{uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}]}
[003:461] [8223] (webrtcvoiceengine.cc:1529): Setting receive voice codecs.
[003:462] [8223] (webrtcvoiceengine.cc:1800): AddSendStream: {id:external_audio;ssrcs:[1883864136];ssrc_groups:;cname:a3uJUrDMv8jZFmHk;stream_ids:caffeine_stream;}
[003:462] [8223] (neteq_impl.cc:114): NetEq config: sample_rate_hz=16000, enable_post_decode_vad=true, max_packets_in_buffer=0, enable_fast_accelerate=false, enable_muted_state= true
[003:462] [8223] (audio_coding_module.cc:451): Created
[003:462] [8223] (audio_send_stream.cc:137): AudioSendStream: 1883864136
[003:462] [8223] (audio_send_stream.cc:199): AudioSendStream::ConfigureStream: {rtp: {ssrc: 1883864136, extensions: [], nack: {rtp_history_ms: 0}, c_name: a3uJUrDMv8jZFmHk}, send_transport: (Transport), min_bitrate_bps: -1, max_bitrate_bps: -1, send_codec_spec: <unset>}
[003:462] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[003:462] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[003:462] [8223] (channel.cc:609): Add send stream ssrc: 1883864136
[003:462] [8223] (channel.cc:778): Changing voice state, recv=0 send=0
[003:462] [8223] (channel.cc:921): Setting local video description
[003:462] [8223] (webrtcvideoengine.cc:990): SetRecvParameters: {codecs: [VideoCodec[96:H264], VideoCodec[97:rtx], VideoCodec[98:red], VideoCodec[99:rtx], VideoCodec[100:ulpfec]], extensions: [{uri: urn:ietf:params:rtp-hdrext:toffset, id: 2}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time, id: 3}, {uri: urn:3gpp:video-orientation, id: 4}, {uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/playout-delay, id: 6}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-content-type, id: 7}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-timing, id: 8}]}
[003:462] [8223] (webrtcvideoengine.cc:1109): AddSendStream: {id:external_video;ssrcs:[3662861842,2905646547];ssrc_groups:{semantics:FID;ssrcs:[3662861842,2905646547]};cname:a3uJUrDMv8jZFmHk;stream_ids:caffeine_stream;}
[003:462] [8223] (webrtcvideoengine.cc:1140): SetLocalSsrc on all the receive streams because we added a send stream.
[003:462] [8223] (channel.cc:609): Add send stream ssrc: 3662861842
[003:462] [8223] (channel.cc:908): Changing video state, send=0
[003:463] [8224] (peerconnection.cc:4754): Local and Remote descriptions must be applied to get the SSL Role of the SCTP transport.
[003:463] [8223] (webrtcvoiceengine.cc:1501): Setting voice channel options: AudioOptions {aec: false, ns: false, hf: false, swap: false, typing: false, comfort_noise: false, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: false, tx_agc_limiter: false, }
[003:463] [8223] (webrtcvoiceengine.cc:324): WebRtcVoiceEngine::ApplyOptions: AudioOptions {aec: false, ns: false, hf: false, swap: false, audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, typing: false, comfort_noise: false, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: false, tx_agc_limiter: false, }
[003:463] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 1
[003:463] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[003:463] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[003:463] [8223] (apm_helpers.cc:114): Echo control set to 0 with mode 0
[003:463] [8223] (apm_helpers.cc:124): EC metrics set to 0
[003:463] [8223] (apm_helpers.cc:149): NS set to 0
[003:463] [8223] (webrtcvoiceengine.cc:507): Stereo swapping enabled? 0
[003:463] [8223] (webrtcvoiceengine.cc:512): NetEq capacity is 50
[003:463] [8223] (webrtcvoiceengine.cc:518): NetEq fast mode? 0
[003:463] [8223] (webrtcvoiceengine.cc:525): Typing detection is enabled? 0
[003:463] [8223] (apm_helpers.cc:163): VAD set to 0 for typing detection.
[003:463] [8223] (webrtcvoiceengine.cc:536): Delay agnostic aec is enabled? 0
[003:463] [8223] (webrtcvoiceengine.cc:546): Extended filter aec is enabled? 0
[003:463] [8223] (webrtcvoiceengine.cc:556): Experimental ns is enabled? 0
[003:463] [8223] (webrtcvoiceengine.cc:562): Intelligibility Enhancer is enabled? 0
[003:463] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 0
[003:463] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[003:463] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[003:463] [8223] (webrtcvoiceengine.cc:1519): Set voice channel options. Current options: AudioOptions {aec: false, ns: false, hf: false, swap: false, audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, typing: false, comfort_noise: false, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: false, tx_agc_limiter: false, }
[003:463] [8223] (webrtcvideoengine.cc:1068): SetVideoSend (ssrc= 3662861842, options: VideoOptions {is_screencast : false, }, source = (source))
[003:463] [8222] (basicportallocator.cc:336): Start getting ports with prune_turn_ports disabled
[003:463] [8222] (basicportallocator.cc:336): Start getting ports with prune_turn_ports disabled
[003:463] [8222] (basicportallocator.cc:107): Filtered out ignored networks:
[003:463] [8222] (basicportallocator.cc:109): Net[lo:0:0:0:x:x:x:x:x/128:Loopback:id=3]
[003:463] [8222] (basicportallocator.cc:109): Net[lo:127.0.0.x/8:Loopback:id=2]
[003:463] [8222] (basicportallocator.cc:825): Network manager has started
[003:463] [8222] (basicportallocator.cc:107): Filtered out ignored networks:
[003:464] [8222] (basicportallocator.cc:109): Net[lo:0:0:0:x:x:x:x:x/128:Loopback:id=3]
[003:464] [8222] (basicportallocator.cc:109): Net[lo:127.0.0.x/8:Loopback:id=2]
[003:464] [8222] (basicportallocator.cc:825): Network manager has started
[003:464] [8222] (basicportallocator.cc:107): Filtered out ignored networks:
[003:464] [8222] (basicportallocator.cc:109): Net[lo:0:0:0:x:x:x:x:x/128:Loopback:id=3]
[003:464] [8222] (basicportallocator.cc:109): Net[lo:127.0.0.x/8:Loopback:id=2]
[003:464] [8222] (basicportallocator.cc:740): Allocate ports on 1 networks
[003:464] [8222] (basicportallocator.cc:107): Filtered out ignored networks:
[003:464] [8222] (basicportallocator.cc:109): Net[lo:0:0:0:x:x:x:x:x/128:Loopback:id=3]
[003:464] [8222] (basicportallocator.cc:109): Net[lo:127.0.0.x/8:Loopback:id=2]
[003:464] [8222] (basicportallocator.cc:740): Allocate ports on 1 networks
[003:464] [8224] (PeerConnectionObserver.cpp:64): ICE gathering: gathering
[003:464] [8222] (basicportallocator.cc:1276): Net[eth0:172.17.32.x/20:Ethernet:id=1]: Allocation Phase=Udp
[003:464] [8222] (port.cc:319): Port[0x7f5bac029d00::1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port created with network cost 0
[003:464] [8222] (basicportallocator.cc:847): Adding allocated port for audio
[003:464] [8222] (basicportallocator.cc:866): Port[0x7f5bac029d00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Added port to allocator
[003:464] [8222] (basicportallocator.cc:883): Port[0x7f5bac029d00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Gathered candidate: Cand[:4008702294:1:udp:2122260223:172.17.41.x:39323:local::0:9JaF:4jw8zp0oJ1WiQvkbxmL+Xc8s:1:0:0]
[003:464] [8222] (basicportallocator.cc:911): Port[0x7f5bac029d00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port ready.
[003:464] [8222] (physicalsocketserver.cc:562): Socket::OPT_DSCP not supported.
[003:464] [8222] (p2ptransportchannel.cc:739): Port[0x7f5bac029d00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: SetOption(5, 0) failed: 0
[003:464] [8222] (basicportallocator.cc:985): Port[0x7f5bac029d00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port completed gathering candidates.
[003:464] [8222] (basicportallocator.cc:1276): Net[eth0:172.17.32.x/20:Ethernet:id=1]: Allocation Phase=Udp
[003:464] [8222] (port.cc:319): Port[0x7f5bac02b960::1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port created with network cost 0
[003:464] [8222] (basicportallocator.cc:847): Adding allocated port for video
[003:464] [8222] (basicportallocator.cc:866): Port[0x7f5bac02b960:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Added port to allocator
[003:464] [8222] (basicportallocator.cc:883): Port[0x7f5bac02b960:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Gathered candidate: Cand[:4008702294:1:udp:2122260223:172.17.41.x:42272:local::0:9JaF:4jw8zp0oJ1WiQvkbxmL+Xc8s:1:0:0]
[003:464] [8222] (basicportallocator.cc:911): Port[0x7f5bac02b960:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port ready.
[003:464] [8222] (physicalsocketserver.cc:562): Socket::OPT_DSCP not supported.
[003:464] [8222] (p2ptransportchannel.cc:739): Port[0x7f5bac02b960:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: SetOption(5, 0) failed: 0
[003:464] [8222] (basicportallocator.cc:985): Port[0x7f5bac02b960:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port completed gathering candidates.
[003:465] [8224] (PeerConnectionObserver.cpp:87): ICE candidate added
[003:465] [8224] (PeerConnectionObserver.cpp:87): ICE candidate added
[003:482] [8238] (paced_sender.cc:104): PacedSender paused.
[003:514] [8222] (basicportallocator.cc:1276): Net[eth0:172.17.32.x/20:Ethernet:id=1]: Allocation Phase=Relay
[003:514] [8222] (basicportallocator.cc:1276): Net[eth0:172.17.32.x/20:Ethernet:id=1]: Allocation Phase=Relay
[003:564] [8222] (basicportallocator.cc:1276): Net[eth0:172.17.32.x/20:Ethernet:id=1]: Allocation Phase=Tcp
[003:564] [8222] (port.cc:319): Port[0x7f5bac02cd00::1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port created with network cost 0
[003:564] [8222] (basicportallocator.cc:847): Adding allocated port for audio
[003:564] [8222] (basicportallocator.cc:866): Port[0x7f5bac02cd00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Added port to allocator
[003:564] [8222] (basicportallocator.cc:883): Port[0x7f5bac02cd00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Gathered candidate: Cand[:2691435942:1:tcp:1518280447:172.17.41.x:50535:local::0:9JaF:4jw8zp0oJ1WiQvkbxmL+Xc8s:1:0:0]
[003:564] [8222] (basicportallocator.cc:911): Port[0x7f5bac02cd00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port ready.
[003:564] [8222] (physicalsocketserver.cc:562): Socket::OPT_DSCP not supported.
[003:564] [8222] (p2ptransportchannel.cc:739): Port[0x7f5bac02cd00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: SetOption(5, 0) failed: 0
[003:564] [8222] (basicportallocator.cc:985): Port[0x7f5bac02cd00:audio:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port completed gathering candidates.
[003:564] [8222] (basicportallocator.cc:1081): All candidates gathered for audio:1:0
[003:564] [8222] (p2ptransportchannel.cc:794): P2PTransportChannel: audio, component 1 gathering complete
[003:564] [8222] (basicportallocator.cc:1276): Net[eth0:172.17.32.x/20:Ethernet:id=1]: Allocation Phase=Tcp
[003:564] [8222] (port.cc:319): Port[0x7f5bac02e250::1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port created with network cost 0
[003:564] [8222] (basicportallocator.cc:847): Adding allocated port for video
[003:564] [8222] (basicportallocator.cc:866): Port[0x7f5bac02e250:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Added port to allocator
[003:564] [8224] (PeerConnectionObserver.cpp:87): ICE candidate added
[003:565] [8222] (basicportallocator.cc:883): Port[0x7f5bac02e250:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Gathered candidate: Cand[:2691435942:1:tcp:1518280447:172.17.41.x:44737:local::0:9JaF:4jw8zp0oJ1WiQvkbxmL+Xc8s:1:0:0]
[003:565] [8222] (basicportallocator.cc:911): Port[0x7f5bac02e250:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port ready.
[003:565] [8222] (physicalsocketserver.cc:562): Socket::OPT_DSCP not supported.
[003:565] [8222] (p2ptransportchannel.cc:739): Port[0x7f5bac02e250:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: SetOption(5, 0) failed: 0
[003:565] [8222] (basicportallocator.cc:985): Port[0x7f5bac02e250:video:1:0:local:Net[eth0:172.17.32.x/20:Ethernet:id=1]]: Port completed gathering candidates.
[003:565] [8222] (basicportallocator.cc:1081): All candidates gathered for video:1:0
[003:565] [8222] (p2ptransportchannel.cc:794): P2PTransportChannel: video, component 1 gathering complete
[003:565] [8224] (PeerConnectionObserver.cpp:87): ICE candidate added
[003:565] [8224] (PeerConnectionObserver.cpp:67): ICE gathering: complete
[004:134] [8235] (Api.cpp:708): Http response [200]
[004:141] [8235] (Api.cpp:169): Request complete
[005:334] [8235] (Api.cpp:708): Http response [200]
[005:342] [8235] (Api.cpp:169): Request complete
[005:978] [8235] (Api.cpp:531): ICE candidates trickled
[005:987] [8235] (Api.cpp:169): Request complete
[005:988] [8223] (webrtcvideoengine.cc:1381): Call stats: 11167636717, {send_bw_bps: 0, recv_bw_bps: 0, max_pad_bps: 0, pacer_delay_ms: 0, rtt_ms: -1}
[005:988] [8222] (dtlssrtptransport.cc:60): Setting RTCP Transport on audio transport 0
[005:988] [8222] (dtlssrtptransport.cc:65): Setting RTP Transport on audio transport 0x7f5bac003590
[005:988] [8222] (p2ptransportchannel.cc:404): Received remote ICE parameters: ufrag=qn15, renomination disabled
[005:988] [8222] (dtlstransport.cc:376): DtlsTransport[audio|1|__]: DTLS setup complete.
[005:989] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[005:989] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[005:989] [8223] (channel.cc:529): Channel enabled
[005:989] [8223] (channel.cc:778): Changing voice state, recv=1 send=0
[005:989] [8223] (channel.cc:529): Channel enabled
[005:989] [8223] (channel.cc:908): Changing video state, send=0
[005:989] [8224] (peerconnection.cc:3503): Session: 7003261807692848151 Old state: kHaveLocalOffer New state: kStable
[005:989] [8223] (channel.cc:837): Setting remote voice description
[005:989] [8223] (webrtcvoiceengine.cc:1323): WebRtcVoiceMediaChannel::SetSendParameters: {codecs: [AudioCodec[111:opus:48000:0:2]], extensions: [{uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], max_bandwidth_bps: -1, mid: audio, options: AudioOptions {}}
[005:989] [8223] (audio_send_stream.cc:199): AudioSendStream::ConfigureStream: {rtp: {ssrc: 1883864136, extensions: [], nack: {rtp_history_ms: 0}, c_name: a3uJUrDMv8jZFmHk}, send_transport: (Transport), min_bitrate_bps: -1, max_bitrate_bps: -1, send_codec_spec: {nack_enabled: false, transport_cc_enabled: false, cng_payload_type: <unset>, payload_type: 111, format: {name: opus, clockrate_hz: 48000, num_channels: 2, parameters: {}}}}
[005:989] [8223] (audio_send_stream.cc:199): AudioSendStream::ConfigureStream: {rtp: {ssrc: 1883864136, extensions: [{uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], nack: {rtp_history_ms: 0}, c_name: a3uJUrDMv8jZFmHk}, send_transport: (Transport), min_bitrate_bps: -1, max_bitrate_bps: -1, send_codec_spec: {nack_enabled: false, transport_cc_enabled: false, cng_payload_type: <unset>, payload_type: 111, format: {name: opus, clockrate_hz: 48000, num_channels: 2, parameters: {}}}}
[005:989] [8223] (audio_send_stream.cc:199): AudioSendStream::ConfigureStream: {rtp: {ssrc: 1883864136, extensions: [{uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], nack: {rtp_history_ms: 0}, c_name: a3uJUrDMv8jZFmHk}, send_transport: (Transport), min_bitrate_bps: -1, max_bitrate_bps: -1, send_codec_spec: {nack_enabled: false, transport_cc_enabled: false, cng_payload_type: <unset>, payload_type: 111, format: {name: opus, clockrate_hz: 48000, num_channels: 2, parameters: {}}}}
[005:989] [8223] (webrtcvoiceengine.cc:2114): WebRtcVoiceMediaChannel::SetMaxSendBitrate.
[005:989] [8223] (webrtcvoiceengine.cc:1501): Setting voice channel options: AudioOptions {}
[005:989] [8223] (webrtcvoiceengine.cc:324): WebRtcVoiceEngine::ApplyOptions: AudioOptions {aec: false, ns: false, hf: false, swap: false, audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, typing: false, comfort_noise: false, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: false, tx_agc_limiter: false, }
[005:989] [8223] (apm_helpers.cc:114): Echo control set to 0 with mode 0
[005:989] [8223] (apm_helpers.cc:124): EC metrics set to 0
[005:989] [8223] (apm_helpers.cc:149): NS set to 0
[005:989] [8223] (webrtcvoiceengine.cc:507): Stereo swapping enabled? 0
[005:989] [8223] (webrtcvoiceengine.cc:512): NetEq capacity is 50
[005:989] [8223] (webrtcvoiceengine.cc:518): NetEq fast mode? 0
[005:989] [8223] (webrtcvoiceengine.cc:525): Typing detection is enabled? 0
[005:989] [8223] (apm_helpers.cc:163): VAD set to 0 for typing detection.
[005:989] [8223] (webrtcvoiceengine.cc:536): Delay agnostic aec is enabled? 0
[005:989] [8223] (webrtcvoiceengine.cc:546): Extended filter aec is enabled? 0
[005:989] [8223] (webrtcvoiceengine.cc:556): Experimental ns is enabled? 0
[005:989] [8223] (webrtcvoiceengine.cc:562): Intelligibility Enhancer is enabled? 0
[005:989] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 0
[005:989] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[005:989] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[005:989] [8223] (webrtcvoiceengine.cc:1519): Set voice channel options. Current options: AudioOptions {aec: false, ns: false, hf: false, swap: false, audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, typing: false, comfort_noise: false, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: false, tx_agc_limiter: false, }
[005:989] [8223] (webrtcvoiceengine.cc:1863): AddRecvStream: {id:janusa0;ssrcs:[2764908381];ssrc_groups:;cname:janus;stream_ids:janus;}
[005:989] [8223] (neteq_impl.cc:114): NetEq config: sample_rate_hz=16000, enable_post_decode_vad=true, max_packets_in_buffer=50, enable_fast_accelerate=false, enable_muted_state= true
[005:989] [8223] (audio_coding_module.cc:451): Created
[005:989] [8223] (audio_receive_stream.cc:106): AudioReceiveStream: 2764908381
[005:989] [8223] (audio_receive_stream.cc:327): AudioReceiveStream::ConfigureStream: {rtp: {remote_ssrc: 2764908381, local_ssrc: 1883864136, transport_cc: off, nack: {rtp_history_ms: 0}, extensions: [{uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}]}, rtcp_send_transport: (Transport), sync_group: janus}
[005:990] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[005:990] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[005:990] [8223] (channel.cc:655): Add remote ssrc: 2764908381
[005:990] [8223] (channel.cc:778): Changing voice state, recv=1 send=0
[005:990] [8223] (channel.cc:972): Setting remote video description
[005:990] [8223] (webrtcvideoengine.cc:754): SetSendParameters: {codecs: [VideoCodec[96:H264]], conference_mode: no, extensions: [{uri: urn:3gpp:video-orientation, id: 4}, {uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/playout-delay, id: 6}], max_bandwidth_bps: -1, mid: video}
[005:990] [8223] (webrtcvideoengine.cc:763): Using codec: VideoCodec[96:H264]
[005:990] [8223] (webrtcvideoengine.cc:1746): RTX SSRCs configured but there's no configured RTX payload type. Ignoring.
[005:990] [8223] (webrtcvideoengine.cc:1762): RecreateWebRtcStream (send) because of SetCodec.
[005:990] [8223] (alr_experiment.cc:65): Using ALR experiment settings: pacing factor: 1, max pacer queue length: 2875, ALR start bandwidth usage percent: 80, ALR end budget level percent: 40, ALR end budget level percent: -60, ALR experiment group ID: 3
[005:990] [8237] (video_send_stream_impl.cc:268): VideoSendStreamInternal: {encoder_settings: { experiment_cpu_load_estimator: off}}, rtp: {ssrcs: [3662861842], rtcp_mode: RtcpMode::kCompound, max_packet_size: 1200, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/playout-delay, id: 6}, {uri: urn:3gpp:video-orientation, id: 4}], nack: {rtp_history_ms: 1000}, ulpfec: {ulpfec_payload_type: -1, red_payload_type: -1, red_rtx_payload_type: -1}, payload_name: H264, payload_type: 96, flexfec: {payload_type: -1, ssrc: 0, protected_media_ssrcs: []}, rtx: {ssrcs: [], payload_type: -1}, c_name: a3uJUrDMv8jZFmHk}, rtcp: {video_report_interval_ms: 1000, audio_report_interval_ms: 5000}, pre_encode_callback: nullptr, post_encode_callback: nullptr, render_delay_ms: 0, target_delay_ms: 0, suspend_below_min_bitrate: off}
[005:990] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[005:990] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[005:990] [8223] (video_send_stream.cc:150): VideoSendStream::Stop
[005:991] [8223] (webrtcvideoengine.cc:812): SetFeedbackOptions on all the receive streams because the send codec or RTCP mode has changed.
[005:991] [8223] (webrtcvideoengine.cc:1205): AddRecvStream: {id:janusv0;ssrcs:[2273434067];ssrc_groups:;cname:janus;stream_ids:janus;}
[005:991] [8223] (internaldecoderfactory.cc:54): Trying to create decoder for unsupported format
[005:991] [8237] (video_send_stream_impl.cc:425): VideoSendStream::Stop
[005:992] [8223] (video_receive_stream.cc:113): VideoReceiveStream: {decoders: [{decoder: (VideoDecoder), payload_type: 96, payload_name: H264, codec_params: {profile-level-id: 42e01f}}], rtp: {remote_ssrc: 2273434067, local_ssrc: 3662861842, rtcp_mode: RtcpMode::kCompound, rtcp_xr: {receiver_reference_time_report: off}, remb: on, transport_cc: on, nack: {rtp_history_ms: 1000}, ulpfec_payload_type: 100, red_type: 98, rtx_ssrc: 0, rtx_payload_types: {97 (pt) -> 96 (apt), 99 (pt) -> 98 (apt), }, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 5}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time, id: 3}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/playout-delay, id: 6}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-content-type, id: 7}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/video-timing, id: 8}, {uri: urn:3gpp:video-orientation, id: 4}, {uri: urn:ietf:params:rtp-hdrext:toffset, id: 2}]}, renderer: (renderer), render_delay_ms: 10, sync_group: janus, target_delay_ms: 0}
[005:992] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=down
[005:992] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Down
[005:992] [8223] (channel.cc:655): Add remote ssrc: 2273434067
[005:992] [8223] (video_send_stream.cc:150): VideoSendStream::Stop
[005:992] [8237] (video_send_stream_impl.cc:425): VideoSendStream::Stop
[005:992] [8223] (channel.cc:908): Changing video state, send=0
[005:992] [8222] (port.cc:1072): Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:KsvVWMY8:1:0:local:udp:172.17.41.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|C--W|-|0|0|8646913483524161023|-]: Connection created
[005:992] [8222] (p2ptransportchannel.cc:1182): Channel[audio|1|__]: Created connection with origin: 2, total: 1
[005:992] [8222] (p2ptransportchannel.cc:1815): Channel[audio|1|__]: Transport channel state changed from 0 to 2
[005:992] [8222] (jseptransportcontroller.cc:1166): audio Transport 1 state changed. Check if state is complete.
[005:992] [8222] (p2ptransportchannel.cc:1396): Channel[audio|1|__]: Have a pingable connection for the first time; starting to ping.
[005:992] [8224] (peerconnection.cc:3455): Changing IceConnectionState 0 => 1
[005:992] [8224] (PeerConnectionObserver.cpp:37): ICE connection: checking
[005:992] [8222] (port.cc:1697): Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:KsvVWMY8:1:0:local:udp:172.17.41.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|C--W|-|0|0|8646913483524161023|-]: Sent STUN ping, id=4e6a486f5762527849417075, use_candidate=1, nomination=0
[005:993] [8222] (jseptransportcontroller.cc:303): Not adding candidate because the JsepTransport doesn't exist. Ignore it.
[005:993] [8222] (jseptransportcontroller.cc:303): Not adding candidate because the JsepTransport doesn't exist. Ignore it.
[005:993] [8224] (peerconnection.cc:4760): Non-rejected SCTP m= section is needed to get the SSL Role of the SCTP transport.
{"id":"accec99c-cbfb-46a3-7928-32e3725bc04a","stage_id":"4D74313A040546A6A26A66C9F0D5BD96","urls":{"heartbeat":"https://fremont-7-5.rtcdn.caffeine.tv:2154/auth/v1/streams/accec99c-cbfb-46a3-7928-32e3725bc04a/heartbeat","updates":"https://fremont-7-5.rtcdn.caffeine.tv:2154/auth/v1/streams/accec99c-cbfb-46a3-7928-32e3725bc04a"}}ready to stream
after wait for started. starting threads
before threads join
0before audio open
[005:995] [8247] (video_stream_encoder.cc:466): ConfigureEncoder requested.
after audio open
[006:007] [8247] (video_stream_encoder.cc:765): Video frame parameters changed: dimensions=1280x720, texture=0.
[006:008] [8247] (X264Encoder.cpp:130): Using x264 encoder
x264 [warning]: CBR HRD requires constant bitrate
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
x264 [info]: profile Constrained Baseline, level 3.1, 4:2:0, 8-bit
[006:041] [8222] (port.cc:1697): Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:KsvVWMY8:1:0:local:udp:172.17.41.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|C--I|-|0|0|8646913483524161023|-]: Sent STUN ping, id=576a44614d49314b644d3446, use_candidate=1, nomination=0
[006:091] [8222] (port.cc:1697): Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:KsvVWMY8:1:0:local:udp:172.17.41.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|C--I|-|0|0|8646913483524161023|-]: Sent STUN ping, id=4b6573473875756250513066, use_candidate=1, nomination=0
[006:129] [8222] (port.cc:1643): Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:KsvVWMY8:1:0:local:udp:172.17.41.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|C--I|-|0|0|8646913483524161023|-]: Received STUN ping response, id=4e6a486f5762527849417075, code=0, rtt=137, pings_since_last_response=4e6a486f5762527849417075 576a44614d49314b644d3446 4b6573473875756250513066
[006:129] [8222] (port.cc:1841): Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:KsvVWMY8:1:0:local:udp:172.17.41.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|CRWS|-|0|0|8646913483524161023|137]: Updating local candidate type to prflx.
[006:129] [8222] (p2ptransportchannel.cc:272): Switching selected connection due to: candidate pair state changed
[006:129] [8222] (p2ptransportchannel.cc:1773): Channel[audio|1|__]: New selected connection: Conn[0x7f5bac0057d0:audio:Net[eth0:172.17.32.x/20:Ethernet:id=1]:Fz0KZcti:1:0:prflx:udp:34.252.67.x:39323->TzdMjAYd:1:2013266431:local:udp:184.105.144.x:28689|CRWS|S|0|0|7962116750806352894|137]
[006:129] [8222] (dtlstransport.cc:791): DtlsTransport[audio|1|__]: configuring DTLS handshake timeout 274 based on ICE RTT 137
[006:129] [8222] (opensslstreamadapter.cc:766): BeginSSL with peer.
[006:129] [8222] (dtlstransport.cc:704): DtlsTransport[audio|1|__]: DtlsTransport: Started DTLS handshake
[006:129] [8222] (srtptransport.cc:349): The params in SRTP transport are reset.
[006:151] [8251] (Broadcast.cpp:684): Screenshot promise set
[006:416] [8222] (opensslstreamadapter.cc:1087): Accepted peer certificate.
[006:416] [8222] (dtlstransport.cc:636): DtlsTransport[audio|1|__]: DTLS handshake complete.
[006:416] [8222] (jseptransportcontroller.cc:1096):  Transport audio writability changed to 1.
[006:416] [8222] (dtlssrtptransport.cc:218): Extracting keys from transport: audio
[006:416] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=up
[006:417] [8224] (peerconnection.cc:5226): Changing to ICE completed state because all transports are complete.
[006:417] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Up
[006:417] [8223] (bitrate_prober.cc:110): Probe cluster (bitrate:min bytes:min packets): (2000000:3750:5)
[006:417] [8223] (bitrate_prober.cc:110): Probe cluster (bitrate:min bytes:min packets): (2000000:3750:5)
[006:417] [8224] (peerconnection.cc:3455): Changing IceConnectionState 1 => 2
[006:417] [8224] (PeerConnectionObserver.cpp:43): ICE connection: connected
[006:417] [8224] (peerconnection.cc:3455): Changing IceConnectionState 2 => 3
[006:417] [8224] (PeerConnectionObserver.cpp:40): ICE connection: completed
[006:417] [8223] (send_side_congestion_controller.cc:555): Bitrate estimate state changed, BWE: 2000000 bps.
[006:417] [8223] (call.cc:1047): UpdateAggregateNetworkState: aggregate_state=up
[006:417] [8223] (send_side_congestion_controller.cc:308): SignalNetworkState Up
[006:417] [8237] (bitrate_allocator.cc:104): Current BWE 2000000
[006:419] [8222] (srtptransport.cc:294): SRTP activated with negotiated parameters: send cipher_suite 1 recv cipher_suite 1
[006:419] [8222] (channel.cc:559): Channel writable (audio) for the first time
[006:419] [8222] (channel.cc:559): Channel writable (video) for the first time
[006:420] [8223] (webrtcvoiceengine.cc:324): WebRtcVoiceEngine::ApplyOptions: AudioOptions {aec: false, ns: false, hf: false, swap: false, audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: false, typing: false, comfort_noise: false, experimental_agc: false, extended_filter_aec: false, delay_agnostic_aec: false, experimental_ns: false, intelligibility_enhancer: false, residual_echo_detector: false, tx_agc_limiter: false, }
[006:420] [8223] (apm_helpers.cc:114): Echo control set to 0 with mode 0
[006:420] [8223] (apm_helpers.cc:124): EC metrics set to 0
[006:420] [8223] (apm_helpers.cc:149): NS set to 0
[006:420] [8223] (webrtcvoiceengine.cc:507): Stereo swapping enabled? 0
[006:420] [8223] (webrtcvoiceengine.cc:512): NetEq capacity is 50
[006:420] [8223] (webrtcvoiceengine.cc:518): NetEq fast mode? 0
[006:420] [8223] (webrtcvoiceengine.cc:525): Typing detection is enabled? 0
[006:420] [8223] (apm_helpers.cc:163): VAD set to 0 for typing detection.
[006:420] [8223] (webrtcvoiceengine.cc:536): Delay agnostic aec is enabled? 0
[006:420] [8223] (webrtcvoiceengine.cc:546): Extended filter aec is enabled? 0
[006:420] [8223] (webrtcvoiceengine.cc:556): Experimental ns is enabled? 0
[006:420] [8223] (webrtcvoiceengine.cc:562): Intelligibility Enhancer is enabled? 0
[006:420] [8223] (audio_processing_impl.cc:689): Highpass filter activated: 0
[006:420] [8223] (audio_processing_impl.cc:703): Gain Controller 2 activated: 0
[006:420] [8223] (audio_processing_impl.cc:705): Pre-amplifier activated: 0
[006:420] [8223] (channel.cc:778): Changing voice state, recv=1 send=1
[006:420] [8223] (video_send_stream.cc:123): VideoSendStream::UpdateActiveSimulcastLayers
[006:420] [8237] (video_send_stream_impl.cc:379): VideoSendStream::UpdateActiveSimulcastLayers
[006:420] [8237] (bitrate_allocator.cc:220): UpdateAllocationLimits : total_requested_min_bitrate: 30000bps, total_requested_padding_bitrate: 0bps, total_requested_max_bitrate: 2500000bps
[006:420] [8247] (video_stream_encoder.cc:980): Video suspend state changed to: not suspended
[006:420] [8223] (channel.cc:908): Changing video state, send=1
[006:428] [8238] (paced_sender.cc:119): PacedSender resumed.
[006:432] [8247] (rtp_sender_video.cc:405): Sent first RTP packet of the first video frame (pre-pacer)
[006:432] [8247] (rtp_sender_video.cc:409): Sent last RTP packet of the first video frame (pre-pacer)
[006:451] [8237] (rtp_sender_audio.cc:243): First audio RTP packet sent to pacer
[007:397] [8235] (Api.cpp:648): Http response code [200]
[007:412] [8235] (Api.cpp:169): Request complete
[008:214] [8223] (probe_bitrate_estimator.cc:149): Probing successful [cluster id: 0] [send: 24784 bytes / 14 ms = 1770.29 kb/s] [receive: 28104 bytes / 13 ms = 2161.85 kb/s]
[008:214] [8223] (probe_bitrate_estimator.cc:149): Probing successful [cluster id: 0] [send: 34152 bytes / 18 ms = 1897.33 kb/s] [receive: 37472 bytes / 17 ms = 2204.24 kb/s]
[008:214] [8223] (probe_bitrate_estimator.cc:149): Probing successful [cluster id: 1] [send: 28104 bytes / 16 ms = 1756.5 kb/s] [receive: 28104 bytes / 16 ms = 1756.5 kb/s]
[008:214] [8223] (probe_bitrate_estimator.cc:149): Probing successful [cluster id: 1] [send: 37472 bytes / 20 ms = 1873.6 kb/s] [receive: 37472 bytes / 19 ms = 1972.21 kb/s]
jpietek commented 4 years ago

Moreover even when the Linux stream is working fine, there are stil console errors in the client, which does not happen when streaming with windows/obs plugin.

datadog-rum-us.js:1 Reporting error: Saga exception during channel: Request failed with status 404. Error: Request failed with status 404
    at main.0e84174d49d31b4e33b9.js:1
    at c (libraries.4e62538ab6231263c402.js:1)
    at Generator._invoke (libraries.4e62538ab6231263c402.js:1)
    at Generator.e.<computed> [as next] (libraries.4e62538ab6231263c402.js:1)
    at n (libraries.4e62538ab6231263c402.js:1)
    at a (libraries.4e62538ab6231263c402.js:1) {level: "warning", layer: "saga", action: "channel", actionPayload: {…}, error: Error: Request failed with status 404
    at https://www.caffeine.tv/main.0e84174d49d31b4e33b9.js:1…}

At backend side I've seen 502 errors while reporting RTC stats, turned off stats reporting in StatsObserver class, but it did not help with unstable streaming.