Problem consuming stream on test server - bitrate problem

CaribouFute · March 24, 2025, 6:48pm

Hi everyone,

We try to deploy our solution for multi-user video broadcasting but have problems consuming the video streams on our test server.

On local, everything goes fine (beside Firefox). I can see myself on two different devices while using the ICE server working on another product production server.

On test server this is different. I open the cam stream from the other user. The stream is there but I get this black wheel of death with a video stream that never starts. The video element having this stream never triggers the canplay event either.

I have been able to receive video very few times with the same server and config, which makes it even hard to debug for me (I’m not an expert of devops, WebRTC or mediasoup). Looks like a bitrate problem coming from ICE servers, but I’m really not sure!

Here is the config passed to the worker:

const newWorker = await mediasoup.createWorker({
    logLevel: 'debug',
    logTags: [
        'info',
        'ice',
        'dtls',
        'rtp',
        'srtp',
        'rtcp',
        'rtx',
        'bwe',
        'score',
        'simulcast',
        'svc',
        'sctp',
        'message'
    ],
    rtcMinPort: 40000, //know it is deprecated, but passed it as precaution
    rtcMaxPort: 49999, //know it is deprecated, but passed it as precaution
});

Here is the config passed to transports.

const transport = await this._mediasoupRouter.createWebRtcTransport({
    listenInfos: [
        {
            // protocol: 'tcp', //'udp' does not seem to work in local
            ip: '0.0.0.0',
            announcedAddress: '57.129.7.45', //the server's public IP address
            portRange: {
                min: process.env.MIN_PORT,
                max: process.env.MAX_PORT
            }
        }
    ],
    enableUdp: true,
    enableTcp: true,
    preferUdp: true,
});

I checked the debug logs on the mediasoup server and there were these lines repeating when trying to consume a video stream.

mediasoup:WARN:Channel [pid:236915] RTC::TransportCongestionControlClient::MayEmitAvailableBitrateEvent() | high BWE value decrease detected, notifying the listener [now:30000, before:44321] +4s
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +788ms
  mediasoup:WARN:Channel [pid:236915] webrtc::SendSideBandwidthEstimation::CapBitrateToThresholds() | Estimated available bandwidth 9177 bps is below configured min bitrate 30 kbps +4s
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +691ms
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +5s

The whole log when starting to consume is here

mediasoup:Router createWebRtcTransport() +23s
  mediasoup:Channel request() [method:ROUTER_CREATE_WEBRTCTRANSPORT] +22s
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::WebRtcTransport() | TCP sockets buffer sizes [send:16384, recv:131072] +2ms
  mediasoup:Channel request succeeded [method:ROUTER_CREATE_WEBRTCTRANSPORT, id:11] +2ms
  mediasoup:Transport constructor() +22s
  mediasoup:WebRtcTransport constructor() +22s
  mediasoup:Transport setMaxIncomingBitrate() [bitrate:1500000] +1ms
  mediasoup:Channel request() [method:TRANSPORT_SET_MAX_INCOMING_BITRATE] +3ms
  mediasoup:Channel [pid:236915] RTC::Transport::HandleRequest() | maximum incoming bitrate set to 1500000 +1ms
  mediasoup:Channel request succeeded [method:TRANSPORT_SET_MAX_INCOMING_BITRATE, id:12] +0ms
subscribeReady: publisherPeer id =  d23c7f1b-9d3a-4aac-a269-5160ee0153e0
_createConsumer() [consumerPeer:OPFHOZnqyTdNRuAiAAAE, producerPeer:d23c7f1b-9d3a-4aac-a269-5160ee0153e0, producer:c96675b6-7678-4ac3-8cd5-a7d241bb8fbb]
  mediasoup:Transport consume() +193ms
  mediasoup:Channel request() [method:TRANSPORT_CONSUME] +195ms
_createConsumer() [consumerPeer:OPFHOZnqyTdNRuAiAAAE, producerPeer:d23c7f1b-9d3a-4aac-a269-5160ee0153e0, producer:3378fd80-0218-43aa-9d6b-527866740b50]
  mediasoup:Transport consume() +4ms
  mediasoup:Channel request() [method:TRANSPORT_CONSUME] +4ms
  mediasoup:Channel [pid:236915] RTC::SimpleConsumer::CreateRtpStream() | [ssrc:891157861, payloadType:100] +1ms
  mediasoup:Channel [pid:236915] RTC::SimpleConsumer::CreateRtpStream() | in band FEC enabled +0ms
  mediasoup:Channel request succeeded [method:TRANSPORT_CONSUME, id:13] +1ms
  mediasoup:Consumer constructor() +0ms
new consumer [transport.id:78c98da1-1df7-4e4d-9932-ea39c90ba826, consumer.id:e6525d04-2076-4d45-bc6a-cd9f5b1d2c39]
OPFHOZnqyTdNRuAiAAAE is consuming d23c7f1b-9d3a-4aac-a269-5160ee0153e0's producer:c96675b6-7678-4ac3-8cd5-a7d241bb8fbb
New consumer:  e6525d04-2076-4d45-bc6a-cd9f5b1d2c39
Consumer score:  ConsumerScoreT { score: 10, producerScore: 0, producerScores: [ 0 ] }
  mediasoup:Consumer getStats() +2ms
  mediasoup:Channel request() [method:CONSUMER_GET_STATS] +3ms
  mediasoup:Channel [pid:236915] RTC::SimpleConsumer::CreateRtpStream() | [ssrc:693203470, payloadType:101] +1ms
  mediasoup:Channel [pid:236915] RTC::SimpleConsumer::CreateRtpStream() | FIR supported +0ms
  mediasoup:Channel [pid:236915] RTC::SimpleConsumer::CreateRtpStream() | NACK supported +0ms
  mediasoup:Channel [pid:236915] RTC::SimpleConsumer::CreateRtpStream() | PLI supported +0ms
  mediasoup:Channel request succeeded [method:TRANSPORT_CONSUME, id:14] +1ms
  mediasoup:Channel [pid:236915] RTC::Transport::HandleRequest() | enabling TransportCongestionControlClient with transport-cc +0ms
  mediasoup:Channel request succeeded [method:CONSUMER_GET_STATS, id:15] +0ms
  mediasoup:Consumer constructor() +2ms
new consumer [transport.id:78c98da1-1df7-4e4d-9932-ea39c90ba826, consumer.id:5c50d3f6-0442-4e26-8a07-9723e0f9c96e]
OPFHOZnqyTdNRuAiAAAE is consuming d23c7f1b-9d3a-4aac-a269-5160ee0153e0's producer:3378fd80-0218-43aa-9d6b-527866740b50
New consumer:  5c50d3f6-0442-4e26-8a07-9723e0f9c96e
Consumer score:  ConsumerScoreT { score: 10, producerScore: 0, producerScores: [ 0 ] }
  mediasoup:Consumer getStats() +3ms
  mediasoup:Channel request() [method:CONSUMER_GET_STATS] +3ms
Consumer stats:  [
  {
    timestamp: 692172469,
    ssrc: 891157861,
    rtxSsrc: undefined,
    rid: undefined,
    kind: 'audio',
    mimeType: 'audio/opus',
    packetsLost: 0,
    fractionLost: 0,
    packetsDiscarded: 0,
    packetsRetransmitted: 0,
    packetsRepaired: 0,
    nackCount: 0,
    nackPacketCount: 0,
    pliCount: 0,
    firCount: 0,
    score: 10,
    roundTripTime: 0,
    rtxPacketsDiscarded: undefined,
    type: 'outbound-rtp',
    byteCount: 0,
    packetCount: 0,
    bitrate: 0
  }
]
  mediasoup:Channel request succeeded [method:CONSUMER_GET_STATS, id:16] +3ms
Consumer stats:  [
  {
    timestamp: 692172473,
    ssrc: 693203470,
    rtxSsrc: 693203471,
    rid: undefined,
    kind: 'video',
    mimeType: 'video/VP8',
    packetsLost: 0,
    fractionLost: 0,
    packetsDiscarded: 0,
    packetsRetransmitted: 0,
    packetsRepaired: 0,
    nackCount: 0,
    nackPacketCount: 0,
    pliCount: 0,
    firCount: 0,
    score: 10,
    roundTripTime: 0,
    rtxPacketsDiscarded: undefined,
    type: 'outbound-rtp',
    byteCount: 0,
    packetCount: 0,
    bitrate: 0
  }
]
  mediasoup:WebRtcTransport connect() +378ms
  mediasoup:Channel request() [method:WEBRTCTRANSPORT_CONNECT] +166ms
  mediasoup:Channel request succeeded [method:WEBRTCTRANSPORT_CONNECT, id:17] +1ms
  mediasoup:Channel [pid:236915] RTC::IceServer::HandleTuple() | transition from state 'new' to 'connected' [hasUseCandidate:false, hasNomination:false, nomination:0] +376ms
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::OnIceServerSelectedTuple() | ICE selected tuple +2ms
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::OnIceServerConnected() | ICE connected +0ms
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::MayRunDtlsTransport() | running DTLS transport in local role 'server' +1ms
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::OnDtlsTransportConnecting() | DTLS connecting +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::Run() | running [role:server] +1ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | DTLS handshake start +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'before SSL initialization'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | role: server, waiting:'before SSL initialization'] +1ms
Transport OPFHOZnqyTdNRuAiAAAE iceselectedtuplechange: {
  localIp: '0.0.0.0',
  localAddress: '0.0.0.0',
  localPort: 49051,
  remoteIp: '107.159.211.193',
  remotePort: 49709,
  protocol: 'tcp'
}
Transport OPFHOZnqyTdNRuAiAAAE icestatechange: connected
Transport OPFHOZnqyTdNRuAiAAAE dtlsstatechange: connecting
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'before SSL initialization'] +101ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS read client hello'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write server hello'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write certificate'] +1ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write key exchange'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write certificate request'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write server done'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | role: server, waiting:'SSLv3/TLS write server done'] +0ms
  mediasoup:Channel [pid:236915] RTC::IceServer::HandleTuple() | transition from state 'connected' to 'completed' [hasUseCandidate:true, hasNomination:false, nomination:0] +9ms
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::OnIceServerCompleted() | ICE completed +1ms
Transport OPFHOZnqyTdNRuAiAAAE icestatechange: completed
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write server done'] +191ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS read client certificate'] +2ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS read client key exchange'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS read certificate verify'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS read change cipher spec'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS read finished'] +1ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write change cipher spec'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | [role:server, action:'SSLv3/TLS write finished'] +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::OnSslInfo() | DTLS handshake done +0ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::CheckRemoteFingerprint() | valid remote fingerprint +1ms
  mediasoup:Channel [pid:236915] RTC::DtlsTransport::GetNegotiatedSrtpCryptoSuite() | chosen SRTP crypto suite: SRTP_AEAD_AES_256_GCM +0ms
  mediasoup:Channel [pid:236915] RTC::WebRtcTransport::OnDtlsTransportConnected() | DTLS connected +0ms
