Video frozen for 10s of seconds before resuming after random seek in GStreamer-backed plain transport stream

Hi Mediasoup Team,

I have a set up where I’m running the Mediasoup client on iOS (via the mediasoup-ios-client library), and feeding it a consumer connected to a producer backed by GStreamer (thanks to vpalmisano’s mediasoupbin example). The set up works great…until I attempt to fast forward the media stream generated by GStreamer. Here are my observations:

  1. On instructing GStreamer to seek into the media stream, it correctly generates a keyframe and sends it to the Mediasoup producer.
  2. Mediasoup recognizes the discontinuity in the video stream (no issues with the audio stream, understandably since audio packets are independently decodable) and issues a PLI against the GStreamer producer.
  3. The PLI RTCP feedback sent to GStreamer correctly triggers another keyframe to be produced. This keyframe is acknowledged by Mediasoup, and I even verified that the iOS client’s consumer registers that the keyframe occurred.
  4. For whatever reason, the video in iOS stays stuck - i.e. no video frames are decoded on the iOS client.
  5. The above dance continues for a few 10s of seconds while the iOS video stays until magically, the video resumes.
  6. Audio is never stuck.

So it seems that a video seek in GStreamer caused the video to stall for a long time before it resumes.

I’ve attached the trace logs that I captured to show how the PLI requests from Mediasoup are being reliably honored by the producer connected to GStreamer, and how Mediasoup acknowledges receipt of the keyframes. Also note that I’ve captured the stats from the consumer each time a keyframe is generated by the producer. Right after the last chunk of trace logs, the video unfroze in the iOS client.

I’m not able to spot anything in the logs to point me to a root cause for this. I don’t see anything different about the last trace log chunk that would indicate why the video unfroze at that point. Could I get some help with this, or any suggestions as to what other logs I should be looking at?

Thank you!

2020-07-12T22:37:36.232Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:36.232Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:19417]
2020-07-12T22:37:36.232Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 19417, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1849304604 }, timestamp: 202584273, type: 'rtp' }]
2020-07-12T22:37:36.233Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 2102, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1849304604, wideSequenceNumber: 2118 }, timestamp: 202584273, type: 'rtp' }]
2020-07-12T22:37:36.233Z mediasoup:Consumer getStats()
2020-07-12T22:37:36.233Z mediasoup:Channel request() [method:consumer.getStats, id:22]
2020-07-12T22:37:36.233Z mediasoup:Channel request succeeded [method:consumer.getStats, id:22]
2020-07-12T22:37:36.234Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1333763, byteCount: 2724436, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2105, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 0, roundTripTime: 3.0670166015625, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202584274, type: 'outbound-rtp' }, { bitrate: 1313219, byteCount: 2682336, firCount: 0, fractionLost: 0, jitter: 782, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2105, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 0, score: 10, ssrc: 29105699, timestamp: 202584274, type: 'inbound-rtp' } ]
2020-07-12T22:37:36.352Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:36.475Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:36.597Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:36.717Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:36.837Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:36.958Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:37.080Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:37.201Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]
2020-07-12T22:37:37.322Z mediasoup:WARN:Channel [pid:41618] RTC::NackGenerator::GetNackBatch() | sequence number removed from the NACK list due to max retries [filter:time, seq:7089]
2020-07-12T22:37:37.322Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::OnNackGeneratorNackRequired() | triggering NACK [ssrc:62083599, first seq:7089, num packets:1]


2020-07-12T22:37:39.086Z mediasoup:Channel [pid:41618] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:403348044, media ssrc:403348044]
2020-07-12T22:37:39.086Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:pli, trace:{ direction: 'in', info: { ssrc: 403348044 }, timestamp: 202587127, type: 'pli' }]
2020-07-12T22:37:39.086Z mediasoup:Consumer getStats()
2020-07-12T22:37:39.086Z mediasoup:Channel request() [method:consumer.getStats, id:23]
2020-07-12T22:37:39.087Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:29105699]
2020-07-12T22:37:39.087Z mediasoup:Channel request succeeded [method:consumer.getStats, id:23]
2020-07-12T22:37:39.087Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1371939, byteCount: 3168330, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2449, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 1, roundTripTime: 3.0059814453125, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202587128, type: 'outbound-rtp' }, { bitrate: 1350819, byteCount: 3119350, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2449, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 1, score: 10, ssrc: 29105699, timestamp: 202587128, type: 'inbound-rtp' } ]
2020-07-12T22:37:39.153Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:19769]
2020-07-12T22:37:39.153Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 19769, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1849567366 }, timestamp: 202587194, type: 'rtp' }]
2020-07-12T22:37:39.153Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 2454, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1849567366, wideSequenceNumber: 2470 }, timestamp: 202587194, type: 'rtp' }]
2020-07-12T22:37:39.153Z mediasoup:Consumer getStats()
2020-07-12T22:37:39.153Z mediasoup:Channel request() [method:consumer.getStats, id:24]
2020-07-12T22:37:39.154Z mediasoup:Channel request succeeded [method:consumer.getStats, id:24]
2020-07-12T22:37:39.154Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1380765, byteCount: 3178555, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2458, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 1, roundTripTime: 3.0059814453125, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202587195, type: 'outbound-rtp' }, { bitrate: 1359453, byteCount: 3129395, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2458, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 1, score: 10, ssrc: 29105699, timestamp: 202587195, type: 'inbound-rtp' } ]


