Janus Server and FFMpeg - Very bad stream quality

[NebulaSleuth]

I am trying to use SIP Sorcery/FFMpeg as the client to a Janus stream. I have tested that the stream works using a web browser client.
Full example code for the test client can be found here: https://github.com/NebulaSleuth/SSStreamTest

In this picture you can see both the web version and the SIP Sorcery Ffmpeg version.

example

I modified the Sip Sorcery Echo Test example to use ffmpeg camera as the source and that worked great. So I implemented a Video Room, but that was horrible. So, I simplified and used ffmpeg to inject an RTP stream to Janus Stream plugin, and created a simple client to watch the stream. It had the same issue as the VideoRoom plugin.

I have tried h264 and VP8. H264 is worse and not at all real-time (at least 5 seconds behind)

So here is what I am doing...
Initialize the Peer and sink
`

              var pc = new RTCPeerConnection(null);
            SIPSorceryMedia.FFmpeg.FFmpegInit.Initialise(SIPSorceryMedia.FFmpeg.FfmpegLogLevelEnum.AV_LOG_VERBOSE, ffmpegLibFullPath, logger);
            var videoSink = new FFmpegVideoEndPoint();
            videoSink.RestrictFormats(format => format.Codec == VideoCodecsEnum.VP8);

            pc.OnVideoFrameReceived += videoSink.GotVideoFrame;
            
            pc.OnVideoFormatsNegotiated += (formats) =>
            {
                videoSink.SetVideoSourceFormat(formats.First());
            };

`

init the track
`

             MediaStreamTrack videoTrack = new MediaStreamTrack(videoSink.GetVideoSinkFormats(), MediaStreamStatusEnum.RecvOnly);
              pc.addTrack(videoTrack);

              pc.OnVideoFrameReceived += videoSink.GotVideoFrame;
              pc.OnVideoFormatsNegotiated += (formats) =>
                  videoSink.SetVideoSinkFormat(formats.First());`

Then handle the Janus stuff
`

            var janusClient = new JanusRestClient(SERVER_URL, logger, cts.Token);

            janusClient.OnJanusEvent += async (str) =>
            {
                var resp = JsonConvert.DeserializeObject<dynamic>(str);
                if (resp.jsep != null)
                {
                    logger.LogDebug($"get event jsep={resp.jsep.type}.");

                    logger.LogDebug($"SDP Answer: {resp.jsep.sdp}");
                    var result = pc.setRemoteDescription(new RTCSessionDescriptionInit { type = RTCSdpType.answer, sdp = resp.jsep.sdp });
                    logger.LogDebug($"SDP Answer: {pc.remoteDescription.sdp}");

                    if (result == SetDescriptionResultEnum.OK)
                    {
                        logger.LogDebug("Starting peer connection.");

                        var answerSdp = pc.createAnswer(null);
                        await pc.setLocalDescription(answerSdp);
                        await janusClient.SendStart(id, answerSdp.sdp);
                    }
                    else
                    {
                        logger.LogDebug($"Error setting remote SDP description {result}.");
                        pc.Close("error");
                    }
                }
                else
                {
                    logger.LogDebug("Event: " + str);
                }
            };

            await janusClient.StartSession().ConfigureAwait(false);
            id = await janusClient.StartStreamingPlugin().ConfigureAwait(false);
            var result = await janusClient.ListRooms(id).ConfigureAwait(false);
            if (result?.plugindata?.data?.list?.Count > 0)
            {
                foreach (var stream in result.plugindata.data.list)
                {
                    logger.LogDebug($"Stream: {stream.id} {stream.display}");
                    if (stream.id == 1001)
                    {
                        // Found it
                        await janusClient.Watch(id, (int)stream.id, "video1", null);

                    }
                }
            }`

Basically it works, but the video quality is horrible. The web client is great for the same stream.
I suspect that there is something wrong in the negotiation? Or with the Ffmpeg configuration. i just can't figure out what.

`
// Janus Stream configuration file
//
// ballcall: {
// type = "rtp"
// id = 1001
// description = "Ball Call Stream"
// metadata = "This is an example of a multistream mountpoint: you'll get an audio stream and two video feeds"
// media = (
// {
// type = "audio"
// mid = "audio1"
// label = "Audio stream"
// port = 8005
// pt = 111
// codec = "opus"
// },
// {
// type = "video"
// mid = "video1"
// label = "Video stream #1"
// port = 8004
// pt = 100
// codec = "vp8"
// videofmtp = "profile-level-id=42e01f;packetization-mode=1"
// }
// )
// }

//
// FFMPEG RTP command
//
// ffmpeg -f dshow -thread_queue_size 8192 -video_size 1280x720 -framerate 10 -i video="Astra Pro HD Camera"
// -pix_fmt yuv420p -c:v libvpx -b:v 1M -deadline realtime -max_delay 0 -an -bufsize 1M -vsync 1 -g 10 -f rtp rtp://10.0.2.25:8004/
//
`

