troubleshooting video from non-WebRTC endpoints?

[Daniel Pocock]

Hi all,

I'm currently looking at how to integrate reSIProcate with Kurento. The
initial steps are here:

https://github.com/resiprocate/resiprocate/blob/b-dpocock-recon-kurento/resip/recon/KurentoRemoteParticipant.cxx#L181

but more is to come, including a C++ client library, similar to the Java
client.

The code above is a proof-of-concept. It is working with WebRTC
clients. Both audio and video streams are in loopback when somebody
dials in.

The code supports both WebRtcEndpoint and regular RtpEndpoint.

With RtpEndpoint:
- the audio loopback is working,
- the video loopback is not working.

Based on the success of audio loopback, I do not believe there is any
issue with firewalls or NAT.

I am trying a few different clients including Linphone and some Cisco /
Tandberg devices, for example, Cisco EX90.

I used tcpdump and wireshark to look at the RTP streams. I see the
device is sending RTP packets to Kurento. Kurento does not send video
back to the device. Only audio is going back.

I tried both Kurento 6.16 on Ubuntu 18.04 and also the Kurento 7
(upstream GStreamer) on Ubuntu 18.04

Can anybody make any suggestions about how to troubleshoot this issue?

Regards,

Daniel

[Juan Navarro]

First thing would be to check on the SDP negotiation. If you copy here a
sample of the SDP Offer that is sent to Kurento, and what is the SDP
Answer that Kurento responds with, I can have a look and let you know if
I see something strange in there.

[Daniel Pocock]

On 15/07/2021 19:35, Juan Navarro wrote:
> First thing would be to check on the SDP negotiation. If you copy here a
> sample of the SDP Offer that is sent to Kurento, and what is the SDP
> Answer that Kurento responds with, I can have a look and let you know if
> I see something strange in there.

Thanks for the fast reply. Here are the SDP offer/answer exchanges from
both Cisco and Linphone video. In both cases, the audio loopback worked
but not the video.

In each case, I can see:
- the caller is sending the video RTP packets to Kurento,
- netstat shows Kurento listening on the RTP/RTCP video ports


SDP Offer from Cisco / Tandberg EX90:


v=0
o=tandberg 83 2 IN IP4 10.1.2.111
s=-
c=IN IP4 10.1.2.111
b=AS:1920
t=0 0
m=audio 2352 RTP/AVP 107 108 109 110 104 105 9 15 18 8 0 101
b=TIAS:128000
a=rtpmap:107 MP4A-LATM/90000
a=fmtp:107 profile-level-id=25;object=23;bitrate=128000
a=rtpmap:108 MP4A-LATM/90000
a=fmtp:108 profile-level-id=24;object=23;bitrate=64000
a=rtpmap:109 MP4A-LATM/90000
a=fmtp:109 profile-level-id=24;object=23;bitrate=56000
a=rtpmap:110 MP4A-LATM/90000
a=fmtp:110 profile-level-id=24;object=23;bitrate=48000
a=rtpmap:104 G7221/16000
a=fmtp:104 bitrate=32000
a=rtpmap:105 G7221/16000
a=fmtp:105 bitrate=24000
a=rtpmap:9 G722/8000
a=rtpmap:15 G728/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
m=video 2354 RTP/AVP 97 126 96 34 31
b=TIAS:1920000
a=rtpmap:97 H264/90000
a=fmtp:97
packetization-mode=0;profile-level-id=420016;max-br=5000;max-mbps=245000;max-fs=9000;max-smbps=245000;max-fps=6000;max-rcmd-nalu-size=3456000;sar-supported=16
a=rtpmap:126 H264/90000
a=fmtp:126
packetization-mode=1;profile-level-id=428016;max-br=5000;max-mbps=245000;max-fs=9000;max-smbps=245000;max-fps=6000;max-rcmd-nalu-size=3456000;sar-supported=16
a=rtpmap:96 H263-1998/90000
a=fmtp:96
custom=1280,768,3;custom=1280,720,3;custom=1024,768,1;custom=1024,576,2;custom=800,600,1;cif4=1;custom=720,480,1;custom=640,480,1;custom=512,288,1;cif=1;custom=352,240,1;qcif=1;maxbr=19200
a=rtpmap:34 H263/90000
a=fmtp:34 cif4=1;cif=1;qcif=1;maxbr=19200
a=rtpmap:31 H261/90000
a=fmtp:31 cif=1;qcif=1;maxbr=19200
a=label:11
a=answer:full
a=content:main
a=rtcp-fb:* nack pli
a=rtcp-fb:* ccm fir
a=rtcp-fb:* ccm tmmbr
a=sendrecv
m=application 2358 RTP/AVP 100
a=rtpmap:100 H224/4800
a=sendrecv


