[jitsi-dev] Jitsi-meet behind NAT and nginx


#1

Hello,

I'm moving this discussion to the dev mailing list (from users) since it's getting technical.

Recap: I'm trying to deploy jitsi-meet in a relatively standard nattend environment. Debian testing x86_64, jitsi-videobridge packaged for debian, same results with both the stable (750-1) and the nightly (882-1).

Site and chat work perfectly (two clients connect and see the other partecipant online), but I cannot get audio and video through.

The network is configured as following:

[public addr] ROUTER [10.0.20.1] --(80/443)--> NGINX [10.0.20.50] --(80/443)--> JITSIMEET [10.0.20.10]
              ROUTER --(udp 5k:6k; 10k:20k)--> JITSIMEET

I would think that since the website works fine the tcp chain going through nginx works. Following Emil suggestion I tested that udp is forwarded correctly: running

nc -u -l -p 10000

on the server, a connection can be established and maintained using

nc -u [public addr] 10000

on a client machine (of course the client is not on the same network).

Using the default configuration, almost as soon as a second client connects to the room, both clients see the other connecting but then crash, then restart and the site and chat works as expected but no video/audio feed (apart from the local one).

Adding:
org.jitsi.videobridge.NAT_HARVESTER_LOCAL_ADDRESS=10.0.20.10
org.jitsi.videobridge.NAT_HARVESTER_PUBLIC_ADDRESS=<public addr>

to /etc/jitsi/videobridge/sip-communicator.properties

seems to be solving the crash problem, but still there is no video/audio feed from the other peer.

Some interesting extracts from /var/log/jitsi/jvb.log (with the NAT_HARVERSTER_* configured as described above):

cat /var/log/jitsi/jvb.log | grep -i udp
JVB 2017-01-25 10:59:12.135 INFO: [50] org.ice4j.ice.harvest.AbstractUdpListener.<init>() Initialized AbstractUdpListener with address 10.0.20.10:10000/udp. Receive buffer size 106496
JVB 2017-01-25 10:59:12.137 INFO: [50] org.ice4j.ice.harvest.SinglePortUdpHarvester.<init>() Initialized SinglePortUdpHarvester with address 10.0.20.10:10000/udp
JVB 2017-01-25 10:59:12.149 INFO: [50] org.jitsi.videobridge.IceUdpTransportManager.log() Initialized TCP harvester on port 443, using SSLTCP:true
[...]

already makes me think, shouldn't the public ip be listed already here somewhere?

The pairing history goes as follows:

cat /var/log/jitsi/jvb.log | grep -i pair
JVB 2017-01-25 10:59:14.742 INFO: [131] org.ice4j.ice.Agent.log() Trigger checks for pairs that were received before running state
JVB 2017-01-25 10:59:14.742 INFO: [131] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7961835276064522239):
JVB 2017-01-25 10:59:14.744 INFO: [131] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
JVB 2017-01-25 10:59:14.787 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 198.18.0.1:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.787 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.2:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.788 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 198.18.0.1:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.788 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.2:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.859 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.868 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.876 INFO: [103] org.ice4j.ice.Agent.log() verify if nominated pair answer again
JVB 2017-01-25 10:59:14.899 INFO: [140] org.ice4j.ice.Agent.log() Trigger checks for pairs that were received before running state
JVB 2017-01-25 10:59:14.899 INFO: [140] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
JVB 2017-01-25 10:59:14.900 INFO: [140] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7961835276064522239):
JVB 2017-01-25 10:59:14.903 INFO: [102] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:40800/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.904 INFO: [102] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:40800/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.943 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.944 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.945 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Nomination confirmed for pair: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Loal ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.948 INFO: [133] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 198.18.0.1:40800/udp/host (stream.RTP)
JVB 2017-01-25 10:59:14.949 INFO: [103] org.ice4j.ice.CheckList.log() Selected pair for stream stream.RTP: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP)
JVB 2017-01-25 10:59:14.971 INFO: [103] org.ice4j.ice.Agent.log() Harvester used for selected pair for stream.RTP (local ufrag 2slap1b7akf43f): srflx
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.12:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.11:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.12:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.11:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.058 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.12:35886/udp/host (stream.RTP)
JVB 2017-01-25 10:59:15.076 INFO: [115] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.077 INFO: [115] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.078 INFO: [115] org.ice4j.ice.Agent.log() verify if nominated pair answer again
JVB 2017-01-25 10:59:15.093 INFO: [113] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:46598/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.094 INFO: [113] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:46598/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.104 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.11:46598/udp/host (stream.RTP)
JVB 2017-01-25 10:59:15.129 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.12:35886/udp/host (stream.RTP)
JVB 2017-01-25 10:59:15.142 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.142 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.143 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log() Nomination confirmed for pair: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Loal ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.143 INFO: [114] org.ice4j.ice.CheckList.log() Selected pair for stream stream.RTP: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP)
JVB 2017-01-25 10:59:15.157 INFO: [114] org.ice4j.ice.Agent.log() Harvester used for selected pair for stream.RTP (local ufrag rim11b7akf47n): srflx

