[jitsi-dev] [jitsi-videobridge] JVB downstream RTP/RTCP link Setup implementation


#1

Following is the system setup, all systems (DHCP IP addresses) are behind
firewall with public address 115.68.221.39.

a. Ubuntu (192.168.1.28) - with ejabberd xmpp server & jitsi-videobridge
installed

b. Ubuntu (192.168.1.28) - with jitsi-ubuntu (v 2.9.5488) installed

c. Windows 7 #1 (192.168.1.16) - with jitsi-windows v2.9.5489 installed

d. Windows 7 #2 (192.168.1.12) - with jitsi-windows v2.9.5488 installed

e. Android Note3 (192.168.1.6) - installed with jitsi-android (self ported
with feature-enhanced version)

During my initial system setup, I was able to perform a full 4-parties video
conferencing via jitsi-videobridge; however there was problem on downstream
audio RTP/RTCP routing. (See attached image - some with no remote audio
activity).

Then I proceed to add jitst-meet; tested working up to the point where it
fails, in attempt to attached/create "jitsimeet" conference room. After
this, I went back to recheck the video conference feature, I found that it
is no more working for both audio/video downstream streaming from
jitsi-videobridge. The problem remains even after I uninstalled jicofo
plugin.

With only the jitsi-videobridge running, I decided to trace the debug
message with running the jitsi-videobrige on a terminal; following is an
extraction of the jitsi-videobridge (jvb) debug messages. For the purpose of
debugging, only a 2-parties conference is being setup between Ubuntu
(192.168.1.28) - calling JID: jitsi-ubuntu and android (192.168.1.6) -
called JID: jitsi-android. The debug message is tagged with my understanding
and comments prefix with "### cmeng"

From debug log, I see that jvb has successfully establish all the upstream

audio RTP/RTCP links to both the calling JID: jitsi-ubuntu and called JID:
jitsi-android .

However jvb failed (see debug log) on:

### cmeng ?#01 - jvb tries to gather/establish downstream link to calling
party (jitsi-ubuntu)? Failed as it is blocked by firewall - timetolive?

Jan 19, 2016 8:44:12 AM org.ice4j.ice.ConnectivityCheckClient processTimeout

INFO: timeout for pair: 192.168.1.28:10001/udp/host ->
115.68.221.39:5000/udp/srflx (audio.RTP), failing.

Note: The same problem exists in any combination of the video conferencing
setup with the system setup above.

I derived that jvb is making a downstream audio link based on the remote
<candidates /> offered when the VB conference is first initiated

Hope the jitsi-videobrige team can help to clarify the following:

1. Why jvb is making an attempt to establish a link to a JID client behind
a firewall? I would expect such attempt will fail as it is blocked by the
client firewall; I see that this port is not opened from the earlier debug
traces and there is no time-to-live period available for jvb to make
connection. Note: I would expect the problem still exist even jvb is not
behind firewall.

INFO: Add remote candidate for audio.RTP: 115.68.221.39:5000/udp/srflx

2. Is it possible to let jvb to send IQ request to get the jitsi-ubuntu to
perform the reverse link check, so it will open up the firewall port for jvb
audio downstream connection?

3. Why jvb did not attempt to use the preferred <candidate /> first as it
has higher priorty.
INFO: Add remote candidate for audio.RTP: 192.168.1.28:34125/udp/host

4. Anything else that I can do to made the jvb working again?

Please correct me if I have misinterpret the debug message.

The exact same problem happen when jid client attempts to add-content for
video call.

Regards,

CM Eng

====== jvb debug message =========

Jan 19, 2016 8:43:57 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="talk.org" to="jitsi-videobridge.talk.org"
id="4hu0E-124" type="result"/>

### cmeng - calling JID (jitsi-ubuntu) initiate a VB conference call with
colibri protocol

Jan 19, 2016 8:44:04 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="cmeng@talk.org/jitsi-1di9e4s"
to="jitsi-videobridge.talk.org" id="ThX94-26" type="get"><conference
xmlns="http://jitsi.org/protocol/colibri"><content name="audio">