Kurento's SDP Answer for the Cisco / Tandberg EX90:


v=0
o=- 3835362201 3835362201 IN IP4 a.b.c.d
s=Kurento Media Server
c=IN IP4 a.b.c.d
t=0 0
m=audio 22438 RTP/AVP 0
a=sendrecv
a=rtcp:22439
a=rtpmap:0 PCMU/8000
a=ssrc:1815998858 cname:user597461156@host-4c6c6a66
m=video 49022 RTP/AVP 97 126
a=sendrecv
a=rtcp:49023
a=rtpmap:97 H264/90000
a=rtpmap:126 H264/90000
a=fmtp:97
packetization-mode=0;profile-level-id=420016;max-br=5000;max-mbps=245000;max-fs=9000;max-smbps=245000;max-fps=6000;max-rcmd-nalu-size=3456000;sar-supported=16
a=fmtp:126
packetization-mode=1;profile-level-id=428016;max-br=5000;max-mbps=245000;max-fs=9000;max-smbps=245000;max-fps=6000;max-rcmd-nalu-size=3456000;sar-supported=16
a=ssrc:3129097934 cname:user597461156@host-4c6c6a66
m=application 0 RTP/AVP 100
a=inactive




SDP Offer from Linphone:


v=0
o=daniel 614 252 IN IP4 10.1.2.71
s=Talk
c=IN IP4 10.1.2.71
t=0 0
a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
m=audio 7078 RTP/AVP 96 0 8 101 97
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=rtpmap:101 telephone-event/48000
a=rtpmap:97 telephone-event/8000
a=rtcp-fb:* trr-int 5
a=rtcp-fb:* ccm tmmbr
m=video 9078 RTP/AVP 96
a=rtpmap:96 VP8/90000
a=rtcp-fb:* trr-int 5
a=rtcp-fb:* ccm tmmbr
a=rtcp-fb:96 nack pli
a=rtcp-fb:96 nack sli
a=rtcp-fb:96 ack rpsi
a=rtcp-fb:96 ccm fir


Kurento's SDP Answer for Linphone:


v=0
o=- 3835362386 3835362386 IN IP4 a.b.c.d
s=Kurento Media Server
c=IN IP4 a.b.c.d
t=0 0
a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
m=audio 58464 RTP/AVP 96 0
a=sendrecv
a=rtcp:58465
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=ssrc:494611622 cname:user311699944@host-1f261def
m=video 29334 RTP/AVP 96
a=sendrecv
a=rtcp:29335
a=rtpmap:96 VP8/90000
a=ssrc:4162474758 cname:user311699944@host-1f261def

[Juan Navarro]

On 15/07/2021 20.31, Daniel Pocock wrote:

On 15/07/2021 19:35, Juan Navarro wrote:

First thing would be to check on the SDP negotiation. If you copy here a
sample of the SDP Offer that is sent to Kurento, and what is the SDP
Answer that Kurento responds with, I can have a look and let you know if
I see something strange in there.

Thanks for the fast reply.  Here are the SDP offer/answer exchanges

Those SDPs look fine to me. Kurento is accepting some of the proposed codecs, and providing its own listening ports where those should be sent.

In each case, I can see:
- the caller is sending the video RTP packets to Kurento,
- netstat shows Kurento listening on the RTP/RTCP video ports

Just like you say "the caller is sending the video"... can we also say the converse? That Kurento is indeed receiving the packets? (e.g. by running Wireshark in the machine where Kurento runs, just to make sure it is indeed receiving packets).

Of course, the video RTP packets should be destined to the Kurento's listening ports (49022 and 29334).

If all that is true, then the video is actually reaching Kurento. Now we should move into looking at why it doesn't go out out it.

Is there any video RTP flow coming out of Kurento, at all? even if it's to the wrong destination port.

Any relevant warning or error message in the logs?

Any of these?

WARN rtpsource [...] duplicate or reordered packet (seqnr 32462, expected 32464)
WARN kmsutils [...] GAP of 3 ms at PTS=0:01:54.187106448 (packet loss?); will request a new keyframe
WARN kmsutils [...] DISCONTINUITY at non-keyframe; will drop until keyframe

(especially the last one)

[Daniel Pocock]

On 15/07/2021 21:07, Juan Navarro wrote:
>
> On 15/07/2021 20.31, Daniel Pocock wrote:
>> On 15/07/2021 19:35, Juan Navarro wrote:
>>> First thing would be to check on the SDP negotiation. If you copy here a
>>> sample of the SDP Offer that is sent to Kurento, and what is the SDP
>>> Answer that Kurento responds with, I can have a look and let you know if
>>> I see something strange in there.
>> Thanks for the fast reply. Here are the SDP offer/answer exchanges
> Those SDPs look fine to me. Kurento is accepting some of the proposed
> codecs, and providing its own listening ports where those should be sent.
>
>
>> In each case, I can see:
>> - the caller is sending the video RTP packets to Kurento,
>> - netstat shows Kurento listening on the RTP/RTCP video ports
>
> Just like you say "the caller is sending the video"... can we also say
> the converse? That Kurento is indeed receiving the packets? (e.g. by
> running Wireshark in the machine where Kurento runs, just to make sure
> it is indeed receiving packets).

Yes, I ran tcpdump on the machine and then I copied the pcap file to a
local workstation to open it with Wireshark

Audio is working. If there was a connectivity or firewall problem then
the audio packets would not reach Kurento.

I checked MTU, it appears reasonable too.

WebRTC calls are successful. I made those tests on the same subnet,
same Kurento servers.

> Of course, the video RTP packets should be destined to the Kurento's
> listening ports (49022 and 29334).

Yes, that is what I see in Wireshark

> If all that is true, then the video is actually reaching Kurento. Now we
> should move into looking at why it doesn't go out out it.
>
> Is there any video RTP flow coming out of Kurento, at all? even if it's
> to the wrong destination port.

No

> Any relevant warning or error message in the logs?

This is from the Cisco, I eliminated some of these by removing the
content sharing media descriptor from the SDP.

$ grep -v DEBUG 2021-07-15T221156.00000.pid24306.log | cut -d: -f16-

"kms_sdp_mid_ext_add_answer_attributes","native!object":"<KmsSdpMidExt@0x7fb160015c50>
","msg":"Remote agent does not support groups"}

"kms_sdp_mid_ext_add_answer_attributes","native!object":"<KmsSdpMidExt@0x7fb1600484b0>
","msg":"Remote agent does not support groups"}

"create_media_answer","native!object":"<KmsSdpAgent@0x7fb150030180>
","msg":"Cannot handle media 'application RTP\/AVP' (multiple m= lines?)"}

"kms_sdp_mid_ext_add_answer_attributes","native!object":"<KmsSdpMidExt@0x7fb15001f640>
","msg":"Remote agent does not support groups"}

"kms_base_rtp_session_get_connection","native!object":"<kmsrtpsession0>
","msg":"Connection '2' not found"}

> Any of these?
>
> WARN rtpsource [...] duplicate or reordered packet (seqnr 32462, expected 32464)
> WARN kmsutils [...] GAP of 3 ms at PTS=0:01:54.187106448 (packet loss?); will request a new keyframe
> WARN kmsutils [...] DISCONTINUITY at non-keyframe; will drop until keyframe
>
>
> (especially the last one)