I masked the public ips but they are correct: 87.21.xxx.xxx is the public ip of the server and 178.250.xxx.xxx is the one where the clients are.
Everything seems to be ok, as far as i can tell, yet the video does not work.

The only error I noticed in the log is:

cat /var/log/jitsi/jvb.log | grep -i except
JVB 2017-01-25 10:59:15.185 SEVERE: [110] util.UtilActivator.uncaughtException().119 An uncaught exception occurred in thread=Thread[IceUdpTransportManager connect thread,5,main] and message was: java.net.UnknownHostException: jitsimeet: jitsimeet: Name or service not known
java.lang.RuntimeException: java.net.UnknownHostException: jitsimeet: jitsimeet: Name or service not known
Caused by: java.net.UnknownHostException: jitsimeet: jitsimeet: Name or service not known
Caused by: java.net.UnknownHostException: jitsimeet: Name or service not known
JVB 2017-01-25 10:59:15.194 SEVERE: [118] util.UtilActivator.uncaughtException().119 An uncaught exception occurred in thread=Thread[IceUdpTransportManager connect thread,5,main] and message was: null
java.lang.NullPointerException

Any idea on how I could proceed to isolate the problem?

Thank you very much for you help!

Samuele

···

--

--
Samuele Carli
www.csspace.net
--


#2

Hello,

I'm moving this discussion to the dev mailing list (from users) since it's getting technical.

Recap: I'm trying to deploy jitsi-meet in a relatively standard nattend environment. Debian testing x86_64, jitsi-videobridge packaged for debian, same results with both the stable (750-1) and the nightly (882-1).

Site and chat work perfectly (two clients connect and see the other partecipant online), but I cannot get audio and video through.

The network is configured as following:

[public addr] ROUTER [10.0.20.1] --(80/443)--> NGINX [10.0.20.50] --(80/443)--> JITSIMEET [10.0.20.10]
              ROUTER --(udp 5k:6k; 10k:20k)--> JITSIMEET

I would think that since the website works fine the tcp chain going through nginx works. Following Emil suggestion I tested that udp is forwarded correctly: running

nc -u -l -p 10000

on the server, a connection can be established and maintained using

nc -u [public addr] 10000

on a client machine (of course the client is not on the same network).

Using the default configuration, almost as soon as a second client connects to the room, both clients see the other connecting but then crash, then restart and the site and chat works as expected but no video/audio feed (apart from the local one).

Adding:
org.jitsi.videobridge.NAT_HARVESTER_LOCAL_ADDRESS=10.0.20.10
org.jitsi.videobridge.NAT_HARVESTER_PUBLIC_ADDRESS=<public addr>

to /etc/jitsi/videobridge/sip-communicator.properties

seems to be solving the crash problem, but still there is no video/audio feed from the other peer.

Some interesting extracts from /var/log/jitsi/jvb.log (with the NAT_HARVERSTER_* configured as described above):

cat /var/log/jitsi/jvb.log | grep -i udp
JVB 2017-01-25 10:59:12.135 INFO: [50] org.ice4j.ice.harvest.AbstractUdpListener.<init>() Initialized AbstractUdpListener with address 10.0.20.10:10000/udp. Receive buffer size 106496
JVB 2017-01-25 10:59:12.137 INFO: [50] org.ice4j.ice.harvest.SinglePortUdpHarvester.<init>() Initialized SinglePortUdpHarvester with address 10.0.20.10:10000/udp
JVB 2017-01-25 10:59:12.149 INFO: [50] org.jitsi.videobridge.IceUdpTransportManager.log() Initialized TCP harvester on port 443, using SSLTCP:true
[...]