<channel endpoint="cmeng@talk.org/jitsi-1di9e4s"
initiator="false"><payload-type id="96" name="opus" channels="2"
clockrate="48000"><parameter name="usedtx"
value="1"/></payload-type><payload-type id="97" name="SILK" channels="1"
clockrate="24000"/><payload-type id="98" name="SILK" channels="1"
clockrate="16000"/><payload-type id="9" name="G722" channels="1"
clockrate="8000"/><payload-type id="100" name="speex" channels="1"
clockrate="32000"/><payload-type id="102" name="speex" channels="1"
clockrate="16000"/><payload-type id="0" name="PCMU" channels="1"
clockrate="8000"/><payload-type id="8" name="PCMA" channels="1"
clockrate="8000"/><payload-type id="103" name="iLBC" channels="1"
clockrate="8000"/><payload-type id="3" name="GSM" channels="1"
clockrate="8000"/><payload-type id="104" name="speex" channels="1"
clockrate="8000"/><payload-type id="101" name="telephone-event" channels="1"
clockrate="8000"/><transport xmlns="urn:xmpp:jingle:transports:ice-udp:1"
ufrag="9b8i1a9bld870" pwd="6i7iuusid9i46q28rds875bhdn">

<candidate foundation="1" component="1" protocol="udp" priority="2130706431"
generation="0" id="1" ip="fe80:0:0:0:2e0:6fff:fe29:6b6f" port="5000"
type="host" network="0"/>

<candidate foundation="2" component="1" protocol="udp" priority="2130706431"
generation="0" id="2" ip="192.168.1.28" port="5000" type="host"
network="0"/>

<candidate foundation="2" component="1" protocol="udp" priority="2113932031"
generation="0" id="3" ip="192.168.1.28" port="34125" type="host"
network="0"/>

<candidate foundation="3" component="1" protocol="udp" priority="1677724415"
generation="0" id="4" ip="115.68.221.39" port="5000" type="srflx"
rel-addr="192.168.1.28" rel-port="5000" network="0"/>

<candidate foundation="5" component="1" protocol="udp" priority="1677724415"
generation="0" id="5" ip="115.68.221.39" port="34125" type="srflx"
rel-addr="192.168.1.28" rel-port="34125" network="0"/>

<candidate foundation="4" component="1" protocol="udp" priority="2815"
generation="0" id="6" ip="115.68.221.39" port="50002" type="relay"
network="0"/>

<candidate foundation="1" component="2" protocol="udp" priority="2130706430"
generation="0" id="7" ip="fe80:0:0:0:2e0:6fff:fe29:6b6f" port="5001"
type="host" network="0"/>

<candidate foundation="2" component="2" protocol="udp" priority="2130706430"
generation="0" id="8" ip="192.168.1.28" port="5001" type="host"
network="0"/>

<candidate foundation="2" component="2" protocol="udp" priority="2113932030"
generation="0" id="9" ip="192.168.1.28" port="44592" type="host"
network="0"/>

<candidate foundation="3" component="2" protocol="udp" priority="1677724414"
generation="0" id="10" ip="115.68.221.39" port="5001" type="srflx"
rel-addr="192.168.1.28" rel-port="5001" network="0"/>

<candidate foundation="5" component="2" protocol="udp" priority="1677724414"
generation="0" id="11" ip="115.68.221.39" port="44592" type="srflx"
rel-addr="192.168.1.28" rel-port="44592" network="0"/>

<candidate foundation="4" component="2" protocol="udp" priority="2814"
generation="0" id="12" ip="115.68.221.39" port="50003" type="relay"
network="0"/>

</transport></channel><channel endpoint="leopard@talk.org/talk"
initiator="true"><payload-type id="96" name="opus" channels="2"
clockrate="48000"><parameter name="usedtx"
value="1"/></payload-type><payload-type id="97" name="SILK" channels="1"
clockrate="24000"/><payload-type id="98" name="SILK" channels="1"
clockrate="16000"/><payload-type id="9" name="G722" channels="1"
clockrate="8000"/><payload-type id="100" name="speex" channels="1"
clockrate="32000"/><payload-type id="102" name="speex" channels="1"
clockrate="16000"/><payload-type id="0" name="PCMU" channels="1"
clockrate="8000"/><payload-type id="8" name="PCMA" channels="1"
clockrate="8000"/><payload-type id="103" name="iLBC" channels="1"
clockrate="8000"/><payload-type id="3" name="GSM" channels="1"
clockrate="8000"/><payload-type id="104" name="speex" channels="1"
clockrate="8000"/><payload-type id="101" name="telephone-event" channels="1"
clockrate="8000"/><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"/></channel></content></conferen

</iq>

Jan 19, 2016 8:44:04 AM org.jitsi.util.Logger info

INFO: Created conference 4b5b99ec8c430e98. The total number of conferences
is now 1, channels 0, video streams 0.

Jan 19, 2016 8:44:04 AM org.jitsi.util.Logger info

INFO: Created content audio of conference 4b5b99ec8c430e98. The total number
of conferences is now 1, channels 0, video streams 0.

Jan 19, 2016 8:44:05 AM org.ice4j.ice.Agent gatherCandidates

INFO: Gather candidates for component audio.RTP

Jan 19, 2016 8:44:05 AM org.ice4j.ice.Agent createComponent

INFO: 192.168.1.28:10001/udp (host)

Jan 19, 2016 8:44:05 AM org.ice4j.ice.Agent gatherCandidates

INFO: Gather candidates for component audio.RTCP

Jan 19, 2016 8:44:05 AM org.ice4j.ice.Agent createComponent

INFO: 192.168.1.28:10002/udp (host)

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: Created channel 61e0117da96613b of content audio of conference
4b5b99ec8c430e98. The total number of conferences is now 1, channels 1,
video streams 1.

### cmeng - jvb adds all received remote candidates from calling JID
(jitsi-ubuntu) to its database

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTP: 192.168.1.28:5000/udp/host

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTP: 192.168.1.28:34125/udp/host

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTCP: 192.168.1.28:5001/udp/host

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTCP: 192.168.1.28:44592/udp/host

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTP: 115.68.221.39:5000/udp/srflx

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTP: 115.68.221.39:34125/udp/srflx

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTCP: 115.68.221.39:5001/udp/srflx

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTCP: 115.68.221.39:44592/udp/srflx

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTP: 115.68.221.39:50002/udp/relay

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTCP: 115.68.221.39:50003/udp/relay

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent startConnectivityEstablishment

INFO: Start ICE connectivity establishment

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent initCheckLists

INFO: Init checklist for stream audio

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent setState

INFO: ICE state changed from Waiting to Running

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: ICE processing state of IceUdpTransportManager #14e50583 (for channels
61e0117da96613b) of conference 4b5b99ec8c430e98 changed from Waiting to
Running.

### cmeng - jvb checks for validity of the received remote candidates from
calling JID (jitsi-ubuntu)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient startChecks