And my log:
`

WebRTC Client Test Console
[16:58:11 DBG] RTCPeerConnection created with DTLS certificate with fingerprint sha-256 A1:26:91:BF:5B:D8:98:00:4B:A7:D2:17:7B:88:F1:E7:F2:0D:F8:30:53:19:3D:B7:2A:4C:86:44:BC:DB:14:E1 and signature algorithm SHA256withECDSA.
[16:58:12 DBG] CreateRtpSocket attempting to create and bind RTP socket(s) on [::]:0.
[16:58:12 DBG] CreateBoundSocket attempting to create and bind socket(s) on [::]:0 using protocol Udp.
[16:58:12 DBG] CreateBoundSocket successfully bound on [::]:50594, dual mode True.
[16:58:12 DBG] Successfully bound RTP socket [::]:50594 (dual mode True).
[16:58:12 DBG] RTPChannel for [::]:50594 started.
[16:58:12 DBG] SCTP windows size for data receiver set at 218.
[16:58:12 DBG] SCTP creating DTLS based association, is DTLS client False, ID 5000:5000:50594.
[16:58:12 INF] FFmpeg binaries path set to: C:\ffmpeg\bin
[16:58:12 DBG] RTP ICE Channel discovered 4 local candidates.
[16:58:12 INF] FFmpeg version info: 7.1-full_build-www.gyan.dev
[16:58:12 DBG] Creating Janus session...
[16:58:12 DBG] Result=success.
[16:58:12 DBG] Transaction=638684962923664147.
[16:58:12 DBG] SessionID=7814829111246584.
[16:58:12 DBG] Sending attach to janus.plugin.streaming.
[16:58:12 DBG] Sending long poll GET to http://10.0.2.25:8088/janus/7814829111246584.
[16:58:12 DBG] {"janus":"attach","plugin":"janus.plugin.streaming","transaction":"638684962924951873","jsep":null,"body":null}
[16:58:12 DBG] Attach response result=success.
[16:58:12 DBG] Attach response plugin id=5514902936182854.
[16:58:12 DBG] {"janus":"message","transaction":"638684962925337976","jsep":null,"body":{"request":"list"}}
[16:58:12 DBG] Stream: 1001
{"janus":"message","transaction":"638684962926286267","jsep":null,"body":{"request":"watch","id":1001,"offer_video":true}}
[16:58:12 DBG] Stream: 1
[16:58:12 DBG] Stream: 123
[16:58:12 DBG] Stream: 2
[16:58:12 DBG] Stream: 3
[16:58:12 DBG] get event result=event.
[16:58:12 DBG] get event jsep=offer.
[16:58:12 DBG] SDP Answer: v=0
o=- 1732921085458566 1 IN IP4 192.168.1.77
s=Mountpoint 1001
t=0 0
a=group:BUNDLE audio1 video1
a=ice-options:trickle
a=fingerprint:sha-256 D7:4F:16:E5:4D:91:06:B2:34:FE:89:78:35:6B:5A:51:44:55:8E:D0:A0:E5:AC:5B:83:33:A0:0D:9F:B4:D3:D1
a=extmap-allow-mixed
a=msid-semantic: WMS *
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 192.168.1.77
a=sendonly
a=mid:audio1
a=rtcp-mux
a=ice-ufrag:INd7
a=ice-pwd:mQQns+t1DxR/NSQTmnc8YB
a=ice-options:trickle
a=setup:actpass
a=rtpmap:111 opus/48000/2
a=rtcp-fb:111 transport-cc
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
a=msid:janus janusaudio1
a=ssrc:4154953829 cname:janus
a=candidate:1 1 udp 2015365375 192.168.1.77 41328 typ host
a=candidate:2 1 udp 2015365631 10.0.2.25 45166 typ host
a=end-of-candidates
m=video 9 UDP/TLS/RTP/SAVPF 100 101
c=IN IP4 192.168.1.77
a=sendonly
a=mid:video1
a=rtcp-mux
a=ice-ufrag:INd7
a=ice-pwd:mQQns+t1DxR/NSQTmnc8YB
a=ice-options:trickle
a=setup:actpass
a=rtpmap:100 VP8/90000
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=rtcp-fb:100 goog-remb
a=rtcp-fb:100 transport-cc
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
a=rtpmap:101 rtx/90000
a=fmtp:101 apt=100
a=ssrc-group:FID 2582065637 1887752808
a=msid:janus janusvideo1
a=ssrc:2582065637 cname:janus
a=ssrc:1887752808 cname:janus
a=candidate:1 1 udp 2015365375 192.168.1.77 41328 typ host
a=candidate:2 1 udp 2015365631 10.0.2.25 45166 typ host
a=end-of-candidates

[16:58:12 DBG] [setRemoteDescription] - Extension:[2 - http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time]
[16:58:12 DBG] [setRemoteDescription] - Extension:[2 - http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time]
[16:58:12 DBG] RTP ICE Channel remote credentials set.
[16:58:12 DBG] ICE connection state changed to checking.
[16:58:12 DBG] RTP ICE Channel received remote candidate: 1 1 udp 2015365375 192.168.1.77 41328 typ host generation 0
[16:58:12 DBG] RTP ICE Channel received remote candidate: 2 1 udp 2015365631 10.0.2.25 45166 typ host generation 0
[16:58:12 DBG] RTP ICE Channel received remote candidate: 1 1 udp 2015365375 192.168.1.77 41328 typ host generation 0
[16:58:12 DBG] RTP ICE Channel received remote candidate: 2 1 udp 2015365631 10.0.2.25 45166 typ host generation 0
[16:58:12 DBG] LogRemoteSDPSsrcAttributes: Audio:[ 4154953829 - ]
Video: [ [2582065637 - 1887752808 - ] ]
[16:58:12 DBG] SDP Answer: v=0
o=- 1732921085458566 1 IN IP4 192.168.1.77
s=Mountpoint 1001
t=0 0
a=fingerprint:sha-256 D7:4F:16:E5:4D:91:06:B2:34:FE:89:78:35:6B:5A:51:44:55:8E:D0:A0:E5:AC:5B:83:33:A0:0D:9F:B4:D3:D1
a=group:BUNDLE audio1 video1
a=ice-options:trickle
a=extmap-allow-mixed
a=msid-semantic: WMS *
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 192.168.1.77
a=ice-ufrag:INd7
a=ice-pwd:mQQns+t1DxR/NSQTmnc8YB
a=setup:actpass
a=candidate:1 1 udp 2015365375 192.168.1.77 41328 typ host
a=candidate:2 1 udp 2015365631 10.0.2.25 45166 typ host
a=mid:audio1
a=rtpmap:111 opus/48000/2
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=rtcp-mux
a=ice-options:trickle
a=rtcp-fb:111 transport-cc
a=msid:janus janusaudio1
a=sendonly
a=ssrc:4154953829 cname:janus
m=video 9 UDP/TLS/RTP/SAVPF 100 101
c=IN IP4 192.168.1.77
a=ice-ufrag:INd7
a=ice-pwd:mQQns+t1DxR/NSQTmnc8YB
a=setup:actpass
a=candidate:1 1 udp 2015365375 192.168.1.77 41328 typ host
a=candidate:2 1 udp 2015365631 10.0.2.25 45166 typ host
a=mid:video1
a=rtpmap:100 VP8/90000
a=rtpmap:101 rtx/90000
a=fmtp:101 apt=100
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=rtcp-mux
a=ice-options:trickle
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=rtcp-fb:100 goog-remb
a=rtcp-fb:100 transport-cc
a=msid:janus janusvideo1
a=sendonly
a=ssrc-group:FID 2582065637 1887752808
a=ssrc:2582065637 cname:janus
a=ssrc:1887752808 cname:janus

[16:58:12 DBG] Starting peer connection.
[16:58:12 DBG] {"janus":"message","transaction":"638684962927575658","jsep":{"type":"answer","sdp":"v=0\r\no=- 29534 0 IN IP4 127.0.0.1\r\ns=sipsorcery\r\nt=0 0\r\na=group:BUNDLE audio1 video1\r\nm=audio 9 UDP/TLS/RTP/SAVP 111 101\r\nc=IN IP4 0.0.0.0\r\na=ice-ufrag:YOIR\r\na=ice-pwd:JQFRXSRCNQAXNJZEMSNRTHMC\r\na=fingerprint:sha-256 A1:26:91:BF:5B:D8:98:00:4B:A7:D2:17:7B:88:F1:E7:F2:0D:F8:30:53:19:3D:B7:2A:4C:86:44:BC:DB:14:E1\r\na=setup:passive\r\na=candidate:3466988343 1 udp 2113937663 192.168.1.200 50594 typ host generation 0\r\na=candidate:4031802564 1 udp 2113940223 2603:8081:6200:12d:f466:ad21:db49:a3b2 50594 typ host generation 0\r\na=candidate:2526844489 1 udp 2113940223 2603:8081:6200:12d:a635:bc91:6f56:fef 50594 typ host generation 0\r\na=candidate:2787588012 1 udp 2113940223 2603:8081:6200:12d::b23 50594 typ host generation 0\r\na=ice-options:ice2,trickle\r\na=mid:audio1\r\na=rtpmap:111 opus/48000/2\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=rtcp-mux\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=end-of-candidates\r\na=inactive\r\na=ssrc:1677017077 cname:a31757ad-8777-4519-a75d-5b76bf3958be\r\nm=video 9 UDP/TLS/RTP/SAVP 100 101\r\nc=IN IP4 0.0.0.0\r\na=ice-ufrag:YOIR\r\na=ice-pwd:JQFRXSRCNQAXNJZEMSNRTHMC\r\na=fingerprint:sha-256 A1:26:91:BF:5B:D8:98:00:4B:A7:D2:17:7B:88:F1:E7:F2:0D:F8:30:53:19:3D:B7:2A:4C:86:44:BC:DB:14:E1\r\na=setup:passive\r\na=ice-options:ice2,trickle\r\na=mid:video1\r\na=rtpmap:100 VP8/90000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=rtcp-mux\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=recvonly\r\na=ssrc:1451379383 cname:d8bec96a-d6cb-4ff8-8291-65aa6f8486ba\r\n","trickle":false},"body":{"request":"start"}}
[16:58:12 DBG] Adding new candidate pair to checklist for: udp:[::]:50594 (host)->udp:192.168.1.77:41328 (host)
[16:58:12 DBG] Adding new candidate pair to checklist for: udp:[::]:50594 (host)->udp:10.0.2.25:45166 (host)
[16:58:12 DBG] Existing checklist entry has higher priority, NOT adding entry for: 1 1 udp 2015365375 192.168.1.77 41328 typ host generation 0
[16:58:12 DBG] Existing checklist entry has higher priority, NOT adding entry for: 2 1 udp 2015365631 10.0.2.25 45166 typ host generation 0
[16:58:12 DBG] ICE RTP channel sending connectivity check for udp:[::]:50594 (host)->udp:10.0.2.25:45166 (host) from [::]:50594 to 10.0.2.25:45166 (use candidate False).
[16:58:12 WRN] ICE RTP channel a STUN binding error response was received from 10.0.2.25:45166.
[16:58:12 WRN] ICE RTP channel check list entry set to failed: 2 1 udp 2015365631 10.0.2.25 45166 typ host generation 0
[16:58:12 DBG] ICE RTP channel sending connectivity check for udp:[::]:50594 (host)->udp:192.168.1.77:41328 (host) from [::]:50594 to 192.168.1.77:41328 (use candidate False).
[16:58:12 DBG] ICE RTP channel remote peer nominated entry from binding request: udp:10.0.2.25:45166 (host).
[16:58:12 INF] ICE RTP channel connected after 774ms udp:[::]:50594 (host)->udp:10.0.2.25:45166 (host).
[16:58:12 DBG] ICE connection state changed to connected.
[16:58:12 DBG] Peer connection connected changed to connecting.
[16:58:12 INF] ICE connected to remote end point 10.0.2.25:45166.
[16:58:12 DBG] Starting DLS handshake with role passive.
[16:58:12 DBG] RTCPeerConnection DoDtlsHandshake started.
[16:58:12 WRN] ICE RTP channel a STUN binding error response was received from 192.168.1.77:41328.
[16:58:12 DBG] DTLS commencing handshake as server.
[16:58:12 WRN] ICE RTP channel check list entry set to failed: 1 1 udp 2015365375 192.168.1.77 41328 typ host generation 0
[16:58:12 WRN] ICE RTP channel received an unexpected STUN message 17 from 10.0.2.25:45166.
Json: SIPSorcery.Net.STUNMessage
[16:58:12 INF] Selected cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256. Using SHA256withECDSA certificate with fingerprint sha-256 A1:26:91:BF:5B:D8:98:00:4B:A7:D2:17:7B:88:F1:E7:F2:0D:F8:30:53:19:3D:B7:2A:4C:86:44:BC:DB:14:E1.
[16:58:12 DBG] RTCPeerConnection DTLS handshake result True, is handshake complete True.
[16:58:12 DBG] RTCPeerConnection remote certificate fingerprint matched expected value of D7:4F:16:E5:4D:91:06:B2:34:FE:89:78:35:6B:5A:51:44:55:8E:D0:A0:E5:AC:5B:83:33:A0:0D:9F:B4:D3:D1 for sha-256.
[16:58:12 DBG] Peer connection connected changed to connected.
[16:58:12 DBG] Set remote track (video - index=0) SSRC to 2582065637.
[16:58:12 DBG] Video depacketisation codec set to VP8 for SSRC 2582065637.
[16:58:13 DBG] [InitialiseDecoder] CodecId:[AV_CODEC_ID_VP8
[16:58:13 DBG] Successfully initialised ffmpeg based image converted for 1280:720:AV_PIX_FMT_YUV420P->1280:720:AV_PIX_FMT_BGR24.
[16:58:13 DBG] Sending long poll GET to http://10.0.2.25:8088/janus/7814829111246584.
[16:58:13 DBG] get event result=event.
[16:58:13 DBG] Event: {"janus":"event","session_id":7814829111246584,"transaction":"638684962927596822","sender":5514902936182854,"plugindata":{"plugin":"janus.plugin.streaming","data":{"streaming":"event","result":{"status":"starting"}}}
[16:58:14 DBG] Sending long poll GET to http://10.0.2.25:8088/janus/7814829111246584.
[16:58:14 DBG] get event result=event.
[16:58:14 DBG] Event: {"janus":"event","session_id":7814829111246584,"sender":5514902936182854,"plugindata":{"plugin":"janus.plugin.streaming","data":{"streaming":"event","result":{"status":"started"}}}
[16:58:15 WRN] ICE RTP channel a STUN binding error response was received from 10.0.2.25:45166.
[16:58:15 WRN] ICE RTP channel check list entry set to failed: 2 1 udp 2015365631 10.0.2.25 45166 typ host generation 0
[16:58:15 DBG] Sending long poll GET to http://10.0.2.25:8088/janus/7814829111246584.
[16:58:15 DBG] get event result=webrtcup.
[16:58:15 DBG] Event: {"janus":"webrtcup","session_id":7814829111246584,"sender":5514902936182854}
[16:58:16 DBG] Sending long poll GET to http://10.0.2.25:8088/janus/7814829111246584.
[16:58:18 WRN] ICE RTP channel a STUN binding error response was received from 10.0.2.25:45166.
[16:58:18 WRN] ICE RTP channel check list entry set to failed: 2 1 udp 2015365631 10.0.2.25 45166 typ host generation 0`