already makes me think, shouldn't the public ip be listed already here somewhere?

These are normal because we're binding to the local addresses. The public address may be listed elsewhere (maybe in a log messsage from MappingCandidateHarvesters). In any case, see below.

The pairing history goes as follows:

cat /var/log/jitsi/jvb.log | grep -i pair
JVB 2017-01-25 10:59:14.742 INFO: [131] org.ice4j.ice.Agent.log() Trigger checks for pairs that were received before running state
JVB 2017-01-25 10:59:14.742 INFO: [131] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7961835276064522239):
JVB 2017-01-25 10:59:14.744 INFO: [131] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
JVB 2017-01-25 10:59:14.787 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 198.18.0.1:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.787 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.2:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.788 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 198.18.0.1:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.788 INFO: [132] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.2:9/tcp/host (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.859 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.868 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f

There you go, ICE succeeded, so the NAT is not a problem.

JVB 2017-01-25 10:59:14.876 INFO: [103] org.ice4j.ice.Agent.log() verify if nominated pair answer again
JVB 2017-01-25 10:59:14.899 INFO: [140] org.ice4j.ice.Agent.log() Trigger checks for pairs that were received before running state
JVB 2017-01-25 10:59:14.899 INFO: [140] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
JVB 2017-01-25 10:59:14.900 INFO: [140] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7961835276064522239):
JVB 2017-01-25 10:59:14.903 INFO: [102] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:40800/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.904 INFO: [102] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:40800/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.943 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.944 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.945 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log() Nomination confirmed for pair: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Loal ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.948 INFO: [133] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 198.18.0.1:40800/udp/host (stream.RTP)
JVB 2017-01-25 10:59:14.949 INFO: [103] org.ice4j.ice.CheckList.log() Selected pair for stream stream.RTP: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx (stream.RTP)
JVB 2017-01-25 10:59:14.971 INFO: [103] org.ice4j.ice.Agent.log() Harvester used for selected pair for stream.RTP (local ufrag 2slap1b7akf43f): srflx
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.12:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.11:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.12:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.11:9/tcp/host (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.058 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.12:35886/udp/host (stream.RTP)
JVB 2017-01-25 10:59:15.076 INFO: [115] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.077 INFO: [115] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.078 INFO: [115] org.ice4j.ice.Agent.log() verify if nominated pair answer again
JVB 2017-01-25 10:59:15.093 INFO: [113] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:46598/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.094 INFO: [113] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:46598/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.104 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.11:46598/udp/host (stream.RTP)
JVB 2017-01-25 10:59:15.129 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.12:35886/udp/host (stream.RTP)
JVB 2017-01-25 10:59:15.142 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.142 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.143 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log() Nomination confirmed for pair: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Loal ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.143 INFO: [114] org.ice4j.ice.CheckList.log() Selected pair for stream stream.RTP: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx (stream.RTP)
JVB 2017-01-25 10:59:15.157 INFO: [114] org.ice4j.ice.Agent.log() Harvester used for selected pair for stream.RTP (local ufrag rim11b7akf47n): srflx

I masked the public ips but they are correct: 87.21.xxx.xxx is the public ip of the server and 178.250.xxx.xxx is the one where the clients are.
Everything seems to be ok, as far as i can tell, yet the video does not work.

The only error I noticed in the log is:

cat /var/log/jitsi/jvb.log | grep -i except
JVB 2017-01-25 10:59:15.185 SEVERE: [110] util.UtilActivator.uncaughtException().119 An uncaught exception occurred in thread=Thread[IceUdpTransportManager connect thread,5,main] and message was: java.net.UnknownHostException: jitsimeet: jitsimeet: Name or service not known
java.lang.RuntimeException: java.net.UnknownHostException: jitsimeet: jitsimeet: Name or service not known

Oh. You seem to be running into that weird fmj bug, which requires the local hostname to be resolvable. We have it somewhere on the list of tasks, and it comes to bite us in the ass over and over again. Try adding "127.0.0.1 jitsimeet" to /etc/hosts

If this doesn't help, please post the full exceptions.

Regards,
Boris

···

On 25/01/2017 05:40, Samuele Carli wrote:


#3

I am not from the dev team.

1)
Are you running JVB and nginx from the same machine?

I can see from your JVB log this line: Initialized TCP harvester on port
443, using SSLTCP:true.
Port 443 will be taken by nginx. In this case, the JVB should configuration
should fallback to 4443. I guess you may not (that's not necessary, I am
just trying to understand)

2)
I see from the docs that org.jitsi.videobridge.NAT_HARVESTER_* settings
have been deprecated since Nov 2016.
Try adding (these below) instead. You don't need to remove the old
settings, the stable version might use the old ones while the nightly might
use the new ones.
org.ice4j.ice.harvest.NAT_HARVESTER_LOCAL_ADDRESS
org.ice4j.ice.harvest.NAT_HARVESTER_PUBLIC_ADDRESS

Docs:
https://github.com/jitsi/jitsi-videobridge/blob/master/doc/tcp.md
https://github.com/jitsi/ice4j/blob/master/doc/configuration.md

3)
Try checking information at chrome://webrtc-internals/ during a conference
It should show up information of the webrtc connection from the conference
in the https://your_domain/conference [some_id]. Still here, check the
Conn-audio-1-0 (only one in bold) if the local and remote IP addresses are
correct.

4)
Sometimes with me, the JVB takes some time to start the first conference.
After starting all components, create a conference and see if you get the
no audio/video. Close all tabs from the first conference and create a new
one different from the first one.

···

On Wed, Jan 25, 2017 at 9:40 AM, Samuele Carli <carlisamuele@csspace.net> wrote:

Hello,

I'm moving this discussion to the dev mailing list (from users) since it's
getting technical.

Recap: I'm trying to deploy jitsi-meet in a relatively standard nattend
environment. Debian testing x86_64, jitsi-videobridge packaged for debian,
same results with both the stable (750-1) and the nightly (882-1).

Site and chat work perfectly (two clients connect and see the other
partecipant online), but I cannot get audio and video through.

The network is configured as following:

[public addr] ROUTER [10.0.20.1] --(80/443)--> NGINX [10.0.20.50]
--(80/443)--> JITSIMEET [10.0.20.10]
              ROUTER --(udp 5k:6k; 10k:20k)--> JITSIMEET

I would think that since the website works fine the tcp chain going
through nginx works. Following Emil suggestion I tested that udp is
forwarded correctly: running

nc -u -l -p 10000

on the server, a connection can be established and maintained using

nc -u [public addr] 10000

on a client machine (of course the client is not on the same network).

Using the default configuration, almost as soon as a second client
connects to the room, both clients see the other connecting but then crash,
then restart and the site and chat works as expected but no video/audio
feed (apart from the local one).

Adding:
org.jitsi.videobridge.NAT_HARVESTER_LOCAL_ADDRESS=10.0.20.10
org.jitsi.videobridge.NAT_HARVESTER_PUBLIC_ADDRESS=<public addr>

to /etc/jitsi/videobridge/sip-communicator.properties

seems to be solving the crash problem, but still there is no video/audio
feed from the other peer.

Some interesting extracts from /var/log/jitsi/jvb.log (with the
NAT_HARVERSTER_* configured as described above):

> cat /var/log/jitsi/jvb.log | grep -i udp
> JVB 2017-01-25 10:59:12.135 INFO: [50] org.ice4j.ice.harvest.AbstractUdpListener.<init>()
Initialized AbstractUdpListener with address 10.0.20.10:10000/udp.
Receive buffer size 106496
> JVB 2017-01-25 10:59:12.137 INFO: [50] org.ice4j.ice.harvest.
SinglePortUdpHarvester.<init>() Initialized SinglePortUdpHarvester with
address 10.0.20.10:10000/udp
> JVB 2017-01-25 10:59:12.149 INFO: [50] org.jitsi.videobridge.IceUdpTransportManager.log()
Initialized TCP harvester on port 443, using SSLTCP:true
> [...]