2020-07-12T22:37:42.088Z mediasoup:Channel [pid:41618] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:403348044, media ssrc:403348044]
2020-07-12T22:37:42.088Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:pli, trace:{ direction: 'in', info: { ssrc: 403348044 }, timestamp: 202590129, type: 'pli' }]
2020-07-12T22:37:42.088Z mediasoup:Consumer getStats()
2020-07-12T22:37:42.088Z mediasoup:Channel request() [method:consumer.getStats, id:25]
2020-07-12T22:37:42.089Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:29105699]
2020-07-12T22:37:42.089Z mediasoup:Channel request succeeded [method:consumer.getStats, id:25]
2020-07-12T22:37:42.089Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1461642, byteCount: 3730635, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2876, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 2, roundTripTime: 3.11279296875, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202590130, type: 'outbound-rtp' }, { bitrate: 1439434, byteCount: 3673115, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2876, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 2, score: 10, ssrc: 29105699, timestamp: 202590130, type: 'inbound-rtp' } ]
2020-07-12T22:37:42.158Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:20198]
2020-07-12T22:37:42.158Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 20198, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1849837636 }, timestamp: 202590199, type: 'rtp' }]
2020-07-12T22:37:42.159Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 2883, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1849837636, wideSequenceNumber: 2899 }, timestamp: 202590199, type: 'rtp' }]
2020-07-12T22:37:42.159Z mediasoup:Consumer getStats()
2020-07-12T22:37:42.159Z mediasoup:Channel request() [method:consumer.getStats, id:26]
2020-07-12T22:37:42.159Z mediasoup:Channel request succeeded [method:consumer.getStats, id:26]
2020-07-12T22:37:42.159Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1450070, byteCount: 3744713, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2887, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 2, roundTripTime: 3.11279296875, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202590200, type: 'outbound-rtp' }, { bitrate: 1428054, byteCount: 3686973, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 2887, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 2, score: 10, ssrc: 29105699, timestamp: 202590200, type: 'inbound-rtp' } ]


2020-07-12T22:37:45.110Z mediasoup:Channel [pid:41618] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:403348044, media ssrc:403348044]
2020-07-12T22:37:45.111Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:pli, trace:{ direction: 'in', info: { ssrc: 403348044 }, timestamp: 202593151, type: 'pli' }]
2020-07-12T22:37:45.111Z mediasoup:Consumer getStats()
2020-07-12T22:37:45.111Z mediasoup:Channel request() [method:consumer.getStats, id:27]
2020-07-12T22:37:45.111Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:29105699]
2020-07-12T22:37:45.111Z mediasoup:Channel request succeeded [method:consumer.getStats, id:27]
2020-07-12T22:37:45.112Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1348013, byteCount: 4261883, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3284, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 3, roundTripTime: 10.92529296875, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202593153, type: 'outbound-rtp' }, { bitrate: 1327213, byteCount: 4196203, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3284, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 3, score: 10, ssrc: 29105699, timestamp: 202593153, type: 'inbound-rtp' } ]
2020-07-12T22:37:45.162Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:20605]
2020-07-12T22:37:45.162Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 20605, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1850107906 }, timestamp: 202593203, type: 'rtp' }]
2020-07-12T22:37:45.162Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 3290, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1850107906, wideSequenceNumber: 3306 }, timestamp: 202593203, type: 'rtp' }]
2020-07-12T22:37:45.164Z mediasoup:Consumer getStats()
2020-07-12T22:37:45.164Z mediasoup:Channel request() [method:consumer.getStats, id:28]
2020-07-12T22:37:45.164Z mediasoup:Channel request succeeded [method:consumer.getStats, id:28]
2020-07-12T22:37:45.165Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1331434, byteCount: 4272118, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3292, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 3, roundTripTime: 10.92529296875, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202593206, type: 'outbound-rtp' }, { bitrate: 1310826, byteCount: 4206278, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3292, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 3, score: 10, ssrc: 29105699, timestamp: 202593206, type: 'inbound-rtp' } ]


