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


#1

Hi,

After an in depth investigation on the problem, following are my findings:

(Note: timestamp may not teddy with clients and JVB server logs as they are
captured at different day/time;

During investigation, one of the jabberd client is a jitsi-android (self
enhanced version) which provides full xmpp logs and debug messages.

The observed problem also happen on jitsi-windows and jitsi-ubuntu, hence
ruling out jitsi-android as the cause.)

When connected to jit.si server, the jabberd client did received
"ReceiveStreamPushBufferDataSource" from JVB and proceed to setup the full
audio graph

to receiving incoming downstream audio data as seen from the log.

====== log on android-jitsi (log on 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@cab9aef for
type: raw

···

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

However, when connected to my own XMPP/JVB server, there is no downstream
audio received i.e. missing "ReceiveStreamPushBufferDataSource" from JVB.

This leads to the observed problem as it does not procced to setup the
incoming decoding audio graph, and hence there is no audio received on
jitsi-android.

#### Following depict the actual own system setup for investigation:

NAT Port map 10000~20000 for 115.66.221.38 <==> 192.168.1.8 as required
when JVB is behind NAT.

# NAT setting if run behind firewall for sip-communicator.properties

org.jitsi.videobridge.NAT_HARVESTER_LOCAL_ADDRESS=192.168.1.8

org.jitsi.videobridge.NAT_HARVESTER_PUBLIC_ADDRESS=115.66.221.38

192.168.1.8 (XMPP/JVB) < == 115.66.221.38 (Public) <=====> 118.201.189.22
(public) ==> 192.168.1.108 (jitsi-windows)

                                                              >>

192.168.1.100 (jitsi-android) <==

I then proceed to execute JVB under live mode and captured the log message
as below

Following are my conclusion/understanding from the logged messages:

1. Gather candidates for component audio.RTP/RTPC has harvested 2 proposed
candidates for connection (see log).

2. CheckList.handleNominationConfirmed() confirm the selected candidate pair
for RTP/RTCP stream connection

#### Selected pair for stream audio.RTP: 192.168.1.8:10001/udp/host ->
118.201.189.22:5000/udp/srflx (audio.RTP)

#### Selected pair for stream audio.RTCP: 192.168.1.8:10002/udp/host ->
118.201.189.22:5001/udp/srflx (audio.RTCP

3. JVB decides to use remote client local address "192.168.1.108:5000" which
is behind firewall for audio streaming. This leads to timeout (unreachable).

This appears to be the reason why the downstream audio is not sent.

#### timeout for pair: 192.168.1.8:10001/udp/host ->
192.168.1.108:5000/udp/host (audio.RTP), failing.

#### timeout for pair: 192.168.1.8:10001/udp/host ->
115.66.221.38:50002/udp/relay (audio.RTP), failing.

#### timeout for pair: 192.168.1.8:10002/udp/host ->
192.168.1.108:5001/udp/host (audio.RTCP), failing.

#### timeout for pair: 192.168.1.8:10002/udp/host ->
115.66.221.38:50003/udp/relay (audio.RTCP), failing.

3 The timeout will not happen if the selected candidate pairs are being used
for streaming audio.

Why JVB does not use the selected "118.201.189.22:5000" ???

Appreciate if someone can help to clarify my finding or was it my incorrect
interpretation of the log message.

Regards,

CM Eng

============ JVB captured log message =================

JVB 2016-02-12 09:51:17.242 INFO: [51]
org.jitsi.videobridge.HarvesterConfiguration.checkConfig() Will append a NAT
harvester for 192.168.1.8:9/udp=>115.66.221.38:9/udp

JVB 2016-02-12 09:51:17.249 INFO: [51]
org.ice4j.ice.Agent.gatherCandidates() Gather candidates for component
audio.RTP

JVB 2016-02-12 09:51:17.270 INFO: [51] org.ice4j.ice.Agent.createComponent()
192.168.1.8:10001/udp (host)

JVB 2016-02-12 09:51:17.270 INFO: [51] org.ice4j.ice.Agent.createComponent()
115.66.221.38:10001/udp (srflx)

JVB 2016-02-12 09:51:17.270 INFO: [51]
org.ice4j.ice.Agent.gatherCandidates() Gather candidates for component
audio.RTCP

JVB 2016-02-12 09:51:17.272 INFO: [51] org.ice4j.ice.Agent.createComponent()
192.168.1.8:10002/udp (host)

JVB 2016-02-12 09:51:17.273 INFO: [51] org.ice4j.ice.Agent.createComponent()
115.66.221.38:10002/udp (srflx)

..

JVB 2016-02-12 09:51:18.757 INFO: [77]
org.ice4j.ice.Agent.incomingCheckReceived() Received check from
192.168.1.8:10001/udp/host -> 118.201.189.22:5000/udp/prflx (audio.RTP)
triggered a check

JVB 2016-02-12 09:51:18.771 INFO: [77]
org.ice4j.ice.ConnectivityCheckClient.processSuccessResponse() Pair
succeeded: 192.168.1.8:10001/udp/host -> 118.201.189.22:5000/udp/srflx
(audio.RTP)

JVB 2016-02-12 09:51:18.772 INFO: [77]
org.ice4j.ice.ConnectivityCheckClient.processSuccessResponse() Pair
validated: 115.66.221.38:10001/udp/srflx -> 118.201.189.22:5000/udp/srflx
(audio.RTP)

JVB 2016-02-12 09:51:18.774 INFO: [77]
org.ice4j.ice.ConnectivityCheckClient.processSuccessResponse()
IsControlling: false USE-CANDIDATE:false

JVB 2016-02-12 09:51:18.779 INFO: [77]
org.ice4j.ice.Agent.incomingCheckReceived() Received check from
192.168.1.8:10001/udp/host -> 118.201.189.22:5000/udp/prflx (audio.RTP)
triggered a check

JVB 2016-02-12 09:51:18.780 INFO: [77]
org.ice4j.ice.CheckList.handleNominationConfirmed() #### Selected pair for
stream audio.RTP: 192.168.1.8:10001/udp/host ->
118.201.189.22:5000/udp/srflx (audio.RTP)

JVB 2016-02-12 09:51:18.812 INFO: [77]
org.ice4j.ice.Agent.incomingCheckReceived() Received check from
192.168.1.8:10002/udp/host -> 118.201.189.22:5001/udp/prflx (audio.RTCP)
triggered a check

JVB 2016-02-12 09:51:18.831 INFO: [77]
org.ice4j.ice.ConnectivityCheckClient.processSuccessResponse() Pair
succeeded: 192.168.1.8:10002/udp/host -> 118.201.189.22:5001/udp/srflx
(audio.RTCP)

JVB 2016-02-12 09:51:18.832 INFO: [77]
org.ice4j.ice.ConnectivityCheckClient.processSuccessResponse() Pair
validated: 115.66.221.38:10002/udp/srflx -> 118.201.189.22:5001/udp/srflx
(audio.RTCP)

JVB 2016-02-12 09:51:18.832 INFO: [77]
org.ice4j.ice.ConnectivityCheckClient.processSuccessResponse()
IsControlling: false USE-CANDIDATE:false

JVB 2016-02-12 09:51:18.842 INFO: [77]
org.ice4j.ice.Agent.incomingCheckReceived() Received check from
192.168.1.8:10002/udp/host -> 118.201.189.22:5001/udp/prflx (audio.RTCP)
triggered a check

JVB 2016-02-12 09:51:18.842 INFO: [77]
org.ice4j.ice.CheckList.handleNominationConfirmed() #### Selected pair for
stream audio.RTCP: 192.168.1.8:10002/udp/host ->
118.201.189.22:5001/udp/srflx (audio.RTCP)

..

JVB 2016-02-12 09:51:24.148 INFO: [59]
org.jitsi.videobridge.xmpp.ComponentImpl.info() RECV: <iq
from="swan@atalk.org/jitsi-nm7ip5" to="jitsi-videobridge.atalk.org"
id="7mKa6-1" type="result"/>

JVB 2016-02-12 09:51:24.148 INFO: [57]
org.jitsi.videobridge.xmpp.ComponentImpl.info() RECV: <iq
from="swan@atalk.org/jitsi-nm7ip5" to="jitsi-videobridge.atalk.org"
id="7mKa6-0" type="result"/>

JVB 2016-02-12 09:51:24.697 INFO: [85]
org.ice4j.ice.ConnectivityCheckClient.processTimeout() #### timeout for
pair: 192.168.1.8:10001/udp/host -> 192.168.1.108:5000/udp/host (audio.RTP),
failing.

JVB 2016-02-12 09:51:24.741 INFO: [87]
org.ice4j.ice.ConnectivityCheckClient.processTimeout() #### timeout for
pair: 192.168.1.8:10001/udp/host -> 115.66.221.38:50002/udp/relay
(audio.RTP), failing.

JVB 2016-02-12 09:51:24.759 INFO: [88]
org.ice4j.ice.ConnectivityCheckClient.processTimeout() #### timeout for
pair: 192.168.1.8:10002/udp/host -> 192.168.1.108:5001/udp/host
(audio.RTCP), failing.

JVB 2016-02-12 09:51:24.819 INFO: [90]
org.ice4j.ice.ConnectivityCheckClient.processTimeout() #### timeout for
pair: 192.168.1.8:10002/udp/host -> 115.66.221.38:50003/udp/relay
(audio.RTCP), failing.

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

======================== previous attached mail

This is the follow up question to the earlier problem that I have
experienced.

i.e. <http://lists.jitsi.org/pipermail/dev/2016-February/026743.html>
[jitsi-dev] [jitsi-videobridge] JVB downstream RTP/RTCP link Setup
implementation

After some effort, I have managed to get the jitsi-meet installation on my
server setup fully working. see

<http://lists.jitsi.org/pipermail/dev/2016-February/026761.html>
[jitsi-dev] [jitsi-meet] Error message: Conference Focus - focus.xxx.com not
available (Resolved)

At least this has verified my jitsi-videobridge installation is ok.

However I am still facing the same problem with the jitsi-client (on windows
7 / Ubuntu 14.04) when launch from client windows [Tools | Create a video
bridge .] to start a videobridge connection. Both the local audio/video are
working, but I am still unable to get the remote downstream audio/video
working i.e. missing.

For test, I created two test xmpp accounts on jit.si server, the option
[Tools | Create a video bridge .] is working, although it did sometimes
failed on receiving remote video media.

Have anybody try the [Tools | Create a video bridge .] and is working fine.

OR facing the same problem as me on their own server.

Any help is appreciated.

Regards,

CM Eng

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


#2

What makes you think that it uses this address? Do you see it sending media to it?

Initially, checks are sent for all pairs. The fact that some of them timeout does not mean that they are used. On the contrary, because checks sent from them timed out, they are considered failed and will *not* be used.

Regards,
Boris

···

On 11/02/16 21:18, cmeng.gm wrote:

Hi,

After an in depth investigation on the problem, following are my findings:

(Note: timestamp may not teddy with clients and JVB server logs as they
are captured at different day/time;

During investigation, one of the jabberd client is a jitsi-android
(self enhanced version) which provides full xmpp logs and debug messages.

The observed problem also happen on jitsi-windows and jitsi-ubuntu,
hence ruling out jitsi-android as the cause.)

When connected to jit.si server, the jabberd client did received
“ReceiveStreamPushBufferDataSource” from JVB and proceed to setup the
full audio graph

to receiving incoming downstream audio data as seen from the log.

====== log on android-jitsi (log on 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@cab9aef
for type: raw

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

However, when connected to my own XMPP/JVB server, there is no
downstream audio received i.e. missing
“ReceiveStreamPushBufferDataSource” from JVB.

This leads to the observed problem as it does not procced to setup the
incoming decoding audio graph, and hence there is no audio received on
jitsi-android.

#### Following depict the actual own system setup for investigation:

NAT Port map 10000~20000 for 115.66.221.38 <==> 192.168.1.8 as required
when JVB is behind NAT.

# NAT setting if run behind firewall for sip-communicator.properties

org.jitsi.videobridge.NAT_HARVESTER_LOCAL_ADDRESS=192.168.1.8

org.jitsi.videobridge.NAT_HARVESTER_PUBLIC_ADDRESS=115.66.221.38

192.168.1.8 (XMPP/JVB) < == 115.66.221.38 (Public) <=====>
118.201.189.22 (public) ==> 192.168.1.108 (jitsi-windows)

                                                               >>

192.168.1.100 (jitsi-android) <==

I then proceed to execute JVB under live mode and captured the log
message as below

Following are my conclusion/understanding from the logged messages:

1. Gather candidates for component audio.RTP/RTPC has harvested 2
proposed candidates for connection (see log).

2. CheckList.handleNominationConfirmed() confirm the selected candidate
pair for RTP/RTCP stream connection

#### Selected pair for stream audio.RTP: 192.168.1.8:10001/udp/host ->
118.201.189.22:5000/udp/srflx (audio.RTP)

#### Selected pair for stream audio.RTCP: 192.168.1.8:10002/udp/host ->
118.201.189.22:5001/udp/srflx (audio.RTCP

3. JVB decides to use remote client local address “192.168.1.108:5000”
which is behind firewall for audio streaming. This leads to timeout
(unreachable).