already makes me think, shouldn't the public ip be listed already here
somewhere?

The pairing history goes as follows:

cat /var/log/jitsi/jvb.log | grep -i pair
JVB 2017-01-25 10:59:14.742 INFO: [131] org.ice4j.ice.Agent.log() Trigger
checks for pairs that were received before running state
JVB 2017-01-25 10:59:14.742 INFO: [131] org.ice4j.ice.Agent.log() Add peer
CandidatePair with new reflexive address to checkList: CandidatePair
(State=Frozen Priority=7961835276064522239):
JVB 2017-01-25 10:59:14.744 INFO: [131] org.ice4j.ice.Agent.log() Add peer
CandidatePair with new reflexive address to checkList: CandidatePair
(State=Frozen Priority=7962116751041232895):
JVB 2017-01-25 10:59:14.787 INFO: [132] org.ice4j.ice.Component.log() new
Pair added: 10.0.20.10:443/tcp/host -> 198.18.0.1:9/tcp/host
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.787 INFO: [132] org.ice4j.ice.Component.log() new
Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.2:9/tcp/host (stream.RTP).
Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.788 INFO: [132] org.ice4j.ice.Component.log() new
Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 198.18.0.1:9/tcp/host
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.788 INFO: [132] org.ice4j.ice.Component.log() new
Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.2:9/tcp/host
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.859 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log()
Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:33525/udp/prflx
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.868 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log()
Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.876 INFO: [103] org.ice4j.ice.Agent.log() verify
if nominated pair answer again
JVB 2017-01-25 10:59:14.899 INFO: [140] org.ice4j.ice.Agent.log() Trigger
checks for pairs that were received before running state
JVB 2017-01-25 10:59:14.899 INFO: [140] org.ice4j.ice.Agent.log() Add peer
CandidatePair with new reflexive address to checkList: CandidatePair
(State=Frozen Priority=7962116751041232895):
JVB 2017-01-25 10:59:14.900 INFO: [140] org.ice4j.ice.Agent.log() Add peer
CandidatePair with new reflexive address to checkList: CandidatePair
(State=Frozen Priority=7961835276064522239):
JVB 2017-01-25 10:59:14.903 INFO: [102] org.ice4j.ice.ConnectivityCheckClient.log()
Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:40800/udp/prflx
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.904 INFO: [102] org.ice4j.ice.ConnectivityCheckClient.log()
Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:40800/udp/prflx
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.943 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log()
Pair succeeded: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.944 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log()
Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:33525/udp/prflx
(stream.RTP). Local ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.945 INFO: [103] org.ice4j.ice.ConnectivityCheckClient.log()
Nomination confirmed for pair: 87.21.xxx.xxx:10000/udp/srflx ->
178.250.xxx.xxx:33525/udp/prflx (stream.RTP). Loal ufrag 2slap1b7akf43f
JVB 2017-01-25 10:59:14.948 INFO: [133] org.ice4j.ice.ConnectivityCheckClient.log()
Pair failed: 10.0.20.10:10000/udp/host -> 198.18.0.1:40800/udp/host
(stream.RTP)
JVB 2017-01-25 10:59:14.949 INFO: [103] org.ice4j.ice.CheckList.log()
Selected pair for stream stream.RTP: 87.21.xxx.xxx:10000/udp/srflx ->
178.250.xxx.xxx:33525/udp/prflx (stream.RTP)
JVB 2017-01-25 10:59:14.971 INFO: [103] org.ice4j.ice.Agent.log()
Harvester used for selected pair for stream.RTP (local ufrag
2slap1b7akf43f): srflx
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new
Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.12:9/tcp/host (stream.RTP).
Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new
Pair added: 10.0.20.10:443/tcp/host -> 10.0.0.11:9/tcp/host (stream.RTP).
Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new
Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.12:9/tcp/host
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:14.972 INFO: [143] org.ice4j.ice.Component.log() new
Pair added: 87.21.xxx.xxx:443/tcp/srflx -> 10.0.0.11:9/tcp/host
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.058 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log()
Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.12:35886/udp/host
(stream.RTP)
JVB 2017-01-25 10:59:15.076 INFO: [115] org.ice4j.ice.ConnectivityCheckClient.log()
Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:35886/udp/prflx
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.077 INFO: [115] org.ice4j.ice.ConnectivityCheckClient.log()
Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.078 INFO: [115] org.ice4j.ice.Agent.log() verify
if nominated pair answer again
JVB 2017-01-25 10:59:15.093 INFO: [113] org.ice4j.ice.ConnectivityCheckClient.log()
Pair succeeded: 10.0.20.10:10000/udp/host -> 178.250.xxx.xxx:46598/udp/prflx
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.094 INFO: [113] org.ice4j.ice.ConnectivityCheckClient.log()
Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:46598/udp/prflx
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.104 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log()
Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.11:46598/udp/host
(stream.RTP)
JVB 2017-01-25 10:59:15.129 INFO: [144] org.ice4j.ice.ConnectivityCheckClient.log()
Pair failed: 10.0.20.10:10000/udp/host -> 10.0.0.12:35886/udp/host
(stream.RTP)
JVB 2017-01-25 10:59:15.142 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log()
Pair succeeded: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.142 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log()
Pair validated: 87.21.xxx.xxx:10000/udp/srflx -> 178.250.xxx.xxx:35886/udp/prflx
(stream.RTP). Local ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.143 INFO: [114] org.ice4j.ice.ConnectivityCheckClient.log()
Nomination confirmed for pair: 87.21.xxx.xxx:10000/udp/srflx ->
178.250.xxx.xxx:35886/udp/prflx (stream.RTP). Loal ufrag rim11b7akf47n
JVB 2017-01-25 10:59:15.143 INFO: [114] org.ice4j.ice.CheckList.log()
Selected pair for stream stream.RTP: 87.21.xxx.xxx:10000/udp/srflx ->
178.250.xxx.xxx:35886/udp/prflx (stream.RTP)
JVB 2017-01-25 10:59:15.157 INFO: [114] org.ice4j.ice.Agent.log()
Harvester used for selected pair for stream.RTP (local ufrag
rim11b7akf47n): srflx

I masked the public ips but they are correct: 87.21.xxx.xxx is the public
ip of the server and 178.250.xxx.xxx is the one where the clients are.
Everything seems to be ok, as far as i can tell, yet the video does not
work.

The only error I noticed in the log is:

cat /var/log/jitsi/jvb.log | grep -i except
JVB 2017-01-25 10:59:15.185 SEVERE: [110] util.UtilActivator.uncaughtException().119
An uncaught exception occurred in thread=Thread[IceUdpTransportManager
connect thread,5,main] and message was: java.net.UnknownHostException:
jitsimeet: jitsimeet: Name or service not known
java.lang.RuntimeException: java.net.UnknownHostException: jitsimeet:
jitsimeet: Name or service not known
Caused by: java.net.UnknownHostException: jitsimeet: jitsimeet: Name or
service not known
Caused by: java.net.UnknownHostException: jitsimeet: Name or service not
known
JVB 2017-01-25 10:59:15.194 SEVERE: [118] util.UtilActivator.uncaughtException().119
An uncaught exception occurred in thread=Thread[IceUdpTransportManager
connect thread,5,main] and message was: null
java.lang.NullPointerException

Any idea on how I could proceed to isolate the problem?

Thank you very much for you help!

Samuele

--
>--
> Samuele Carli
> www.csspace.net
>--

_______________________________________________
dev mailing list
dev@jitsi.org
Unsubscribe instructions and other list options:
http://lists.jitsi.org/mailman/listinfo/dev


#4

I am not from the dev team.

1) Are you running JVB and nginx from the same machine?

I can see from your JVB log this line: Initialized TCP harvester on port 443, using SSLTCP:true. Port 443 will be taken by nginx. In this case, the JVB should configuration should fallback to 4443. I guess you may not (that's not necessary, I am just trying to understand)

No, nginx and JVB are on different machines.

2) I see from the docs that org.jitsi.videobridge.NAT_HARVESTER_* settings have been deprecated since Nov 2016. Try adding (these below) instead. You don't need to remove the old settings, the stable version might use the old ones while the nightly might use the new ones. org.ice4j.ice.harvest.NAT_HARVESTER_LOCAL_ADDRESS org.ice4j.ice.harvest.NAT_HARVESTER_PUBLIC_ADDRESS