Transport OPFHOZnqyTdNRuAiAAAE dtlsstatechange: connected
  mediasoup:Channel [pid:236915] webrtc::BitrateProber::SetEnabled() | Bandwidth probing enabled, set to inactive +1ms
  mediasoup:Channel [pid:236915] webrtc::AlrExperiment::CreateFromFieldTrial() | Using ALR experiment settings: pacing factor: 1.000000, 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, ALR timeout: 3000 +1ms
  mediasoup:Channel [pid:236915] webrtc::AimdRateControl::AimdRateControl() | Using aimd rate control with back off factor: 0.850000  +0ms
  mediasoup:Consumer resume() +1s
  mediasoup:Channel request() [method:CONSUMER_RESUME] +142ms
  mediasoup:Channel request succeeded [method:CONSUMER_RESUME, id:18] +1ms
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +0ms
  mediasoup:WARN:Channel [pid:236915] webrtc::AlrDetector::GetApplicationLimitedRegionStartTime() | large delta_time_ms: 3002, forcing alr state change +2s
  mediasoup:WARN:Channel [pid:236915] RTC::TransportCongestionControlClient::MayEmitAvailableBitrateEvent() | high BWE value decrease detected, notifying the listener [now:76731, before:600000] +5s
  mediasoup:WARN:Channel [pid:236915] webrtc::SendSideBandwidthEstimation::CapBitrateToThresholds() | Estimated available bandwidth 18546 bps is below configured min bitrate 30 kbps +5s
  mediasoup:WARN:Channel [pid:236915] RTC::TransportCongestionControlClient::MayEmitAvailableBitrateEvent() | high BWE value decrease detected, notifying the listener [now:30000, before:82869] +1ms
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +720ms
  mediasoup:WARN:Channel [pid:236915] RTC::TransportCongestionControlClient::MayEmitAvailableBitrateEvent() | high BWE value decrease detected, notifying the listener [now:30000, before:48947] +4s
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +787ms
  mediasoup:WARN:Channel [pid:236915] webrtc::SendSideBandwidthEstimation::CapBitrateToThresholds() | Estimated available bandwidth 9264 bps is below configured min bitrate 30 kbps +4s
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +707ms
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +5s
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +5s
  mediasoup:WARN:Channel [pid:236915] webrtc::SendSideBandwidthEstimation::CapBitrateToThresholds() | Estimated available bandwidth 11806 bps is below configured min bitrate 30 kbps +4s
  mediasoup:WARN:Channel [pid:236915] RTC::TransportCongestionControlClient::MayEmitAvailableBitrateEvent() | high BWE value decrease detected, notifying the listener [now:30000, before:53863] +1ms
  mediasoup:WARN:Channel [pid:236915] webrtc::ProbeController::Process() | kWaitingForProbingResult: timeout +705ms

Does that sound you a bell? Could it be related simply to the server not having enough bandwidth or power to sustain a video stream?

Thanks for the help!

BronzedBroth · March 25, 2025, 9:29pm

It could be client sided and in such case they can detect and request to restart ICE. Though I would run a speedtest and see if your server actually can deliver good speeds.

Low bitrate situations do lead to a broadcast never loading for others.

CaribouFute · March 26, 2025, 12:10am

Thanks! Makes a lot of sense. Will ask to make a speed test.

Topic		Replies	Views
Strange Issue mediasoup-demo	3	512	March 15, 2021
Video stream from mediasoup server to react-native-webrtc client Integration	10	1984	April 27, 2023
Mediasoup audio and video works on local enviroment but dosent work on remote server mediasoup libraries	3	238	October 1, 2023
Video is not playing in video Element although I am getting the media track in consmer mediasoup libraries	27	1324	January 18, 2021
Mediasoup - Users Cannot Join Room (Media Blocked) Deployment & Scalability	5	29	February 26, 2025

Problem consuming stream on test server - bitrate problem

Related topics