2020-07-12T22:37:48.113Z mediasoup:Channel [pid:41618] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:403348044, media ssrc:403348044]
2020-07-12T22:37:48.114Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:pli, trace:{ direction: 'in', info: { ssrc: 403348044 }, timestamp: 202596155, type: 'pli' }]
2020-07-12T22:37:48.114Z mediasoup:Consumer getStats()
2020-07-12T22:37:48.114Z mediasoup:Channel request() [method:consumer.getStats, id:29]
2020-07-12T22:37:48.114Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:29105699]
2020-07-12T22:37:48.115Z mediasoup:Channel request succeeded [method:consumer.getStats, id:29]
2020-07-12T22:37:48.115Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1486413, byteCount: 4817960, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3707, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 4, roundTripTime: 2.166748046875, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202596156, type: 'outbound-rtp' }, { bitrate: 1463693, byteCount: 4743820, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3707, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 4, score: 10, ssrc: 29105699, timestamp: 202596156, type: 'inbound-rtp' } ]
2020-07-12T22:37:48.160Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:21029]
2020-07-12T22:37:48.160Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 21029, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1850378176 }, timestamp: 202596201, type: 'rtp' }]
2020-07-12T22:37:48.161Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 3714, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1850378176, wideSequenceNumber: 3730 }, timestamp: 202596201, type: 'rtp' }]
2020-07-12T22:37:48.161Z mediasoup:Consumer getStats()
2020-07-12T22:37:48.161Z mediasoup:Channel request() [method:consumer.getStats, id:30]
2020-07-12T22:37:48.161Z mediasoup:Channel request succeeded [method:consumer.getStats, id:30]
2020-07-12T22:37:48.162Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1432038, byteCount: 4833177, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3719, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 4, roundTripTime: 2.166748046875, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202596203, type: 'outbound-rtp' }, { bitrate: 1410086, byteCount: 4758797, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 3719, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 4, score: 10, ssrc: 29105699, timestamp: 202596203, type: 'inbound-rtp' } ]


2020-07-12T22:37:51.136Z mediasoup:Channel [pid:41618] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:403348044, media ssrc:403348044]
2020-07-12T22:37:51.136Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:pli, trace:{ direction: 'in', info: { ssrc: 403348044 }, timestamp: 202599178, type: 'pli' }]
2020-07-12T22:37:51.136Z mediasoup:Consumer getStats()
2020-07-12T22:37:51.136Z mediasoup:Channel request() [method:consumer.getStats, id:31]
2020-07-12T22:37:51.137Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:29105699]
2020-07-12T22:37:51.137Z mediasoup:Channel request succeeded [method:consumer.getStats, id:31]
2020-07-12T22:37:51.137Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1526854, byteCount: 5416668, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4163, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 5, roundTripTime: 3.6773681640625, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202599178, type: 'outbound-rtp' }, { bitrate: 1503622, byteCount: 5333408, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4163, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 5, score: 10, ssrc: 29105699, timestamp: 202599178, type: 'inbound-rtp' } ]
2020-07-12T22:37:51.206Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:21485]
2020-07-12T22:37:51.206Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 21485, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1850652200 }, timestamp: 202599247, type: 'rtp' }]
2020-07-12T22:37:51.206Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 4170, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1850652200, wideSequenceNumber: 4186 }, timestamp: 202599247, type: 'rtp' }]
2020-07-12T22:37:51.206Z mediasoup:Consumer getStats()
2020-07-12T22:37:51.206Z mediasoup:Channel request() [method:consumer.getStats, id:32]
2020-07-12T22:37:51.207Z mediasoup:Channel request succeeded [method:consumer.getStats, id:32]
2020-07-12T22:37:51.207Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1540877, byteCount: 5431180, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4174, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 5, roundTripTime: 3.6773681640625, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202599248, type: 'outbound-rtp' }, { bitrate: 1517453, byteCount: 5347700, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4174, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 5, score: 10, ssrc: 29105699, timestamp: 202599248, type: 'inbound-rtp' } ]


