Could somebody please enlighten me what I see here?

mediasoup libraries
1

Disclaimer: Quoted ode has been seen in one or other form in many samples. I have some problems to understand. A little explanation would be appreciated.

My producer uses this simulcast setup in client-side JS:

  params.encodings = [
    { maxBitrate: 100000 },
    { maxBitrate: 1000000 },
    { maxBitrate: 3000000 },
  ]
  
  params.codecOptions = {
    videoGoogleStartBitrate : 1000
  }

  producer = await transport.produce(params)

Server-side the consumer issues this on consume:

  if (consumer.type === 'simulcast') {
    await consumer.setPreferredLayers({ spatialLayer: 2, temporalLayer: 2 });
  }

My producer resides on a Linux box, running Chrome. Server app on a MacBook in the same network, client also on Chrome.

I’m throttling the network power on the reception side using NetworkLinkConditioner. As seen, my Mac simulates Edge environment with delay

image

Without this conditioner applied the consumer starts at 1M, 640x480 (no lon.

The server traces this (on layerschange):

layerschange { spatialLayer: 1, temporalLayer: 0 }
layerschange { spatialLayer: 1, temporalLayer: 1 }
layerschange { spatialLayer: 1, temporalLayer: 2 }

When I apply the “brake”, consumer side received resolution goes down to 320x240 and bitrate is about 100kB. Video is still there, but of course a bit blurry now and slightly delayed (due to the delay applied by the conditioner).

The server traces this (on layerschange):

layerschange { spatialLayer: 0, temporalLayer: 0 }
layerschange { spatialLayer: 0, temporalLayer: 1 }
layerschange { spatialLayer: 0, temporalLayer: 2 }

image
image726×390 29.1 KB

If I remove the brake again, bitrate and resolution go up again and the server trace this:

layerschange { spatialLayer: 1, temporalLayer: 0 }
layerschange { spatialLayer: 1, temporalLayer: 1 }
layerschange { spatialLayer: 1, temporalLayer: 2 }

Question I have: What does this layerschange events mean to the consumer side? Is here really a selection of another simulcast stream happening? I understand, that the server traces indicates a change in (used?) spatial layer, since the resolution dropped. I admit I would have expected to see a drop in bitrate (which happened too) while maintaining the resolution, but this is all thin ice for me here.

Could anybody kindly provide more input on this or some links to learn about?

Thanks in advance

2

Server-side simulcast consumer gets packets from one of the producer’s streams and puts them in a single output stream. When the spatial layer is changed, it switches to another input stream internally. But its output stream remains the same.

3

Thanks, that makes sense. Can this switch somehow be “seen”? Maybe by a trace message in the server-side code?

4

Found this in the logs with simulcast logs enabled server-side:

mediasoup:Channel request() [method:consumer.resume, id:11] +2ms
  mediasoup:Channel [pid:46519] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:1, media ssrc:241065923] +0ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | using spatial layer 2 as RTP timestamp reference +0ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:2, temporal:0, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +0ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:268898189] +0ms
  mediasoup:Channel request succeeded [method:consumer.resume, id:11] +0ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:268898189, seq:17167] +48ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sync key frame received +1ms
layerschange { spatialLayer: 2, temporalLayer: 0 }
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sending sync packet [ssrc:241065923, seq:2, ts:3659210179] from original [ssrc:756561442, seq:17167, ts:3659210179] +3ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:1131389698, seq:30325] +0ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:2088] +0ms
  mediasoup:Channel [pid:46519] RTC::IceServer::HandleTuple() | transition from state 'connected' to 'completed' [hasUseCandidate:true, hasNomination:false, nomination:0] +9ms
  mediasoup:Channel [pid:46519] RTC::WebRtcTransport::OnIceServerCompleted() | ICE completed +0ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:2, temporal:2, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +27ms
layerschange { spatialLayer: 2, temporalLayer: 1 }
layerschange { spatialLayer: 2, temporalLayer: 2 }


