Local camera delay and ping time out in natted environment

I have a somewhat non-standard environment (natted, ports 80 and 443 must be shifted to different ports, firewall) where I fail to get jitsi running.

When I load the URL of the jitsi meet installation it takes some 60 seconds from page-load until I see my (local) camera stream. During the waiting time the camera and the mike icons are croseed out. In the console log from “Strophe connecting” to “Strophe connected” it takes as well some 60 seconds, there is no further error message. When a second user wants to enter the room I have the same problem. Waiting time of 60 seconds. Then, the connection is fine. After a hile I then get loads of strophe.ping.js ping timeout errors on one of the machines and Bridge channel send: no opened channel errors on the other machine, the connection however is present and working between the two cameras.

It is not a client side issue: I tested a standard configuration on an Amazon EC2 instance and there everything is working, nice and fast.

My guess is that somewhere in my network configuration a nat, a firewall rule or a port redirection is not really correct. However, I need some hint to do a more focused search.

A second question may be loosely connected with this. In my EC2 instance I realized that the sip-communicator.properties are important to get right.

org.jitsi.videobridge.NAT_HARVESTER_LOCAL_ADDRESS=127.0.0.1
org.jitsi.videobridge.NAT_HARVESTER_PUBLIC_ADDRESS=

What would I enter as IP ADDRESS in a natted environment? And what would I be doing if that IP ADDRESS is not stable but changes every 24 hours (residential gateway line)?

Your public Internet address. This address is sent to clients to connect to jvb.

You need to change it and restart jvb every time the address changes. You can also setup stun harvester to auto-discover the public address so you will just need a restart. This is the value: https://github.com/jitsi/docker-jitsi-meet/blob/master/env.example#L185
And the property to put there https://github.com/jitsi/docker-jitsi-meet/blob/master/jvb/rootfs/defaults/sip-communicator.properties#L5 instead of NAT_HARVESTER_LOCAL_ADDRESS and NAT_HARVESTER_PUBLIC_ADDRESS.
Hey @Boris_Grozev can we put that ^ by default in jvb, before releasing to stable? We are already doing it for docker images :slight_smile:

@damencho Ok, will do so and find a way to connect that with my DNS system which detects the IP change.

But even if I do this manually I still have this 60 second delay until I get camera.

I checked prosody log and it looks like in the first round I always get an “rid too large” warning with the new rid being equal to the last rid + 2 and the BOSH client disconnects. Then, 60 seconds later there is a new BOSH session which seems to succeed. So I assume that the 60 seconds delay I see is the BOSH timeout. What can I do to solve this? I have no idea why I get this +2 shift in the rid.

Interesting … yeah no idea …

@damencho Thank you for your comment.

It would help me probably if I knew which component issues these requests with rids to which component and where these components kept the recent state persistent.

Maybe some log info could help.

I did a complete restart of all components to get a clean log and I try to include the relevant portions.

Prosody tells me:

Mar 19 00:28:16 mod_posix warn Received SIGTERM
Mar 19 00:28:16 general info Shutting down: Received SIGTERM
Mar 19 00:28:16 c2s55a4a8d58eb0 info c2s stream for focus@auth.clemenscap.de/focus292687120646610 closed: Received SIGTERM
Mar 19 00:28:16 c2s55a4a8d58eb0 info Client disconnected: connection closed
Mar 19 00:28:16 general info Shutting down…
Mar 19 00:28:16 general info Shutdown status: Cleaning up
Mar 19 00:28:16 general info Shutdown complete
Mar 19 00:28:16 general info Hello and welcome to Prosody version 0.9.12
Mar 19 00:28:16 general info Prosody is using the select backend for connection handling
Mar 19 00:28:16 portmanager info Activated service ‘s2s’ on [::]:5269, []:5269
Mar 19 00:28:16 portmanager info Activated service ‘c2s’ on [::]:5222, [
]:5222
Mar 19 00:28:16 portmanager info Activated service ‘legacy_ssl’ on no ports
Mar 19 00:28:16 mod_posix info Prosody is about to detach from the console, disabling further console output
Mar 19 00:28:16 mod_posix info Successfully daemonized to PID 21889
Mar 19 00:28:16 portmanager info Activated service ‘component’ on [127.0.0.1]:5347, [::1]:5347
Mar 19 00:28:16 portmanager info Activated service ‘http’ on [::]:5280, []:5280
Mar 19 00:28:16 portmanager info Activated service ‘https’ on [::]:5281, [
]:5281
Mar 19 00:28:17 jcp5654cc7bc420 info Incoming Jabber component connection
Mar 19 00:28:17 focus.clemenscap.de:component info External component successfully authenticated
Mar 19 00:28:24 c2s5654cc7c8a80 info Client connected
Mar 19 00:28:24 c2s5654cc7c8a80 info Authenticated as focus@auth.clemenscap.de
Mar 19 00:28:24 jitsi-videobridge.clemenscap.de:component warn Component not connected, bouncing error for:
Mar 19 00:28:26 jcp5654cc80b6f0 info Incoming Jabber component connection
Mar 19 00:28:26 jitsi-videobridge.clemenscap.de:component info External component successfully authenticated
Mar 19 00:28:31 c2s5654cc7c8a80 info Client disconnected: closed
Mar 19 00:28:31 jcp5654cc7bc420 info component disconnected: focus.clemenscap.de (closed)
Mar 19 00:28:31 c2s5654cc7d4c00 info Client connected
Mar 19 00:28:31 c2s5654cc7d4c00 info Authenticated as focus@auth.clemenscap.de
Mar 19 00:28:31 focus.clemenscap.de:component warn Component not connected, bouncing error for:
Mar 19 00:28:32 jcp5654cc855270 info Incoming Jabber component connection
Mar 19 00:28:32 focus.clemenscap.de:component info External component successfully authenticated
Mar 19 00:28:36 mod_bosh info Client tried to use sid ‘e1fa0f22-23d5-45a5-a904-18291046196d’ which we don’t know about
Mar 19 00:29:42 mod_bosh info New BOSH session, assigned it sid ‘5a28e5a8-a433-4871-925f-ae7c02991096’
Mar 19 00:30:42 bosh5a28e5a8-a433-4871-925f-ae7c02991096 info Authenticated as 3edce417-8196-4c28-915b-b304f1873dac@clemenscap.de

and javascript console tells me:

(TIME) index.html loaded: 52.17000003904104
Logger.js:154 2020-03-18T23:29:42.239Z [modules/browser/BrowserCapabilities.js] : This appears to be chrome, ver: 80.0
Logger.js:154 2020-03-18T23:29:42.402Z [index.web] <HTMLDocument.>: (TIME) document ready: 216.8250000104308
Logger.js:154 2020-03-18T23:29:42.428Z [modules/UI/videolayout/VideoLayout.js] <Object.changeUserAvatar>: Missed avatar update - no small video yet for undefined
o @ Logger.js:154
Logger.js:154 2020-03-18T23:29:42.433Z [features/base/media] Start muted:
Logger.js:154 2020-03-18T23:29:42.433Z [features/base/media] Start audio only set to false
Logger.js:154 2020-03-18T23:29:42.435Z [features/analytics] Error creating analytics handler: Error: Failed to initialize Amplitude handler, no APP key
o @ Logger.js:154
Logger.js:154 2020-03-18T23:29:42.500Z [modules/UI/videolayout/SmallVideo.js] <g.w.updateView>: Unable to init avatar - no id g
o @ Logger.js:154
Logger.js:154 2020-03-18T23:29:42.505Z [modules/UI/videolayout/SmallVideo.js] <g.w.updateView>: Unable to init avatar - no id g
o @ Logger.js:154
Logger.js:154 2020-03-18T23:29:42.585Z [modules/RTC/RTCUtils.js] Audio output device set to default
Logger.js:154 2020-03-18T23:29:42.612Z [modules/xmpp/xmpp.js] <t.value>: P2P STUN servers: Array(3)
Logger.js:154 2020-03-18T23:29:42.621Z [modules/xmpp/xmpp.js] <t.value>: Lip-sync enabled !
Logger.js:154 2020-03-18T23:29:42.624Z [modules/xmpp/xmpp.js] <t.value>: (TIME) Strophe connecting: 442.23499996587634
Logger.js:154 2020-03-18T23:29:42.628Z [modules/RTC/RTCUtils.js] <t.value>: Using the new gUM flow
Logger.js:154 2020-03-18T23:29:42.628Z [modules/RTC/RTCUtils.js] <t.>: Got media constraints: Object
Logger.js:154 2020-03-18T23:29:44.416Z [features/base/storage] <Object.persistState>: redux state persisted. 356c7b005b98f3ab414453c663e4fffe -> b85563e8a8079b0b4a33298fc48872cb
Logger.js:154 2020-03-18T23:29:45.480Z [modules/RTC/RTCUtils.js] onUserMediaSuccess
Logger.js:154 2020-03-18T23:29:52.955Z [modules/UI/videolayout/SmallVideo.js] <g.w.updateView>: Unable to init avatar - no id g
o @ Logger.js:154
Logger.js:154 2020-03-18T23:30:43.101Z [modules/xmpp/xmpp.js] <t.value>: (TIME) Strophe connected: 60922.710000071675
Logger.js:154 2020-03-18T23:30:43.102Z [modules/xmpp/xmpp.js] <t.value>: My Jabber ID: 3edce417-8196-4c28-915b-b304f1873dac@clemenscap.de/861826d7-063a-4f25-bd47-8241c1830133
Logger.js:154 2020-03-18T23:30:43.121Z [conference.js] initialized with 2 local tracks
Logger.js:154 2020-03-18T23:30:43.128Z [modules/settings/Settings.js] <Object.get callStatsUserName [as callStatsUserName]>: generated callstats uid Alena-geC
Logger.js:154 2020-03-18T23:30:43.128Z [modules/xmpp/xmpp.js] <t.value>: JID 3edce417-8196-4c28-915b-b304f1873dac@clemenscap.de/861826d7-063a-4f25-bd47-8241c1830133 using MUC nickname 3edce417
Logger.js:154 2020-03-18T23:30:43.129Z [modules/xmpp/ChatRoom.js] : Joined MUC as aaaa@conference.clemenscap.de/3edce417
Logger.js:154 2020-03-18T23:30:43.130Z [modules/e2eping/e2eping.js] : Initializing e2e ping; pingInterval=10000, analyticsInterval=60000.
Logger.js:154 2020-03-18T23:30:43.131Z [modules/connectivity/ParticipantConnectionStatus.js] : RtcMuteTimeout set to: 10000
Logger.js:154 2020-03-18T23:30:43.134Z [modules/statistics/AvgRTPStatsReporter.js] : Avg RTP stats will be calculated every 15 samples
Logger.js:154 2020-03-18T23:30:43.135Z [JitsiConference.js] : backToP2PDelay: 5
Logger.js:154 2020-03-18T23:30:43.153Z [JitsiConference.js] <ee._doReplaceTrack>: _doReplaceTrack - no JVB JingleSession
Logger.js:154 2020-03-18T23:30:43.154Z [JitsiConference.js] <ee._doReplaceTrack>: _doReplaceTrack - no P2P JingleSession
Logger.js:154 2020-03-18T23:30:43.155Z [JitsiConference.js] <ee._doReplaceTrack>: _doReplaceTrack - no JVB JingleSession
Logger.js:154 2020-03-18T23:30:43.156Z [JitsiConference.js] <ee._doReplaceTrack>: _doReplaceTrack - no P2P JingleSession
Logger.js:154 2020-03-18T23:30:43.157Z [modules/remotecontrol/RemoteControl.js] <d.init>: Initializing remote control.
Logger.js:154 2020-03-18T23:30:43.159Z [modules/xmpp/moderator.js] <d.setFocusUserJid>: Focus jid set to: undefined
Logger.js:154 2020-03-18T23:30:43.160Z [modules/settings/Settings.js] <Object.get machineId [as machineId]>: generated id 94416460d282bdb163c7284a4cede7fb
Logger.js:154 2020-03-18T23:30:43.160Z [modules/xmpp/moderator.js] <d.createConferenceIq>: Session ID: null machine UID: 94416460d282bdb163c7284a4cede7fb
Logger.js:154 2020-03-18T23:30:43.164Z [features/base/tracks] Replace audio track - unmuted
Logger.js:154 2020-03-18T23:30:43.167Z [features/base/tracks] Replace video track - unmuted
Logger.js:154 2020-03-18T23:30:43.201Z [modules/xmpp/strophe.ping.js] <s.value>: XMPP pings will be sent every 10000 ms
Logger.js:154 2020-03-18T23:30:43.271Z [modules/xmpp/moderator.js] <d.setFocusUserJid>: Focus jid set to: focus@auth.clemenscap.de
Logger.js:154 2020-03-18T23:30:43.272Z [modules/xmpp/moderator.js] <d.parseConfigOptions>: Authentication enabled: false
Logger.js:154 2020-03-18T23:30:43.272Z [modules/xmpp/moderator.js] <d.parseConfigOptions>: External authentication enabled: false
Logger.js:154 2020-03-18T23:30:43.275Z [modules/xmpp/moderator.js] <d.parseConfigOptions>: Sip gateway enabled: false
Logger.js:154 2020-03-18T23:30:43.284Z [modules/xmpp/ChatRoom.js] <t.value>: entered aaaa@conference.clemenscap.de/focus {affiliation: “owner”, role: “moderator”, jid: “focus@auth.clemenscap.de/focus292981475772436”, isFocus: true, isHiddenDomain: false}
Logger.js:154 2020-03-18T23:30:43.285Z [modules/xmpp/ChatRoom.js] <t.value>: Ignore focus: aaaa@conference.clemenscap.de/focus, real JID: focus@auth.clemenscap.de/focus292981475772436
Logger.js:154 2020-03-18T23:30:43.291Z [modules/version/ComponentsVersions.js] Got xmpp version: Prosody(0.9.12,Linux)
Logger.js:154 2020-03-18T23:30:43.291Z [modules/version/ComponentsVersions.js] Got focus version: JiCoFo(1.0.1.0-508,Linux)
Logger.js:154 2020-03-18T23:30:43.292Z [conference.js] <c.>: My role changed, new role: none
Logger.js:154 2020-03-18T23:30:43.297Z [modules/xmpp/ChatRoom.js] <t.value>: (TIME) MUC joined: 61118.934999918565
Logger.js:154 2020-03-18T23:30:43.408Z [conference.js] <c.>: My role changed, new role: moderator

rid is the request id of the bosh messages. Bosh is handled by Strophe library in the client, goest through the webserver which proxies it to prosody. Normally these ids needs to be incremented by 1, in some reconnect/network fail events the diff maybe -1 but that should be handled gracefully. We had problems with diff -2 in the past and that was fixed and the fix went upstream, not sure whether it is in prosody 0.10 or 0.11 …

It is this commit https://github.com/bjc/prosody/commit/fcd7a24cd6a0dc55e24e8a07f4cd573f0dea3d7a

Hello… I had the same problem… with two devices the connection was good… with three, third didn’t had camera and microphone of other interlocutors… You must change 127.0.0.1 with your real IP local… for example 192.168.1.200…

Good Luck,
Andrea

P.s. sorry if I wrong with some words, but I’m Italian :slight_smile: