Consumer video stuck 'buffering'

I am using mediasoup with Electron. I have logging enabled for mediasoup on my server, and everything there looks fine, no errors at all. Producer and Consumer ends also have no errors, and everything looks like its getting set up perfectly.
But the video in the consumer end is stuck loading. I don’t know if loading is the right word to use.

Screenshot:

Screenshot from 2020-04-17 12-14-29

Is this a common issue? Should I provide code? Are there any common mistakes that can lead to this?

I tried to monitor network activity on my Producer end, and the client is not using any upload bandwidth.
Nothing is being uploaded, if that helps narrow down the issue.

Yes. The problem is that the sender is not sending anything.

This is the produce function in my react client

    async function produce() {
        let stream;
        if (!sendTransport) {
            console.error("no send transport");
            return;
        }
        try {
            stream = await getUserMedia(isWebcam, device);
            const track = stream.getVideoTracks()[0];
            const params = { track };
            if (SIMULCAST) {
                params.encodings = [
                    { maxBitrate: 100000 },
                    { maxBitrate: 300000 },
                    { maxBitrate: 900000 },
                ];
                params.codecOptions = {
                    videoGoogleStartBitrate: 1000
                };
            }
            setProducer(await sendTransport.produce(params));
            setLocalStream(stream);
            //console.log(stream);
            //console.log(stream.getVideoTracks());
            console.log("Producing");
            socket.emit('producerReady', () => { console.log("Producer is ready"); });

        } catch (err) {
            console.error("Errored at produce:", err);
        }
    }

The getUserMedia() function returns a valid stream, and that is confirmed because the call to setLocalStream(stream) sets the srcObject on a video element to the stream, which works and displays the webcam output into the local video element.

socket.emit('producerReady') event is emitted by the server to all connected clients, upon which they start consuming. This is my consume() implementation:


const consume = (producerId) => {
        if (!(device && device.rtpCapabilities)) {
            console.error("Device not loaded");
            return;
        }

        const { rtpCapabilities } = device;
        console.log("Consume called on", producerId);

        if (!receiveTransport) {
            console.error("no receive transport");
            return;
        }

        let consumer;

        socket.emit('consume', producerId, rtpCapabilities, async (data) => {
            if (data.error) { console.error(data.error); return; };
            const { producerId, id, kind, rtpParameters, type, producerPause } = data;

            consumer = await receiveTransport.consume({
                id,
                producerId,
                kind,
                rtpParameters
            });

            console.log("Everything great before resume, consumer received");
            socket.emit('resume', (args) => {
                if (args && args.error) {
                    console.error(args.error);
                    return;
                };
                setConsumer(consumer);
                const {track} = consumer;
                const stream = new MediaStream([track]);
                //console.log(consumer);
                //console.log(stream.getTracks());
                setRemoteStream(stream);
            })
        });
    }

Is there anything that I am doing wrong? Should I include my server side code too?

I will not check your code, sorry. Check whether ICE connects, etc. There are lot of API and logs in client and server side to check that. Just saying that “everything seems ok in the server because you don’t see fatal errors” means nothing if you did not enable ICE logs or if you don’t check the ICE connection state of the transport in client and server side.

This should be enough for enabling all logs including ICE on the server side right?

process.env.DEBUG = "mediasoup*"

I don’t see any logs related to ICE.
Here is what generally happens when a client starts producing and the other starts consuming:

2020-04-17T06:42:45.823Z mediasoup:Transport produce()

2020-04-17T06:42:45.824Z mediasoup:Channel request() [method:transport.produce, id:77]

2020-04-17T06:42:45.825Z mediasoup:Channel request succeeded [method:transport.produce, id:77]

2020-04-17T06:42:45.826Z mediasoup:Producer constructor()

2020-04-17T06:42:46.038Z mediasoup:Transport consume()

2020-04-17T06:42:46.039Z mediasoup:Channel request() [method:transport.consume, id:78]

2020-04-17T06:42:46.042Z mediasoup:Channel request succeeded [method:transport.consume, id:78]

2020-04-17T06:42:46.042Z mediasoup:Consumer constructor()

2020-04-17T06:42:46.043Z mediasoup:Consumer setPreferredLayers()

2020-04-17T06:42:46.043Z mediasoup:Channel request() [method:consumer.setPreferredLayers, id:79]

2020-04-17T06:42:46.044Z mediasoup:Channel request succeeded [method:consumer.setPreferredLayers, id:79]

2020-04-17T06:42:46.149Z mediasoup:WebRtcTransport connect()