[sipsorcery]

It's impressive you got that to work at all! That's a lot of moving parts.

The issue with the video performance is the inefficiency in C# bytes manipulation. See #384. While I expect there are some performance improvements that could be made I suspect the dotnet managed runtime overhead is always going to crop up.

I realise your case is 720p rather than 1080p and you might be able to get a consistent video stream by reducing the frame rate to 5 or 10fps. That won't be much use for a live video call but it would align with the dotnet performance bottleneck theory.

[NebulaSleuth]

Thanks. I thought the decode and conversion was happening in the FFMpeg.dll. Is the MediaAbstraction layer still involved with the I420toBGR ? I will test the theory by reducing to a low resolution image and see if that helps. If that works, then maybe a native c implementation would be better. If that is the case then maybe a method for 'Frame Received' that pushes up the I420 data and let me handle the conversion.
My final application is running on DirectX on windows and OpenGL on linux. I could even take the I420 data and possibly create a GPU assisted transformation if this is the bottleneck. Can you give me some guidance on where I could alter the code to deliver the raw frames?

[NebulaSleuth]

Also, note that I was able to get it working without going through Janus, so I was thinking it was more of an issue a difference in the stream itself. or to do with packet loss (although the Janus server is on the same local network) So using a direct FFPmeg encoder (based on your examples) and websocket signaling worked to the same client.

To help me understand better, what makes this issue crop up when going through the Janus server?

[sipsorcery]

You can avoid the pixel format conversion if you can find a way to display I420 (or whatever you're getting) directly in your Windows app. All the Windows UI controls I've ever used only support BGR hence the need for the conversion.

Putting the pixel conversion into a native library "might" help but it also could jsut shift the problem marshalling backwards and forwards across the managed/native boundary (PInvoking).

A better option would be if the FFmpeg decoder could be configured to decode directly into the required pixel format. That's probably possible.

As far as where you get the video frames from see the IVideoSink interface which is what the FFmpegVideoEndPoint implements. And then the GotVideoFrame method is where you could start looking for improvements. Note that the whole SIPSorceryMedia.FFmpeg project is at prototype level only. The goal was to see if it could work. Only s amll amount of subsequent performance work has been undertaken.