[jitsi-dev] [jitsi-videobridge] Missing remote downstream RTP media (audio/video) - Jitsi-Videobridge BUG ???


#1

Hi Boris Grozev,

I have done a comparison between the debug messages captured with jitsi
clients (initiators) logged onto jit.si and my xmpp/videobridge server.
Attached below are the observed differences extracted from the log message:

I have checked all protocol exchanges on the two test cases prior to below
message; they remain identical, in particular the content of
<conference-info/> stanza being sent.
i.e. The no working case does not have any RTCPReporter event being
received. Subsequently I see only the Audio-Graph for audio encoding is
being created. Whereas the good test case have audio-graphs being created
for both the audio encode and decode.

Look like I need to have more in depth understanding of the videobridge
operation to get to the cause.
Any update on my previous questions? Any clarifications will certainly
quicken me in my further investigation.

============= common message captured on jitsi-windows (the initiator)

ยทยทยท

============
2:36.078 FINER: [884] fmj.newInstance() Trying RTPManager class:
org.jitsi.impl.neomedia.jmfext.media.rtp.RTPSessionMgr
[java] 2016-02-13 14:52:36.078 FINE: [884]
org.jitsi.impl.neomedia.AudioMediaStreamImpl.debug() registering format
ALAW/rtp, 8000.0 Hz, 8-bit, Mono, Signed with RTPManager
[java] 2016-02-13 14:52:36.079 FINE: [884]
org.jitsi.impl.neomedia.AudioMediaStreamImpl.debug() registering format
g722/rtp, 8000.0 Hz, Mono with RTPManager
[java] 2016-02-13 14:52:36.079 FINER: [884]
org.jitsi.impl.neomedia.AudioMediaStreamImpl.trace() Set receiver buffer
length to 120
============= message missing on when log to my xmpp/videobridge server

[java] 2016-02-13 14:52:36.174 FINEST: [1252]
net.sf.fmj.media.rtp.RTCPReporter.run() RTCP reporting for running again
after 1613.7116207666998 ms.
[java] 2016-02-13 14:52:36.176 FINER: [1246]
org.jitsi.impl.neomedia.MediaStreamImpl.trace() rtpstat:Received a receiver
report for audio stream SSRC:1646114669 [ ]
[java] 2016-02-13 14:52:36.182 FINER: [1246]
org.jitsi.impl.neomedia.MediaStreamImpl.trace() Received new ReceiveStream
with ssrc 473438189
[java] 2016-02-13 14:52:36.182 INFO: [1249] net.sf.fmj.media.Log.info()
Resetting queue, last seq added: 9223372036854775806, current seq: 14770
[java] 2016-02-13 14:52:36.182 FINE: [1249] net.sf.fmj.media.Log.comment()
Resetting the RTP packet queue
[java] 2016-02-13 14:52:36.182 FINE: [1249] net.sf.fmj.media.Log.comment()
RTP socket receive buffer size: -1 bytes.

Thanks & Regards,

====================================================
Hi,

## My best guess is that the problem stems from the way the jitsi client
configures jitsi-videobridge (over COLIBRI). A good amount of changes
have been introduced since it was last tested or used actively (by our
team).

1. Are you referring the new changes made to jitsi client or videobridge? Or
both?

2. I have also tested the same three jitsi-clients i.e. jitsi-windows,
jitsi-ubuntu and jitsi-android with videobridge on jit.si server. They all
work well with jit.si server, although not 100% of the time.

2a. May I know what version of the jitsi-videobridge is being installed at
jit.si server?

3. I have compared the jitsi-android debug log when logged to jit.si and my
own server. I was not able to detect any major
differences in the protocol exchanges during videobridge setup; except below
debug log differences captured on jitsi-android (not working test case):

Additional Stanza send from abc123 (jvb initiator) to leopard (invitee)

==== Additional stanza received by jitsi-android (prior to encode audio
graph creation process) ========

02-11 14:46:58.823: D/SMACK(20758): RECV (0): <iq
from='abc123 at jvb.example.org
<http://lists.jitsi.org/mailman/listinfo/dev> /jitsi-10skqn1'
to='leopard at jvb.example.org <http://lists.jitsi.org/mailman/listinfo/dev>
/android' id='TXh4D-724' type='set'>