2020-07-12T22:37:54.142Z mediasoup:Channel [pid:41618] RTC::Transport::HandleRtcpPacket() | PLI received, requesting key frame for Consumer [sender ssrc:403348044, media ssrc:403348044]
2020-07-12T22:37:54.142Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:pli, trace:{ direction: 'in', info: { ssrc: 403348044 }, timestamp: 202602183, type: 'pli' }]
2020-07-12T22:37:54.142Z mediasoup:Consumer getStats()
2020-07-12T22:37:54.142Z mediasoup:Channel request() [method:consumer.getStats, id:33]
2020-07-12T22:37:54.143Z mediasoup:Channel [pid:41618] RTC::RtpStreamRecv::RequestKeyFrame() | sending PLI [ssrc:29105699]
2020-07-12T22:37:54.143Z mediasoup:Channel request succeeded [method:consumer.getStats, id:33]
2020-07-12T22:37:54.143Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1549238, byteCount: 6011654, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4620, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 6, roundTripTime: 18.096923828125, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202602184, type: 'outbound-rtp' }, { bitrate: 1525366, byteCount: 5919254, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4620, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 6, score: 10, ssrc: 29105699, timestamp: 202602184, type: 'inbound-rtp' } ]
2020-07-12T22:37:54.211Z mediasoup:Channel [pid:41618] RTC::Producer::ReceiveRtpPacket() | key frame received [ssrc:29105699, seq:21941]
2020-07-12T22:37:54.211Z Mediasoup:INFO:Room producer "trace" event [producerId:34039d6b-a6f2-4007-88d0-fa25dd68e729, trace.type:rtp, trace:{ direction: 'in', info: { isKeyFrame: true, marker: 'false', payloadSize: 1388, payloadType: 101, sequenceNumber: 21941, size: 1400, spatialLayer: 0, ssrc: 29105699, temporalLayer: 0, timestamp: 1850922470 }, timestamp: 202602252, type: 'rtp' }]
2020-07-12T22:37:54.211Z Mediasoup:INFO:Room consumer "trace" event [consumerId:29439aa3-34ac-4c72-ad4a-bc71a88e0d95, trace.type:rtp, trace:{ direction: 'out', info: { isKeyFrame: true, marker: 'false', mid: '1', payloadSize: 1388, payloadType: 101, sequenceNumber: 4626, size: 1420, spatialLayer: 0, ssrc: 403348044, temporalLayer: 0, timestamp: 1850922470, wideSequenceNumber: 4642 }, timestamp: 202602252, type: 'rtp' }]
2020-07-12T22:37:54.211Z mediasoup:Consumer getStats()
2020-07-12T22:37:54.211Z mediasoup:Channel request() [method:consumer.getStats, id:34]
2020-07-12T22:37:54.212Z mediasoup:Channel request succeeded [method:consumer.getStats, id:34]
2020-07-12T22:37:54.212Z Mediasoup:INFO:Room Consumer stats:[ { bitrate: 1531498, byteCount: 6023875, firCount: 0, fractionLost: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4629, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 6, roundTripTime: 18.096923828125, rtxSsrc: 449694857, score: 10, ssrc: 403348044, timestamp: 202602254, type: 'outbound-rtp' }, { bitrate: 1507882, byteCount: 5931295, firCount: 0, fractionLost: 0, jitter: 0, kind: 'video', mimeType: 'video/VP8', nackCount: 0, nackPacketCount: 0, packetCount: 4629, packetsDiscarded: 0, packetsLost: 0, packetsRepaired: 0, packetsRetransmitted: 0, pliCount: 6, score: 10, ssrc: 29105699, timestamp: 202602254, type: 'inbound-rtp' } ]

@ethand91 just wanted to alert you to this in case there could be some sort of thread contention issue on the iOS side. Just hazarding a guess here.

Does the same happen when viewing the stream from HTML?

If it’s an iOS only please open an issue at:

Including the LogLevel.TRACE logs from the iOS client.

Yes, the same thing happens when viewing the stream from HTML.

Specifically, I used the exact set up in the GStreamer example in the mediasoup-demo source code. Everything streams to the web perfectly. However, when I do a seek on the GStreamer bin, the behavior I saw in iOS occurs.

So it’s looking more and more like this is a problem in how libmediasoupclient handles discontinuous streams? Hard to say on my own.

From reading consumer/producer stats and logs on the server, iOS and web client, I see that even when the video is stalled, bytes are still flowing, and key frames are being decoded (i.e. the ‘keyFramesDecoded’ field keeps increasing. The one thing that gets stuck while the video is stalled is the ‘framesDecoded’ field. It starts to increase once the video stops stalling.

@ibc Just in case you might have some insights on what aspects of the system I should be looking at. I’m starting to spend some time reading the mediasoup code here and here. Is it possible that when a large skip happens in the stream due to a random seek on the GStreamer side, it triggers constant issuing of PLIs until the nack list drains?

Please, avoid direct mentions. This is a forum with many participants, not just mediasoup authors.

The NACK logic of mediasoup is extremely tested. I don’t know how good GStreamer behaves when it comes to retransmissions handling, but that’s not an issue in mediasoup.