INFO: Start connectivity checks!

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10001/udp/host ->
192.168.1.28:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 192.168.1.28:10001/udp/host ->
192.168.1.28:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: false USE-CANDIDATE:false

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10002/udp/host ->
192.168.1.28:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 192.168.1.28:10002/udp/host ->
192.168.1.28:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: false USE-CANDIDATE:false

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10001/udp/host ->
192.168.1.28:34125/udp/host (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 192.168.1.28:10001/udp/host ->
192.168.1.28:34125/udp/host (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: false USE-CANDIDATE:false

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10002/udp/host ->
192.168.1.28:44592/udp/host (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 192.168.1.28:10002/udp/host ->
192.168.1.28:44592/udp/host (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: false USE-CANDIDATE:false

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Receive a peer-reflexive candidate: 115.68.221.39:10001/udp

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10001/udp/host ->
115.68.221.39:34125/udp/srflx (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 115.68.221.39:10001/udp/prflx ->
115.68.221.39:34125/udp/srflx (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: false USE-CANDIDATE:false

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Receive a peer-reflexive candidate: 115.68.221.39:10002/udp

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10002/udp/host ->
115.68.221.39:44592/udp/srflx (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 115.68.221.39:10002/udp/prflx ->
115.68.221.39:44592/udp/srflx (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: false USE-CANDIDATE:false

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent gatherCandidates

INFO: Gather candidates for component audio.RTP

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent createComponent

INFO: 192.168.1.28:10003/udp (host)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent gatherCandidates

INFO: Gather candidates for component audio.RTCP

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent createComponent

INFO: 192.168.1.28:10004/udp (host)

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: Created channel 3d127fe0b74f1909 of content audio of conference
4b5b99ec8c430e98. The total number of conferences is now 1, channels 2,
video streams 2.

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

### cmeng - jvb reverses the candidates checked results to the calling JID
and offer validated candidates for use. It provides also the upstream
candidates for called JID (jitsi-android)for relay by calling JID
(jitsi-ubuntu)

INFO: SENT: <iq id="ThX94-26" to="cmeng@talk.org/jitsi-1di9e4s"
from="jitsi-videobridge.talk.org" type="result"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio">

<channel endpoint="cmeng@talk.org/jitsi-1di9e4s" expire="60"
id="61e0117da96613b" initiator="false"
rtp-level-relay-type="translator"><source
xmlns="urn:xmpp:jingle:apps:rtp:ssma:0"
ssrc="3284190498"></source><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"
pwd="3qtpbvf291lql8humem7i76jqg" ufrag="5hmgb1a9bldc5b"><fingerprint
xmlns="urn:xmpp:jingle:apps:dtls:0"
hash="sha-1">64:C9:92:9C:C3:33:0F:E6:5D:DE:18:BA:0A:3A:5D:1D:19:D7:D7:71</fi

<candidate component="1" foundation="1" generation="0"
id="4b5b99ec8c430e9814e5058323ea9d6302e101" network="0"
priority="2130706431" protocol="udp" type="host" ip="192.168.1.28"
port="10001"/>

<candidate component="2" foundation="1" generation="0"
id="4b5b99ec8c430e9814e5058323ea9d63038ab3c51" network="0"
priority="2130706430" protocol="udp" type="host" ip="192.168.1.28"
port="10002"/>

</transport></channel>

<channel endpoint="leopard@talk.org/talk" expire="60" id="3d127fe0b74f1909"
initiator="true" rtp-level-relay-type="translator"><source
xmlns="urn:xmpp:jingle:apps:rtp:ssma:0"
ssrc="3284190498"></source><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"
pwd="69jg8psna9fmq3gs4lpb61lt1d" ufrag="5k13d1a9blddfu"><fingerprint
xmlns="urn:xmpp:jingle:apps:dtls:0"
hash="sha-1">DC:33:E7:DB:5F:EC:E1:90:14:27:B5:F9:DE:A5:CA:A5:56:90:1E:B6</fi

<candidate component="1" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a03091e5b0" network="0"
priority="2130706431" protocol="udp" type="host" ip="192.168.1.28"
port="10003"/>

<candidate component="2" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a04ee6a1af" network="0"
priority="2130706430" protocol="udp" type="host" ip="192.168.1.28"
port="10004"/></transport></channel></content></conference></iq>

### cmeng - calling JID (jitsi-ubuntu) does a validation and make final
selection of the received candidates from jvb for upstream RTP/RTCP links

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10001/udp/host ->
192.168.1.28:5000/udp/prflx (audio.RTP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10002/udp/host ->
192.168.1.28:5001/udp/prflx (audio.RTCP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10001/udp/host ->
192.168.1.28:34125/udp/prflx (audio.RTP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10002/udp/host ->
192.168.1.28:44592/udp/prflx (audio.RTCP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10001/udp/host ->
115.68.221.39:34125/udp/prflx (audio.RTP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10002/udp/host ->
115.68.221.39:44592/udp/prflx (audio.RTCP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10001/udp/host ->
192.168.1.28:5000/udp/prflx (audio.RTP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.CheckList handleNominationConfirmed

#### INFO: Selected pair for stream audio.RTP: 192.168.1.28:10001/udp/host
-> 192.168.1.28:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10002/udp/host ->
192.168.1.28:5001/udp/prflx (audio.RTCP) triggered a check

Jan 19, 2016 8:44:06 AM org.ice4j.ice.CheckList handleNominationConfirmed

#### INFO: Selected pair for stream audio.RTCP: 192.168.1.28:10002/udp/host
-> 192.168.1.28:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent checkListStatesUpdated

INFO: CheckList of stream audio is COMPLETED

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent setState

INFO: ICE state changed from Running to Completed

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: ICE processing state of IceUdpTransportManager #14e50583 (for channels
61e0117da96613b) of conference 4b5b99ec8c430e98 changed from Running to
Completed.

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent logCandTypes

INFO: Harvester used for selected pair for audio.RTP: host

Jan 19, 2016 8:44:06 AM org.ice4j.ice.Agent logCandTypes

INFO: Harvester used for selected pair for audio.RTCP: host

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: Transport connected for channel 61e0117da96613b of content audio of
conference 4b5b99ec8c430e98

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: audio codec/freq: null/null Hz

Jan 19, 2016 8:44:06 AM org.jitsi.util.Logger info

INFO: audio remote IP/port: 192.168.1.28/5000

Jan 19, 2016 8:44:07 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="talk.org" to="jitsi-videobridge.talk.org"
id="4hu0E-125" type="result"/>

### cmeng - calling JID (jitsi-ubuntu) update JVB about its called JID
(jitsi-android) and its candidates for use

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="cmeng@talk.org/jitsi-1di9e4s"
to="jitsi-videobridge.talk.org" id="ThX94-28" type="set"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio"><channel id="3d127fe0b74f1909" initiator="true"><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1" ufrag="7gmf5"
pwd="29cuk28k14f7rjbk6tbnjdm065">

<candidate foundation="1" component="1" protocol="udp" priority="2130706431"
generation="0" id="1" ip="fe80::f025:b7ff:fe9c:3c5" port="5000" type="host"
network="0"/>

<candidate foundation="2" component="1" protocol="udp" priority="2130706431"
generation="0" id="2" ip="fe80::f225:b7ff:fe9c:3c5" port="5000" type="host"
network="0"/>

<candidate foundation="3" component="1" protocol="udp" priority="2113932031"
generation="0" id="3" ip="192.168.1.6" port="5000" type="host" network="0"/>

<candidate foundation="1" component="2" protocol="udp" priority="2130706430"
generation="0" id="4" ip="fe80::f025:b7ff:fe9c:3c5" port="5001" type="host"
network="0"/>

<candidate foundation="2" component="2" protocol="udp" priority="2130706430"
generation="0" id="5" ip="fe80::f225:b7ff:fe9c:3c5" port="5001" type="host"
network="0"/>

<candidate foundation="3" component="2" protocol="udp" priority="2113932030"
generation="0" id="6" ip="192.168.1.6" port="5001" type="host" network="0"/>

</transport></channel></content></conference></iq>

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTP: 192.168.1.6:5000/udp/host

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Component addRemoteCandidate

INFO: Add remote candidate for audio.RTCP: 192.168.1.6:5001/udp/host

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent startConnectivityEstablishment

INFO: Start ICE connectivity establishment

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent initCheckLists

INFO: Init checklist for stream audio

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent setState

INFO: ICE state changed from Waiting to Running

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: ICE processing state of IceUdpTransportManager #44465d15 (for channels
3d127fe0b74f1909) of conference 4b5b99ec8c430e98 changed from Waiting to
Running.

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient startChecks

INFO: Start connectivity checks!

### cmeng - jvb reverse with its proposed candidates for upstream link with
the called JID (jitsi-android); Note: info is to be relayed to called jid by
calling jid

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: SENT: <iq id="ThX94-28" to="cmeng@talk.org/jitsi-1di9e4s"
from="jitsi-videobridge.talk.org" type="result"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio">

<channel endpoint="leopard@talk.org/talk" expire="60" id="3d127fe0b74f1909"
initiator="true" rtp-level-relay-type="translator"><source
xmlns="urn:xmpp:jingle:apps:rtp:ssma:0"
ssrc="3284190498"></source><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"
pwd="69jg8psna9fmq3gs4lpb61lt1d" ufrag="5k13d1a9blddfu"><fingerprint
xmlns="urn:xmpp:jingle:apps:dtls:0"
hash="sha-1">DC:33:E7:DB:5F:EC:E1:90:14:27:B5:F9:DE:A5:CA:A5:56:90:1E:B6</fi

<candidate component="1" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a03091e5b0" network="0"
priority="2130706431" protocol="udp" type="host" ip="192.168.1.28"
port="10003"/>

<candidate component="2" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a04ee6a1af" network="0"
priority="2130706430" protocol="udp" type="host" ip="192.168.1.28"
port="10004"/>

</transport></channel></content></conference></iq>

### cmeng - called JID jitsi-android doing an upstream candidates (info
relayed by calling JID) checking and making selection

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/prflx (audio.RTP) triggered a check

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.DefaultNominator
strategyNominateFirstValid

INFO: Nominate (first valid): 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: true USE-CANDIDATE:false

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent nominate

INFO: verify if nominated pair answer again

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/prflx (audio.RTCP) triggered a check

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: true USE-CANDIDATE:false

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair validated: 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.DefaultNominator
strategyNominateFirstValid

INFO: Nominate (first valid): 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent nominate

INFO: verify if nominated pair answer again

### cmeng - link check successfully. android selected the candidates

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: true USE-CANDIDATE:false

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent incomingCheckReceived

INFO: Received check from 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/prflx (audio.RTCP) triggered a check

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: true USE-CANDIDATE:true

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Nomination confirmed for pair: 192.168.1.28:10003/udp/host ->
192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.CheckList handleNominationConfirmed

#### INFO: Selected pair for stream audio.RTP: 192.168.1.28:10003/udp/host
-> 192.168.1.6:5000/udp/host (audio.RTP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Pair succeeded: 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: IsControlling: true USE-CANDIDATE:true

Jan 19, 2016 8:44:08 AM org.ice4j.ice.ConnectivityCheckClient
processSuccessResponse

INFO: Nomination confirmed for pair: 192.168.1.28:10004/udp/host ->
192.168.1.6:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.CheckList handleNominationConfirmed

#### INFO: Selected pair for stream audio.RTCP: 192.168.1.28:10004/udp/host
-> 192.168.1.6:5001/udp/host (audio.RTCP)

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent checkListStatesUpdated

INFO: CheckList of stream audio is COMPLETED

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent setState

INFO: ICE state changed from Running to Completed

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: ICE processing state of IceUdpTransportManager #44465d15 (for channels
3d127fe0b74f1909) of conference 4b5b99ec8c430e98 changed from Running to
Completed.

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent logCandTypes

INFO: Harvester used for selected pair for audio.RTP: host

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: Transport connected for channel 3d127fe0b74f1909 of content audio of
conference 4b5b99ec8c430e98

Jan 19, 2016 8:44:08 AM org.ice4j.ice.Agent logCandTypes

INFO: Harvester used for selected pair for audio.RTCP: host

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: audio codec/freq: null/null Hz

Jan 19, 2016 8:44:08 AM org.jitsi.util.Logger info

INFO: audio remote IP/port: 192.168.1.6/5000

Jan 19, 2016 8:44:09 AM org.ice4j.ice.Agent setState

INFO: ICE state changed from Completed to Terminated

Jan 19, 2016 8:44:09 AM org.jitsi.util.Logger info

INFO: ICE processing state of IceUdpTransportManager #14e50583 (for channels
61e0117da96613b) of conference 4b5b99ec8c430e98 changed from Completed to
Terminated.

### cmeng - both upstream links from calling(jitsi-ubuntu) and called JID
(jitsi-android) established up to this point

Jan 19, 2016 8:44:10 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="cmeng@talk.org/jitsi-1di9e4s"
to="jitsi-videobridge.talk.org" id="ThX94-30" type="set"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio"><channel id="3d127fe0b74f1909" initiator="true"><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"/></channel></content></conferen

</iq>

Jan 19, 2016 8:44:10 AM org.jitsi.util.Logger info

### cmeng - jvb send updated info on upstrem (RTP/RTCP) links for both jid
to calling JID.

INFO: SENT: <iq id="ThX94-30" to="cmeng@talk.org/jitsi-1di9e4s"
from="jitsi-videobridge.talk.org" type="result"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio">

<channel endpoint="leopard@talk.org/talk" expire="60" id="3d127fe0b74f1909"
initiator="true" rtp-level-relay-type="translator"><source
xmlns="urn:xmpp:jingle:apps:rtp:ssma:0"
ssrc="3284190498"></source><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"
pwd="69jg8psna9fmq3gs4lpb61lt1d" ufrag="5k13d1a9blddfu"><fingerprint
xmlns="urn:xmpp:jingle:apps:dtls:0"
hash="sha-1">DC:33:E7:DB:5F:EC:E1:90:14:27:B5:F9:DE:A5:CA:A5:56:90:1E:B6</fi

<candidate component="1" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a03091e5b0" network="0"
priority="2130706431" protocol="udp" type="host" ip="192.168.1.28"
port="10003"/>

<candidate component="2" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a04ee6a1af" network="0"
priority="2130706430" protocol="udp" type="host" ip="192.168.1.28"
port="10004"/>

</transport></channel></content></conference></iq>

### cmeng - jvb reverses to the called jid (jitsi-android) on the final
candidates for upstream use

Jan 19, 2016 8:44:11 AM org.jitsi.util.Logger info

INFO: SENT: <iq id="4hu0E-126" to="cmeng@talk.org/jitsi-1di9e4s"
from="jitsi-videobridge.talk.org" type="set"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio">

<channel endpoint="leopard@talk.org/talk" expire="60" id="3d127fe0b74f1909"
initiator="true" rtp-level-relay-type="translator"><source
xmlns="urn:xmpp:jingle:apps:rtp:ssma:0"
ssrc="3284190498"></source><ssrc>913140225</ssrc><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"
pwd="69jg8psna9fmq3gs4lpb61lt1d" ufrag="5k13d1a9blddfu"><fingerprint
xmlns="urn:xmpp:jingle:apps:dtls:0"
hash="sha-1">DC:33:E7:DB:5F:EC:E1:90:14:27:B5:F9:DE:A5:CA:A5:56:90:1E:B6</fi

<candidate component="1" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a03091e5b0" network="0"
priority="2130706431" protocol="udp" type="host" ip="192.168.1.28"
port="10003"/>

<candidate component="2" foundation="1" generation="0"
id="4b5b99ec8c430e9844465d1512f7671a04ee6a1af" network="0"
priority="2130706430" protocol="udp" type="host" ip="192.168.1.28"
port="10004"/>

</transport></channel></content></conference></iq>

Jan 19, 2016 8:44:11 AM org.jitsi.util.Logger info

INFO: SENT: <iq id="4hu0E-127" to="cmeng@talk.org/jitsi-1di9e4s"
from="jitsi-videobridge.talk.org" type="set"><conference
xmlns="http://jitsi.org/protocol/colibri" id="4b5b99ec8c430e98"><content
name="audio">

<channel endpoint="cmeng@talk.org/jitsi-1di9e4s" expire="60"
id="61e0117da96613b" initiator="false"
rtp-level-relay-type="translator"><source
xmlns="urn:xmpp:jingle:apps:rtp:ssma:0"
ssrc="3284190498"></source><ssrc>732674844</ssrc><transport
xmlns="urn:xmpp:jingle:transports:ice-udp:1"
pwd="3qtpbvf291lql8humem7i76jqg" ufrag="5hmgb1a9bldc5b"><fingerprint
xmlns="urn:xmpp:jingle:apps:dtls:0"
hash="sha-1">64:C9:92:9C:C3:33:0F:E6:5D:DE:18:BA:0A:3A:5D:1D:19:D7:D7:71</fi

<candidate component="1" foundation="1" generation="0"
id="4b5b99ec8c430e9814e5058323ea9d6302e101" network="0"
priority="2130706431" protocol="udp" type="host" ip="192.168.1.28"
port="10001"/>

<candidate component="1" foundation="2" generation="0"
id="4b5b99ec8c430e9814e5058323ea9d6306646967c" network="0"
priority="1862270975" protocol="udp" type="prflx" ip="115.68.221.39"
port="10001" rel-addr="192.168.1.28" rel-port="10001"/>

<candidate component="2" foundation="1" generation="0"
id="4b5b99ec8c430e9814e5058323ea9d63038ab3c51" network="0"
priority="2130706430" protocol="udp" type="host" ip="192.168.1.28"
port="10002"/>

<candidate component="2" foundation="2" generation="0"
id="4b5b99ec8c430e9814e5058323ea9d6302441db59" network="0"
priority="1862270974" protocol="udp" type="prflx" ip="115.68.221.39"
port="10002" rel-addr="192.168.1.28" rel-port="10002"/>

</transport></channel></content></conference></iq>

Jan 19, 2016 8:44:11 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="cmeng@talk.org/jitsi-1di9e4s"
to="jitsi-videobridge.talk.org" id="4hu0E-126" type="result"/>

Jan 19, 2016 8:44:11 AM org.jitsi.util.Logger info

INFO: RECV: <iq from="cmeng@talk.org/jitsi-1di9e4s"
to="jitsi-videobridge.talk.org" id="4hu0E-127" type="result"/>

Jan 19, 2016 8:44:11 AM org.ice4j.ice.Agent setState

INFO: ICE state changed from Completed to Terminated

Jan 19, 2016 8:44:11 AM org.jitsi.util.Logger info

INFO: ICE processing state of IceUdpTransportManager #44465d15 (for channels
3d127fe0b74f1909) of conference 4b5b99ec8c430e98 changed from Completed to
Terminated.

### cmeng ?#01 - jvb tries to gather/establish downstream link to calling
party (jitsi-ubuntu)? Failed as it is blocked by firewall - timetolive?

Jan 19, 2016 8:44:12 AM org.ice4j.ice.ConnectivityCheckClient processTimeout

INFO: timeout for pair: 192.168.1.28:10001/udp/host ->
115.68.221.39:5000/udp/srflx (audio.RTP), failing.

Jan 19, 2016 8:44:12 AM org.ice4j.ice.ConnectivityCheckClient processTimeout

INFO: timeout for pair: 192.168.1.28:10001/udp/host ->
115.68.221.39:50002/udp/relay (audio.RTP), failing.

Jan 19, 2016 8:44:12 AM org.ice4j.ice.ConnectivityCheckClient processTimeout

INFO: timeout for pair: 192.168.1.28:10002/udp/host ->
115.68.221.39:5001/udp/srflx (audio.RTCP), failing.

Jan 19, 2016 8:44:12 AM org.ice4j.ice.ConnectivityCheckClient processTimeout

INFO: timeout for pair: 192.168.1.28:10002/udp/host ->
115.68.221.39:50003/udp/relay (audio.RTCP), failing.

### cmeng - calling JID (jitsi-ubuntu) initiate video call

### debug message excluded as it is having the same problem as the audio
downstream link setup

ยทยทยท

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

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