<conference-info xmlns='urn:ietf:params:xml:ns:conference-info'
entity='xmpp:abc123 at jvb.example.org
<http://lists.jitsi.org/mailman/listinfo/dev> /jitsi-10skqn1'
sid='227i1gvlvkvpj'
version='2'>

<conference-description/><conference-state><user-count>2</user-count></confe
rence-state><users>

<user entity='xmpp:abc123 at jvb.example.org
<http://lists.jitsi.org/mailman/listinfo/dev> /jitsi-10skqn1'><endpoint
entity='xmpp:abc123 at jvb.example.org
<http://lists.jitsi.org/mailman/listinfo/dev>
/jitsi-10skqn1'><status>connected</status

<media
id='audio'><src-id>1544483604</src-id><type>audio</type><status>sendrecv</st

</media></endpoint></user>

<user
entity='leopard at jvb.example.org
<http://lists.jitsi.org/mailman/listinfo/dev>
/android'><display-text>leopard at jvb.example.o
<http://lists.jitsi.org/mailman/listinfo/dev>
rg</display-text>

<endpoint
entity='leopard at jvb.example.org
<http://lists.jitsi.org/mailman/listinfo/dev>
/android'><status>connected</status><media
id='audio'><type>audio</type><status>sendrecv</status></media></endpoint></u

</users></conference-info></iq>

=================================

Following is missing from no working test case (as reported in my previous
message).

====== Debug log on android-jitsi (when log onto jit.si server) ============

02-10 14:37:30.355: I/Jitsi(12450): [96] net.sf.fmj.media.Log.info()
Resetting queue, last seq added: 9223372036854775806, current seq: 40105

02-10 14:37:30.355: I/Jitsi(12450): [97] fmj.createProcessor() ### Creating
Processor for DataSource ###:
org.jitsi.impl.neomedia.device.ReceiveStreamPushBufferDataSource at cab9aef
<http://lists.jitsi.org/mailman/listinfo/dev> for
type: raw

==================================

3a. Does the debug log above provide you new insight into the problem?

4. When testing with jitsi-android (jvb initiate not implemented yet), I
always use jitsi-windows as the videobridge initiator.

I will find a way to perform debug log on jitsi-windows, so I can compared
the difference when log to jit.si and own servers.

Will update you on my findings.

Regards,
CM Eng

======================================

On 11/02/16 23:30, cmeng.gm wrote:

Hi Boris Grozev,

After I terminated the videobridge call, I observed the following debug

messages log from JVB.

JVB 2016-02-12 13:16:36.561 INFO: [65]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10004/udp/host -> 92.168.1.100:5001/udp/host (audio.RTCP),
failing.

JVB 2016-02-12 13:16:36.562 INFO: [63]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10003/udp/host -> 192.168.1.100:5000/udp/host (audio.RTP),
failing.

JVB 2016-02-12 13:16:49.041 INFO: [125]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10002/udp/host -> 118.201.189.22:5001/udp/srflx (audio.RTCP),
failing.

JVB 2016-02-12 13:16:49.041 INFO: [124]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10001/udp/host -> 118.201.189.22:5000/udp/srflx (audio.RTP),
failing.

JVB 2016-02-12 13:16:51.557 INFO: [127]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10004/udp/host -> 192.168.1.100:5001/udp/host (audio.RTCP),
failing.

JVB 2016-02-12 13:16:51.558 INFO: [126]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10003/udp/host -> 192.168.1.100:5000/udp/host (audio.RTP),
failing.

JVB 2016-02-12 13:17:04.040 INFO: [63]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10001/udp/host -> 118.201.189.22:5000/udp/srflx (audio.RTP),
failing.

JVB 2016-02-12 13:17:04.041 INFO: [65]

org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for pair:
192.168.1.8:10002/udp/host -> 118.201.189.22:5001/udp/srflx (audio.RTCP),
failing.

Look like JVB was actually sending UDP data out during the active call

session???

It might have been just sending ICE consent checks and no media.

But why none is being observed on wireshark or received by both

jitsi-android and jitsi-windows clients???

My best guess is that the problem stems from the way the jitsi client
configures jitsi-videobridge (over COLIBRI). A good amount of changes
have been introduced since it was last tested or used actively (by our
team).

Regards,

---
This email has been checked for viruses by Avast antivirus software.
https://www.avast.com/antivirus