egrep -i '(reordered|keyframe)' 2021-07-15T*log

For the Cisco / Tandberg calls, none of those messages appear


For the Linphone calls, I have this:

"duplicate or reordered packet (seqnr 8, expected 10)"}
"duplicate or reordered packet (seqnr 10, expected 12)"}
"duplicate or reordered packet (seqnr 12, expected 14)"}
"duplicate or reordered packet (seqnr 16, expected 18)"}
"duplicate or reordered packet (seqnr 20, expected 22)"}
"duplicate or reordered packet (seqnr 22, expected 24)"}
...


Do you have any test instance of Kurento on a server with public
connectivity? If you like, I can configure my reSIProcate process to
make a WebSocket connection to your Kurento machine so you can observe
the same behavior.

In reSIProcate, I created a parameter like this:

KurentoURI = kurento:aaa.bbb.ccc.ddd:8888


Regards,

Daniel

[Daniel Pocock]

Found the issue, two possible bugs in Kurento video codec or H264...

At the start of the call, I notice that the Cisco EX90 sends a very
short packet on each stream, audio and video

The packet is 32 bytes IP, 12 bytes UDP or 4 bytes of RTP data if you
interpret the packet as RTP

Here are the 12 bytes in the UDP:


09 7a 06 84 00 0c 0c 75 50 49 4e 48 : .z.....uPINH



This appears to prevent Kurento from following the stream

I used IP tables to block packets with IP length 32, that prevents
Kurento receiving the PINH packet. That immediately fixed the problems.

If I toggle the EX90 into screensharing mode and back to video mode then
Kurento recovers and starts processing the stream correctly.

Therefore, there are two problems:

- specific: cleanly disposing of any bad packets without killing the codec

- general: something has put the stream in a very bad state, but Kurento
did not log any error, maybe some code is not checking a return value

This happens with both the Kurento 6.16 gstreamer and also the Kurento 7
new gstreamer.

I haven't made any standalone tests with gstreamer or ffmpeg, it would
be interesting to see if they choke on the same RTP packet.

Regards,

Daniel

[Israel Robotnick]

I noticed that the bin that rtpendpoint uses makes a lot of troubles, and it's better to use the playerendpoint bin.

Therefore I made an rtsp server, that takes the rtp and transform it to rtsp, and only than kurento takes it. 