2020-04-17T06:42:46.150Z mediasoup:Channel request() [method:transport.connect, id:80]

2020-04-17T06:42:46.151Z mediasoup:Channel request succeeded [method:transport.connect, id:80]

2020-04-17T06:42:46.272Z mediasoup:Consumer resume()

2020-04-17T06:42:46.273Z mediasoup:Channel request() [method:consumer.resume, id:81]

2020-04-17T06:42:46.274Z mediasoup:Channel request succeeded [method:consumer.resume, id:81]

Do I need to enable logging for ICE explicitly?

I enabled logs on the client too. I am sorry but I can’t understand what’s wrong. It would be great if someone could point out the general direction I should proceed towards.

Here’s the consumer logs:

common.js:114 mediasoup-client:Transport consume() +9s

common.js:114 mediasoup-client:Chrome74 receive() [trackId:0ff7e0c6-f313-45c5-9284-665cd9c1323b, kind:video] +9s

common.js:114 mediasoup-client:Chrome74 receive() | calling pc.setRemoteDescription() [offer:{type: "offer", sdp: "v=0
↵o=mediasoup-client 10000 1 IN IP4 0.0.0.0
↵s=…D 127539657 391677036
↵a=rtcp-mux
↵a=rtcp-rsize
↵"}] +5ms

common.js:114 mediasoup-client:RemoteSdp updateDtlsRole() [role:server] +0ms

common.js:114 mediasoup-client:Chrome74 receive() | calling pc.setLocalDescription() [answer:{type: "answer", sdp: "v=0
↵o=- 1089209412160333349 2 IN IP4 127.0.0.1
↵s…a=ice-options:trickle
↵a=rtcp-mux
↵a=rtcp-rsize
↵"}] +112ms

common.js:114 mediasoup-client:Consumer constructor() +0ms

common.js:114 mediasoup-client:Chrome74 receive() [trackId:probator, kind:video] +10ms

common.js:114 mediasoup-client:Chrome74 receive() | calling pc.setRemoteDescription() [offer:{type: "offer", sdp: "v=0
↵o=mediasoup-client 10000 2 IN IP4 0.0.0.0
↵s=…c:1234 cname:probator
↵a=rtcp-mux
↵a=rtcp-rsize
↵"}] +1ms

common.js:114 mediasoup-client:Transport connection state changed to connecting +134ms

common.js:114 mediasoup-client:Chrome74 receive() | calling pc.setLocalDescription() [answer:{type: "answer", sdp: "v=0
↵o=- 1089209412160333349 3 IN IP4 127.0.0.1
↵s…a=ice-options:trickle
↵a=rtcp-mux
↵a=rtcp-rsize
↵"}type: "answer"sdp: "v=0
↵o=- 1089209412160333349 3 IN IP4 127.0.0.1
↵s=-
↵t=0 0
↵a=msid-semantic: WMS
↵a=group:BUNDLE 0 probator
↵m=video 51856 UDP/TLS/RTP/SAVPF 101 102
↵c=IN IP4 192.168.1.100
↵a=rtpmap:101 VP8/90000
↵a=rtpmap:102 rtx/90000
↵a=fmtp:102 apt=101
↵a=rtcp:9 IN IP4 0.0.0.0
↵a=rtcp-fb:101 transport-cc
↵a=rtcp-fb:101 ccm fir
↵a=rtcp-fb:101 nack
↵a=rtcp-fb:101 nack pli
↵a=extmap:12 urn:ietf:params:rtp-hdrext:toffset
↵a=extmap:4 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
↵a=extmap:11 urn:3gpp:video-orientation
↵a=extmap:5 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
↵a=extmap:6 http://tools.ietf.org/html/draft-ietf-avtext-framemarking-07
↵a=extmap:1 urn:ietf:params:rtp-hdrext:sdes:mid
↵a=setup:active
↵a=mid:0
↵a=recvonly
↵a=ice-ufrag:iIIF
↵a=ice-pwd:eyYf9WPqeq3KJioCvkypKiDa
↵a=fingerprint:sha-256 A6:8A:82:71:6C:DF:56:22:EE:39:62:E7:C2:9F:5A:46:11:D4:DA:DB:11:D3:61:FF:E5:03:2B:F0:F7:0D:5F:1E
↵a=candidate:4076596107 1 udp 2122262783 2409:4061:2106:c14f:bd9a:6532:9436:a327 36706 typ host generation 0 network-id 2 network-cost 50
↵a=candidate:3013953624 1 udp 2122194687 192.168.1.100 51856 typ host generation 0 network-id 1 network-cost 50
↵a=candidate:25025252 1 udp 2122131711 2620:9b::1959:5920 59213 typ host generation 0 network-id 4
↵a=candidate:4102952089 1 udp 2122063615 25.89.89.32 43764 typ host generation 0 network-id 3
↵a=ice-options:trickle
↵a=rtcp-mux
↵a=rtcp-rsize
↵m=video 9 UDP/TLS/RTP/SAVPF 127
↵c=IN IP4 0.0.0.0
↵a=rtpmap:127 VP8/90000
↵a=rtcp:9 IN IP4 0.0.0.0
↵a=rtcp-fb:127 transport-cc
↵a=rtcp-fb:127 ccm fir
↵a=rtcp-fb:127 nack
↵a=rtcp-fb:127 nack pli
↵a=extmap:12 urn:ietf:params:rtp-hdrext:toffset
↵a=extmap:4 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
↵a=extmap:11 urn:3gpp:video-orientation
↵a=extmap:5 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
↵a=extmap:6 http://tools.ietf.org/html/draft-ietf-avtext-framemarking-07
↵a=extmap:1 urn:ietf:params:rtp-hdrext:sdes:mid
↵a=setup:active
↵a=mid:probator
↵a=recvonly
↵a=ice-ufrag:iIIF
↵a=ice-pwd:eyYf9WPqeq3KJioCvkypKiDa
↵a=fingerprint:sha-256 A6:8A:82:71:6C:DF:56:22:EE:39:62:E7:C2:9F:5A:46:11:D4:DA:DB:11:D3:61:FF:E5:03:2B:F0:F7:0D:5F:1E
↵a=ice-options:trickle
↵a=rtcp-mux
↵a=rtcp-rsize
↵"__proto__: Object] +8ms

common.js:114 mediasoup-client:Transport consume() | Consumer for RTP probation created +13ms

common.js:114 mediasoup-client:Transport connection state changed to disconnected +2m

I see that the transport connection state changes to disconnected right after connecting.
Also the consumer receives the DTLS role of server, is that normal?
mediasoup-client:RemoteSdp updateDtlsRole() [role:server]

And here is the producer logs:

common.js:114 mediasoup-client:Transport produce() [track:MediaStreamTrack {kind: "video", id: "e7f2c93e-bd00-4a20-8a51-fd5d84f93f5d", label: "HP TrueVision HD Camera (04f2:b67f)", enabled: true, muted: false, …}] +2s

common.js:114 mediasoup-client:Chrome74 send() [kind:video, track.id:e7f2c93e-bd00-4a20-8a51-fd5d84f93f5d] +2s

common.js:114 mediasoup-client:RemoteSdp updateDtlsRole() [role:client] +0ms

common.js:114 mediasoup-client:Chrome74 send() | calling pc.setLocalDescription() [offer:RTCSessionDescription {type: "offer", sdp: "v=0
↵o=- 8644871460964641051 2 IN IP4 127.0.0.1
↵s… send
↵a=rid:r2 send
↵a=simulcast:send r0;r1;r2
↵"}type: "offer"sdp: "v=0
↵o=- 8644871460964641051 2 IN IP4 127.0.0.1
↵s=-
↵t=0 0
↵a=group:BUNDLE 0
↵a=msid-semantic: WMS 317cc931-5e98-4cae-8f90-43bdef73f70c
↵m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 102 122 127 121 125 107 108 109 124 120 123
↵c=IN IP4 0.0.0.0
↵a=rtcp:9 IN IP4 0.0.0.0
↵a=ice-ufrag:supd
↵a=ice-pwd:z5vh1auzQo3ZH0i+6F6xqonj
↵a=ice-options:trickle
↵a=fingerprint:sha-256 93:3D:18:73:FD:FE:C7:BC:DF:08:F1:7D:FB:1A:04:74:C6:50:F4:1C:D4:A8:5D:A0:04:53:F2:1B:F3:8A:0B:7D
↵a=setup:actpass
↵a=mid:0
↵a=extmap:14 urn:ietf:params:rtp-hdrext:toffset
↵a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
↵a=extmap:13 urn:3gpp:video-orientation
↵a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
↵a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay
↵a=extmap:11 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type
↵a=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-timing
↵a=extmap:8 http://tools.ietf.org/html/draft-ietf-avtext-framemarking-07
↵a=extmap:9 http://www.webrtc.org/experiments/rtp-hdrext/color-space
↵a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
↵a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id
↵a=extmap:6 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id
↵a=sendonly
↵a=msid:317cc931-5e98-4cae-8f90-43bdef73f70c e7f2c93e-bd00-4a20-8a51-fd5d84f93f5d
↵a=rtcp-mux
↵a=rtcp-rsize
↵a=rtpmap:96 VP8/90000
↵a=rtcp-fb:96 goog-remb
↵a=rtcp-fb:96 transport-cc
↵a=rtcp-fb:96 ccm fir
↵a=rtcp-fb:96 nack
↵a=rtcp-fb:96 nack pli
↵a=rtpmap:97 rtx/90000
↵a=fmtp:97 apt=96
↵a=rtpmap:98 VP9/90000
↵a=rtcp-fb:98 goog-remb
↵a=rtcp-fb:98 transport-cc
↵a=rtcp-fb:98 ccm fir
↵a=rtcp-fb:98 nack
↵a=rtcp-fb:98 nack pli
↵a=fmtp:98 profile-id=0
↵a=rtpmap:99 rtx/90000
↵a=fmtp:99 apt=98
↵a=rtpmap:100 VP9/90000
↵a=rtcp-fb:100 goog-remb
↵a=rtcp-fb:100 transport-cc
↵a=rtcp-fb:100 ccm fir
↵a=rtcp-fb:100 nack
↵a=rtcp-fb:100 nack pli
↵a=fmtp:100 profile-id=2
↵a=rtpmap:101 rtx/90000
↵a=fmtp:101 apt=100
↵a=rtpmap:102 H264/90000
↵a=rtcp-fb:102 goog-remb
↵a=rtcp-fb:102 transport-cc
↵a=rtcp-fb:102 ccm fir
↵a=rtcp-fb:102 nack
↵a=rtcp-fb:102 nack pli
↵a=fmtp:102 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42001f
↵a=rtpmap:122 rtx/90000
↵a=fmtp:122 apt=102
↵a=rtpmap:127 H264/90000
↵a=rtcp-fb:127 goog-remb
↵a=rtcp-fb:127 transport-cc
↵a=rtcp-fb:127 ccm fir
↵a=rtcp-fb:127 nack
↵a=rtcp-fb:127 nack pli
↵a=fmtp:127 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42001f
↵a=rtpmap:121 rtx/90000
↵a=fmtp:121 apt=127
↵a=rtpmap:125 H264/90000
↵a=rtcp-fb:125 goog-remb
↵a=rtcp-fb:125 transport-cc
↵a=rtcp-fb:125 ccm fir
↵a=rtcp-fb:125 nack
↵a=rtcp-fb:125 nack pli
↵a=fmtp:125 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f
↵a=rtpmap:107 rtx/90000
↵a=fmtp:107 apt=125
↵a=rtpmap:108 H264/90000
↵a=rtcp-fb:108 goog-remb
↵a=rtcp-fb:108 transport-cc
↵a=rtcp-fb:108 ccm fir
↵a=rtcp-fb:108 nack
↵a=rtcp-fb:108 nack pli
↵a=fmtp:108 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42e01f
↵a=rtpmap:109 rtx/90000
↵a=fmtp:109 apt=108
↵a=rtpmap:124 red/90000
↵a=rtpmap:120 rtx/90000
↵a=fmtp:120 apt=124
↵a=rtpmap:123 ulpfec/90000
↵a=rid:r0 send
↵a=rid:r1 send
↵a=rid:r2 send
↵a=simulcast:send r0;r1;r2
↵"__proto__: RTCSessionDescription] +168ms
common.js:114 mediasoup-client:Chrome74 send() | calling pc.setRemoteDescription() [answer:{type: "answer", sdp: "v=0
↵o=mediasoup-client 10000 1 IN IP4 0.0.0.0
↵s=… recv
↵a=rid:r2 recv
↵a=simulcast:recv r0;r1;r2
↵"}type: "answer"sdp: "v=0
↵o=mediasoup-client 10000 1 IN IP4 0.0.0.0
↵s=-
↵t=0 0
↵a=ice-lite
↵a=fingerprint:sha-512 3C:8E:E5:D2:01:DC:A0:6E:8D:5D:37:2A:23:3E:D0:BF:5B:F5:33:BF:B0:DB:41:7C:E9:AB:DE:30:5B:97:9E:EF:0E:08:96:8B:59:6E:01:07:36:92:5F:15:F3:14:7D:32:2F:F7:0B:91:F7:DB:53:A5:3B:2C:78:A2:2D:21:53:C7
↵a=msid-semantic: WMS *
↵a=group:BUNDLE 0
↵m=video 7 UDP/TLS/RTP/SAVPF 96 97
↵c=IN IP4 127.0.0.1
↵a=rtpmap:96 VP8/90000
↵a=rtpmap:97 rtx/90000
↵a=fmtp:96 x-google-start-bitrate=1000
↵a=fmtp:97 apt=96
↵a=rtcp-fb:96 transport-cc 
↵a=rtcp-fb:96 ccm fir
↵a=rtcp-fb:96 nack 
↵a=rtcp-fb:96 nack pli
↵a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
↵a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id
↵a=extmap:6 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id
↵a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
↵a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
↵a=extmap:8 http://tools.ietf.org/html/draft-ietf-avtext-framemarking-07
↵a=extmap:13 urn:3gpp:video-orientation
↵a=extmap:14 urn:ietf:params:rtp-hdrext:toffset
↵a=setup:active
↵a=mid:0
↵a=recvonly
↵a=ice-ufrag:drtbmj0x80439wjx
↵a=ice-pwd:e4a470xmtd1029c2nlv9c9iniumpz29j
↵a=candidate:udpcandidate 1 udp 1076558079 139.59.65.23 10008 typ host
↵a=candidate:tcpcandidate 1 tcp 1076302079 139.59.65.23 10036 typ host tcptype passive
↵a=end-of-candidates
↵a=ice-options:renomination
↵a=rtcp-mux
↵a=rtcp-rsize
↵a=rid:r0 recv
↵a=rid:r1 recv
↵a=rid:r2 recv
↵a=simulcast:recv r0;r1;r2
↵"__proto__: Object] +16ms

common.js:114 mediasoup-client:Transport connection state changed to connecting +194ms

common.js:114 mediasoup-client:Producer constructor() +0ms

common.js:114 mediasoup-client:Transport connection state changed to disconnected +2m

Here too I notice the same problem. And the producer receives the DTLS role of server, is that just the way things work?
mediasoup-client:RemoteSdp updateDtlsRole() [role:server]

I understand that you do not have the time or the incentive to dig through my logs, and I am sorry if I come off as annoying, or expecting too much. Its just that I am really confused, and have been trying to solve this issue for a very long time now. If you could help me approach the problem, that would be really great.

Thanks a lot.

No, check the Debugging documentation of mediasoup server.

Yes, that’s what the docs say.

This is a random question. You read something in the logs for first time and, since you have a problem, you assume that such a log is the problem. No, that’s ok but I cannot explain here how DTLS works.

So ICE fails. Check your networking setup. TIP: https://mediasoup.org/faq/#running-mediasoup-in-hosts-with-private-ip

Hey, thanks a lot for the lead on. I tried logging the ICE status server side with

webRtcTransport.on("icestatechange", (iceState) =>
{
  console.log("ICE state changed to %s", iceState);
});

and it looks like the ICE status is stuck at new, which I assume is not ideal?
It turns out that logging was already enabled for the ice namespace, but there were no related logs.

Thanks for that tip too, but I am running on DigitalOcean, with a public IPv4 address, so that shouldn’t be an issue right? Could this be a firewall configuration issue? Currently I have all outgoing enabled, but incoming is enabled only for OpenSSH and Nginx. Should I also enable incoming for all ports in the range rtcMaxPort to rtcMinPort?

No, it’s not. You have not enabled it. I said “read the Debugging” section of the docs. You didn’t

No time to explain this again and again, sorry. The FAQ should help you, but you have to understand how your deployment and networking is.

Sorry for the misunderstanding, I meant that I had already enabled it in my config.js file.

As for reading the FAQ, I did go through it. I am not that adept with remote deployments and networking, I am still in high school, was trying to create a video streaming application to help my school conduct online classes.

Thanks for the help anyway :smile:

Which config.js? mediasoup does not have any config.js file. If you are using the demo project, please don’t open topics on the mediasoup category.

BTW, no, you have a private IP and a public announced IP in your cloud server. And yes, you have to redirect all mediasoup port range to the interval IP in which mediasoup is listening because, I insist, your server does not have a public IP but a private one.

Hey, I solved the issue. DigitalOcean does provide me with a public IP, so it wasn’t that.

It was actually firewall settings. I temporarily allowed all incoming connection, and voila it worked.

Anyway, thank you so much for your prompt replies. Mediasoup is an amazing piece of technology, and without it, writing a whole video conferencing app would be impossible for someone like me.

Once again, thanks a lot. :smile:

Great