Docs: https://github.com/jitsi/jitsi-videobridge/blob/master/doc/tcp.md https://github.com/jitsi/ice4j/blob/master/doc/configuration.md

Cool, my fault I didn't notice! (And well, maybe https://github.com/jitsi/jitsi-meet/blob/master/doc/manual-install.md should get updated...)

Anyway, I just tried:

org.ice4j.ice.harvest.NAT_HARVESTER_LOCAL_ADDRESS=10.0.20.10
org.ice4j.ice.harvest.NAT_HARVESTER_PUBLIC_ADDRESS=87.21.xxx.xxx

but nothing changed.

3) Try checking information at chrome://webrtc-internals/ during a conference It should show up information of the webrtc connection from the conference in the https://your_domain/conference [some_id]. Still here, check the Conn-audio-1-0 (only one in bold) if the local and remote IP addresses are correct.

This is a very cool tip, i didn't know about that! Thanks!

Conn-audio-1-0 (googCandidatePair)
Statistics Conn-audio-1-0
timestamp 25/01/2017, 15:34:12
googActiveConnection true
bytesReceived 854
bytesSent 7183
packetsSent 11
googReadable true
requestsSent 35
consentRequestsSent 1
responsesSent 28
requestsReceived 28
responsesReceived 35
googChannelId Channel-audio-1
googLocalAddress 178.250.xxx.xxx:54342
localCandidateId Cand-LqQN0jW8
googLocalCandidateType prflx
googRemoteAddress 87.21.xxx.xxx:10000
remoteCandidateId Cand-7ywfUySc
googRemoteCandidateType stun
googRtt 50
packetsDiscardedOnSend 0
googTransportType udp
googWritable true

The ips are the right ones one both machines...

about:webrtc on firefox is a bit more informative, I get:

ICE Stats
Local Candidate Remote Candidate ICE State Priority Nominated Selected
198.18.0.1:36036/udp(host) 10.0.20.10:10000/udp(host) failed 9115005270299247000
10.0.0.2:38400/udp(host) 10.0.20.10:10000/udp(host) failed 9114723795322536000
198.18.0.1:36036/udp(host) 87.21.xxx.xxx:10000/udp(serverreflexive) failed 7205771498370236000 true
10.0.0.2:38400/udp(host) 87.21.xxx.xxx:10000/udp(serverreflexive) failed 7205771498370105000
178.250.xxx.xxx:38400/udp(peerreflexive) 87.21.xxx.xxx:10000/udp(serverreflexive) succeeded 7205771497833366000 true true
178.250.xxx.xxx:38400/udp(peerreflexive) 87.21.xxx.xxx:10000/udp(serverreflexive) succeeded 7205771497833234000
178.250.xxx.xxx:38400/udp(peerreflexive) 87.21.xxx.xxx:10000/udp(serverreflexive) succeeded 7205771497833234000
  10.0.20.10:443/tcp(host)
  87.21.xxx.xxx:443/tcp(serverreflexive)

from which i really like the line:
178.250.xxx.xxx:38400/udp(peerreflexive) 87.21.xxx.xxx:10000/udp(serverreflexive) succeeded 7205771497833366000 true true

So maybe the problem is not the network after all?

4) Sometimes with me, the JVB takes some time to start the first conference. After starting all components, create a conference and see if you get the no audio/video. Close all tabs from the first conference and create a new one different from the first one.

Unfortunately, no difference...

Thank you very much for you tips anyway!

Cheers,
Samuele

···

On 25/01/17 14:30, Camilo wrote:

--

--
Samuele Carli
www.csspace.net
--


#5

Amazing, the problem was really just that! Thank you so much! Jitsi-meet really rocks :slight_smile:

Have a nice day,

Samuele

···

On 25/01/17 16:02, Boris Grozev wrote:

Oh. You seem to be running into that weird fmj bug, which requires the local hostname to be resolvable. We have it somewhere on the list of tasks, and it comes to bite us in the ass over and over again. Try adding "127.0.0.1 jitsimeet" to /etc/hosts

If this doesn't help, please post the full exceptions.

Regards,
Boris

--

--
Samuele Carli
www.csspace.net
--