Not the best thing to do in term of cpu and latency (though it doesn't transcode, just forward the packets), but it made the connection quicker and fixed the problem that rtpendpoint has to do sdp negotiations. 

--
You received this message because you are subscribed to the Google Groups "kurento" group.
To unsubscribe from this group and stop receiving emails from it, send an email to kurento+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/kurento/b2018916-58d1-0a97-2f55-9adc8471130d%40pocock.pro.

[Juan Navarro]

On 19/07/2021 14.42, Daniel Pocock wrote:
> Found the issue, two possible bugs in Kurento video codec or H264...
>

> At the start of the call, I notice that the Cisco EX90 sends a very
> short packet on each stream, audio and video
>
> The packet is 32 bytes IP, 12 bytes UDP or 4 bytes of RTP data if you
> interpret the packet as RTP
>
> Here are the 12 bytes in the UDP:
>
>
> 09 7a 06 84 00 0c 0c 75 50 49 4e 48 : .z.....uPINH
>
>
>
> This appears to prevent Kurento from following the stream
>
> I used IP tables to block packets with IP length 32, that prevents
> Kurento receiving the PINH packet. That immediately fixed the problems.
>
> If I toggle the EX90 into screensharing mode and back to video mode then
> Kurento recovers and starts processing the stream correctly.
>
> Therefore, there are two problems:
>
> - specific: cleanly disposing of any bad packets without killing the codec
>
> - general: something has put the stream in a very bad state, but Kurento
> did not log any error, maybe some code is not checking a return value
>
> This happens with both the Kurento 6.16 gstreamer and also the Kurento 7
> new gstreamer.
>
> I haven't made any standalone tests with gstreamer or ffmpeg, it would
> be interesting to see if they choke on the same RTP packet.

Great find! And what a strange bug, too. I wonder if GStreamer itself is
able to detect that something is wrong at the decoder and communicate it
to the application... another option I can think of is that the decoder
is simply fed with those bogus initial bytes, and it is permanently left
in a bad state from which it doesn't recover.

Kurento should be using the OpenH264 package for decoding H.264 streams,
so maybe there are improvements in later versions of this library. One
of the planned upgrades after releasing the Kurento 7 branch, is to
update OpenH264 to the latest 2.x branch (currently I think we're at the
most recent version of 1.x)

Also, why does the device send fake data concealed as H.264 encoded
video? That seems like a VERY bad behavior and not surprisingly it must
have broken things all around...

Regards

[Daniel Pocock]

On 19/07/2021 18:03, Israel Robotnick wrote:
> I noticed that the bin that rtpendpoint uses makes a lot of troubles,
> and it's better to use the playerendpoint bin.
> Therefore I made an rtsp server, that takes the rtp and transform it to
> rtsp, and only than kurento takes it. 
>
> Not the best thing to do in term of cpu and latency (though it doesn't
> transcode, just forward the packets), but it made the connection quicker
> and fixed the problem that rtpendpoint has to do sdp negotiations.

Thanks for this feedback

The reSIProcate[1] / Kurento integration opens up Kurento to more users,
some may be tempted to contribute improvements to RtpEndpoint (Kurento)
and/or rtpbin[2] (GStreamer)

Are the problems are in RtpEndpoint, rtpbin, or both?

Is this is a case where the code can be improved or where it may be
better to rewrite the code?

If people want to help, what is the best way to contribute?

Regards,

Daniel

1. https://www.resiprocate.org
2. https://gstreamer.freedesktop.org/documentation/rtpmanager/rtpbin.html

[Daniel Pocock]

After the iptables hack, the video stream works for a few minutes but
then fails

Now I see some log entries which I'm happy to share

Before the iptables hack, I didn't see any clues in the log, the video
just didn't work at all.


{"time":"2021-07-19T16:14:42.165978Z","proc!id":"8445","proc!tid":140316237620992,"pname":"/usr/bin/kurento-media-server","appname":"kurento6test","host":"abc","gstreamer!level":2,"pri":"WARN","syslog!level":4,"subsys":"kmsutils","file!name":"kmsutils.c","file!line":504,"native!function":"gap_detection_probe","native!object":"<kmsrtpendpoint0_kmsagnosticbin2-1:sink>
","msg":"GAP of 5 ms at PTS=0:00:26.577505558 (packet loss?); will
request a new keyframe"}

{"time":"2021-07-19T16:14:42.229966Z","proc!id":"8445","proc!tid":140316237620992,"pname":"/usr/bin/kurento-media-server","appname":"kurento6test","host":"abc","gstreamer!level":2,"pri":"WARN","syslog!level":4,"subsys":"kmsutils","file!name":"kmsutils.c","file!line":478,"native!function":"discont_detection_probe","native!object":"<kmsrtpendpoint0_kmsagnosticbin2-1:sink>
","msg":"DISCONTINUITY at non-keyframe; will drop until keyframe"}

{"time":"2021-07-19T16:14:43.944479Z","proc!id":"8445","proc!tid":140317965055744,"pname":"/usr/bin/kurento-media-server","appname":"kurento6test","host":"abc","gstreamer!level":5,"pri":"DEBUG","syslog!level":7,"subsys":"KurentoMediaElementImpl","file!name":"MediaElementImpl.cpp","file!line":565,"native!function":"mediaFlowInStateChange","native!object":"<kmsrtpendpoint0>
","msg":"MediaFlowInStateChange: NOT FLOWING, pad: 'default', type:
'video'"}