// Brakes on

  mediasoup:WARN:Channel [pid:46519] RTC::RtpStreamRecv::OnTimer() | RTP inactivity detected, resetting score to 0 [ssrc:268898189] +57s
  mediasoup:Channel [pid:46519] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:1, media ssrc:241065923] +33s
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:268898189] +1ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:1, temporal:2, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +263ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +0ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:268898189] +736ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +264ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:3069] +2s
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:3101] +777ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:1, temporal:1, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +739ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +0ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +1s
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:3235] +632ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:3266] +871ms
  mediasoup:WARN:Channel [pid:46519] RTC::RtpStreamRecv::OnTimer() | RTP inactivity detected, resetting score to 0 [ssrc:1131389698] +9s
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:1, temporal:0, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +438ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +0ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:3321] +943ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:0, temporal:2, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +55ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:265869984] +1ms
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +0ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:3340] +957ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sync key frame received +1ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sending sync packet [ssrc:241065923, seq:5345, ts:3663032299] from original [ssrc:756561440, seq:3340, ts:4208765540] +0ms
layerschange { spatialLayer: 0, temporalLayer: 0 }
layerschange { spatialLayer: 0, temporalLayer: 2 }


// Brakes off

  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:1131389698, seq:33681] +2m
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:5916] +55ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:1, temporal:2, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +3s
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:1131389698] +1ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:1131389698, seq:33849] +46ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sync key frame received +2ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sending sync packet [ssrc:241065923, seq:8017, ts:3671468269] from original [ssrc:756561441, seq:33849, ts:3330907489] +0ms
layerschange { spatialLayer: 1, temporalLayer: 0 }
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:6012] +53ms
layerschange { spatialLayer: 1, temporalLayer: 1 }
layerschange { spatialLayer: 1, temporalLayer: 2 }
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:268898189, seq:22554] +15s
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:1131389698, seq:35403] +45ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:6512] +1ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::UpdateTargetLayers() | target layers changed [spatial:2, temporal:2, consumerId:1cd6af28-2ebe-4a3a-b09d-4fb5f12f3af8] +3s
  mediasoup:Channel [pid:46519] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:268898189] +1ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:268898189, seq:22929] +37ms
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sync key frame received +1ms
layerschange { spatialLayer: 2, temporalLayer: 0 }
  mediasoup:Channel [pid:46519] RTC::SimulcastConsumer::SendRtpPacket() | sending sync packet [ssrc:241065923, seq:9903, ts:3673091059] from original [ssrc:756561442, seq:22929, ts:3673091059] +1ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:1131389698, seq:35741] +41ms
  mediasoup:Channel [pid:46519] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:265869984, seq:6611] +0ms
layerschange { spatialLayer: 2, temporalLayer: 1 }
layerschange { spatialLayer: 2, temporalLayer: 2 }

Doc says:

consumer.on(“layerschange”, fn(layers))


This event is emitted under various circumstances in SVC or simulcast consumers (assuming the consumer endpoints supports BWE via REMB or Transport-CC):

When the consumer (or its associated producer) is paused.
When all the RTP streams of the associated producer become inactive (no RTP received for a while).
When the available bitrate of the BWE makes the consumer upgrade or downgrade the spatial and/or temporal layers.
When there is no available bitrate for this consumer (even for the lowest layers) so the event fires with null as argument.
The Node.js application can detect the latter (consumer deactivated due to not enough bandwidth) by checking if both consumer.paused and consumer.producerPaused are falsy after the consumer has emitted this event with null as argument.

So I suppose the log is the expression of that internal switch you were mentioning.

Thanks

5

But layerschange is the message. Switching from one stream to another actually amounts to which packets (with which ssrc) the consumer does not drop, using the mapping from ssrc to spatial layer. It’s not something physical on the transport level.

6

Hmm. Not sure to understand. I meant, that the mediasoup log is somehow showing that switch and the event is documenting it to the outside world.