3 ways conf on docker was working last week, stopped after unknown changes :(

j2l2 · April 14, 2020, 7:59pm

I feel stupid, I should have git and commit each change.

I had docker-jitsi-meet v4101-2 working fine for 3 ways (and more) conf behind NAT.
Since then, I tested multiple things (jibri, muc_size changes, maybe folder ownership …) and added a 2nd SSL certificate.

Now, p2p still works, but as soon a third party joins (on LAN or outside), it’s video+audio muted for everyone.
First to join is moderator using plain_internal auth, others are guests.

Logs are so long, to help out track the issue, I diffed each logs and only show new lines after third party joins:
Prosody:

mod_bosh                                  info	New BOSH session, assigned it sid '2dcb6c87-5fbc-43ce-b5c3-290a826ba614',
bosh2dcb6c87-5fbc-43ce-b5c3-290a826ba614  info	Authenticated as 3gntriilreyvq7ie@guest.meet.jitsi,

JVB:

JVB 2020-04-14 21:40:20.133 INFO: [20] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=7350a621dbff34bb conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4,
JVB 2020-04-14 21:40:20.185 INFO: [20] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 53ms. Sticky failure: false,
JVB 2020-04-14 21:40:23.263 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@3d825566,
JVB 2020-04-14 21:40:28.264 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@4b0a97de,
JVB 2020-04-14 21:40:30.189 INFO: [20] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=fb4d8f9549442686 conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4,
JVB 2020-04-14 21:40:30.213 INFO: [20] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 24ms. Sticky failure: false,
JVB 2020-04-14 21:40:33.264 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@45368115,
JVB 2020-04-14 21:40:38.265 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@3f559fe6,
JVB 2020-04-14 21:40:40.214 INFO: [20] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=21a7b8fa504319a6 conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4,
JVB 2020-04-14 21:40:40.228 INFO: [20] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 14ms. Sticky failure: false,
JVB 2020-04-14 21:40:43.265 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@1053c40f,
JVB 2020-04-14 21:40:48.267 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@ff805bc,
JVB 2020-04-14 21:40:48.351 INFO: [19] org.jitsi.videobridge.VideobridgeExpireThread.log() Running expire(),
JVB 2020-04-14 21:40:50.228 INFO: [20] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=7fc17b626e9b199d conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4,
JVB 2020-04-14 21:40:50.262 INFO: [20] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 34ms. Sticky failure: false,
JVB 2020-04-14 21:40:53.267 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@7eb7037f,
JVB 2020-04-14 21:40:57.603 INFO: [29] org.ice4j.ice.Agent.log() Gathering candidates for component stream.RTP. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:40:57.604 INFO: [29] org.jitsi.videobridge.Conference.log() CAT=stat create_ice_tm,conf_id=d88cdc1272b00c7a ufrag=cmr9h1e5t3aus3,bundle=12dd8b03,initiator=true,
JVB 2020-04-14 21:40:57.605 INFO: [29] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=d88cdc1272b00c7a,content=audio,ch_id=9a0da11b9e8c4c95,endp_id=null,stream=160567965,
JVB 2020-04-14 21:40:57.605 INFO: [29] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=d88cdc1272b00c7a,content=audio,ch_id=9a0da11b9e8c4c95,endp_id=null,stream=160567965 transport=default,bundle=12dd8b03,initiator=true,media_type=audio,relay_type=null,
JVB 2020-04-14 21:40:57.606 INFO: [29] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=d88cdc1272b00c7a,content=video,ch_id=3b2f7a0a2eab5d7,endp_id=null,stream=1420555993,
JVB 2020-04-14 21:40:57.607 INFO: [29] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=d88cdc1272b00c7a,content=video,ch_id=3b2f7a0a2eab5d7,endp_id=null,stream=1420555993 transport=default,bundle=12dd8b03,initiator=true,media_type=video,relay_type=null,
JVB 2020-04-14 21:40:58.267 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@6d0e19e0,
JVB 2020-04-14 21:41:00.263 INFO: [20] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=cd4005f4bf92f644 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9,
JVB 2020-04-14 21:41:00.282 INFO: [20] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 20ms. Sticky failure: false,
JVB 2020-04-14 21:41:01.112 INFO: [29] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=3991768623,secondary_ssrcs={},temporal_id=-1,spatial_id=-1,
JVB 2020-04-14 21:41:01.112 INFO: [29] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=2670583912,secondary_ssrcs={},temporal_id=-1,spatial_id=-1,
JVB 2020-04-14 21:41:01.113 INFO: [29] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=2630541080,secondary_ssrcs={},temporal_id=-1,spatial_id=-1,
JVB 2020-04-14 21:41:01.113 WARNING: [29] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 87fae9d6 not ready yet.,
JVB 2020-04-14 21:41:01.113 WARNING: [29] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message,
JVB 2020-04-14 21:41:01.113 INFO: [29] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=3991768623,secondary_ssrcs={},temporal_id=-1,spatial_id=-1,
JVB 2020-04-14 21:41:01.113 INFO: [29] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=2670583912,secondary_ssrcs={},temporal_id=-1,spatial_id=-1,
JVB 2020-04-14 21:41:01.113 INFO: [29] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=2630541080,secondary_ssrcs={},temporal_id=-1,spatial_id=-1,
JVB 2020-04-14 21:41:01.114 WARNING: [29] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 6867b93e not ready yet.,
JVB 2020-04-14 21:41:01.114 WARNING: [29] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message,
JVB 2020-04-14 21:41:01.115 INFO: [29] org.jitsi.videobridge.IceUdpTransportManager.log() Starting ICE agent without remote candidates.,
JVB 2020-04-14 21:41:01.115 INFO: [29] org.ice4j.ice.Agent.log() Start ICE connectivity establishment. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.115 INFO: [29] org.ice4j.ice.Agent.log() Init checklist for stream stream,
JVB 2020-04-14 21:41:01.115 INFO: [29] org.ice4j.ice.Agent.log() ICE state changed from Waiting to Running. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.116 INFO: [29] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=d88cdc1272b00c7a,content=data,ch_id=e0abc6026c813c6d,endp_id=12dd8b03 old_state=Waiting,new_state=Running,
JVB 2020-04-14 21:41:01.116 INFO: [29] org.ice4j.ice.Agent.log() Trigger checks for pairs that were received before running state,
JVB 2020-04-14 21:41:01.116 INFO: [29] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962083765692399615):,
	LocalCandidate=candidate:1 1 udp 2130706431 172.18.0.4 10000 typ host,
	RemoteCandidate=candidate:10000 1 udp 1853817087 90.51.61.191 33871 typ prflx,
JVB 2020-04-14 21:41:01.117 INFO: [29] org.ice4j.ice.ConnectivityCheckClient.log() Start connectivity checks. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.142 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 172.18.0.4:10000/udp/host -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.142 INFO: [37] org.ice4j.socket.MergingDatagramSocket.log() Adding allowed address: 90.51.61.191:33871/udp,
JVB 2020-04-14 21:41:01.143 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.143 INFO: [37] org.ice4j.ice.DefaultNominator.log() Nominate (first valid): 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.143 INFO: [37] org.ice4j.ice.Agent.log() verify if nominated pair answer again,
JVB 2020-04-14 21:41:01.143 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() IsControlling: true USE-CANDIDATE:false. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.144 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 172.18.0.4:10000/udp/host -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.144 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.145 INFO: [37] org.ice4j.ice.DefaultNominator.log() Nominate (first valid): 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.145 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() IsControlling: true USE-CANDIDATE:false. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.161 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 172.18.0.4:10000/udp/host -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.161 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.162 INFO: [37] org.ice4j.ice.DefaultNominator.log() Nominate (first valid): 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.162 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() IsControlling: true USE-CANDIDATE:false. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.DefaultNominator.log() Nominate (first valid): 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() IsControlling: true USE-CANDIDATE:true. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.ConnectivityCheckClient.log() Nomination confirmed for pair: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP). Loal ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.CheckList.log() Selected pair for stream stream.RTP: 90.51.61.191:10000/udp/srflx -> 90.51.61.191:33871/udp/prflx (stream.RTP),
JVB 2020-04-14 21:41:01.165 INFO: [37] org.ice4j.ice.Agent.log() CheckList of stream stream is COMPLETED,
JVB 2020-04-14 21:41:01.166 INFO: [37] org.ice4j.ice.Agent.log() ICE state changed from Running to Completed. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:01.166 INFO: [37] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=d88cdc1272b00c7a,content=data,ch_id=e0abc6026c813c6d,endp_id=12dd8b03 old_state=Running,new_state=Completed,
JVB 2020-04-14 21:41:01.167 INFO: [37] org.ice4j.ice.Agent.log() Harvester used for selected pair for stream.RTP (local ufrag cmr9h1e5t3aus3): srflx,
JVB 2020-04-14 21:41:01.167 INFO: [360] org.jitsi.videobridge.Channel.log() CAT=stat transport_connected,conf_id=d88cdc1272b00c7a,content=audio,ch_id=9a0da11b9e8c4c95,endp_id=12dd8b03,stream=160567965,
JVB 2020-04-14 21:41:01.188 INFO: [360] org.jitsi.videobridge.Channel.log() CAT=stat transport_connected,conf_id=d88cdc1272b00c7a,content=video,ch_id=3b2f7a0a2eab5d7,endp_id=12dd8b03,stream=1420555993,
JVB 2020-04-14 21:41:01.195 INFO: [360] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=1302598199,secondary_ssrcs={1294781568=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=1302598199,secondary_ssrcs={1294781568=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=1302598199,secondary_ssrcs={1294781568=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=3956392593,secondary_ssrcs={1624395759=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=3956392593,secondary_ssrcs={1624395759=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=3956392593,secondary_ssrcs={1624395759=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=2086851405,secondary_ssrcs={3543562143=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=2086851405,secondary_ssrcs={3543562143=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=2086851405,secondary_ssrcs={3543562143=rtx},temporal_id=2,spatial_id=-1,
JVB 2020-04-14 21:41:01.195 INFO: [360] org.jitsi.videobridge.cc.BitrateController.log() new track projection for  subjective_quality=0,primary_ssrc=178492527,secondary_ssrcs={3642457787=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=178492527,secondary_ssrcs={3642457787=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=178492527,secondary_ssrcs={3642457787=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=1394652969,secondary_ssrcs={1632401712=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=1394652969,secondary_ssrcs={1632401712=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=1394652969,secondary_ssrcs={1632401712=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=2857218397,secondary_ssrcs={1074266902=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=2857218397,secondary_ssrcs={1074266902=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=2857218397,secondary_ssrcs={1074266902=rtx},temporal_id=2,spatial_id=-1,
JVB 2020-04-14 21:41:01.195 WARNING: [360] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 12dd8b03 not ready yet.,
JVB 2020-04-14 21:41:01.195 WARNING: [360] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message,
JVB 2020-04-14 21:41:01.195 INFO: [360] org.jitsi.videobridge.Channel.log() CAT=stat transport_connected,conf_id=d88cdc1272b00c7a,content=data,ch_id=e0abc6026c813c6d,endp_id=12dd8b03,
JVB 2020-04-14 21:41:01.199 SEVERE: [391] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[org.jitsi.videobridge.SctpConnection-pool-15-thread-5,5,main] and message was: Could not initialize class org.jitsi.sctp4j.Sctp,
java.lang.NoClassDefFoundError: Could not initialize class org.jitsi.sctp4j.Sctp,
	at org.jitsi.videobridge.SctpConnection.lambda$maybeStartStream$1(SctpConnection.java:537),
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149),
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624),
	at java.lang.Thread.run(Thread.java:748),
JVB 2020-04-14 21:41:03.268 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@6373cbf2,
JVB 2020-04-14 21:41:04.167 INFO: [61] org.ice4j.ice.Agent.log() ICE state changed from Completed to Terminated. Local ufrag cmr9h1e5t3aus3,
JVB 2020-04-14 21:41:04.167 INFO: [61] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=d88cdc1272b00c7a,content=data,ch_id=e0abc6026c813c6d,endp_id=12dd8b03 old_state=Completed,new_state=Terminated,
JVB 2020-04-14 21:41:08.268 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@2ce9e7c5,
JVB 2020-04-14 21:41:10.282 INFO: [20] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=3f44fa937cbe6284 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9,
JVB 2020-04-14 21:41:10.288 WARNING: [16] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 7c154f57e791d257 not ready yet.,
JVB 2020-04-14 21:41:10.288 WARNING: [16] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message,
JVB 2020-04-14 21:41:10.311 INFO: [20] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 29ms. Sticky failure: false,
JVB 2020-04-14 21:41:13.268 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@6a03a5dc,
JVB 2020-04-14 21:41:18.269 INFO: [15] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@775f6065,

JICOFO:

Jicofo 2020-04-14 21:40:53.335 INFO: [50] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: test@muc.meet.jitsi,
Jicofo 2020-04-14 21:40:54.575 INFO: [29] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@42c949e1 member=ChatMember[test@muc.meet.jitsi/12dd8b03, jid: null]@736305650],
Jicofo 2020-04-14 21:40:54.576 INFO: [29] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@muc.meet.jitsi/12dd8b03 joined.,
Jicofo 2020-04-14 21:40:54.576 INFO: [29] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= test@muc.meet.jitsi/12dd8b03, bridge=jvbbrewery@internal-muc.meet.jitsi/66c8be14007c,
Jicofo 2020-04-14 21:40:54.576 INFO: [29] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ffb962 octo_enabled= false: [[null, null, null, null]],
Jicofo 2020-04-14 21:40:57.598 INFO: [93] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal-muc.meet.jitsi/66c8be14007c to allocate channels for: Participant[endpointId=12dd8b03],
Jicofo 2020-04-14 21:40:57.599 INFO: [43] org.jitsi.jicofo.Bridge.log() Adding 5 video streams on jvbbrewery@internal-muc.meet.jitsi/66c8be14007c video streams: 4 diff: 5 (estimated: 9),
Jicofo 2020-04-14 21:40:57.613 INFO: [93] org.jitsi.jicofo.LipSyncHack.log() Not merging A/V streams from test@muc.meet.jitsi/87fae9d6 to test@muc.meet.jitsi/12dd8b03,
Jicofo 2020-04-14 21:40:57.613 INFO: [93] org.jitsi.jicofo.LipSyncHack.log() Not merging A/V streams from test@muc.meet.jitsi/6867b93e to test@muc.meet.jitsi/12dd8b03,
Jicofo 2020-04-14 21:40:58.274 INFO: [29] org.jitsi.jicofo.Bridge.log() Reset video stream diff on jvbbrewery@internal-muc.meet.jitsi/66c8be14007c video streams: 4 (estimation error: 5),
Jicofo 2020-04-14 21:41:01.104 INFO: [29] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from 12dd8b03 with accepted sources:Sources{ video: [ssrc=2630541080 ssrc=2670583912 ssrc=3991768623 ] audio: [ssrc=210775104 ssrc=416339752 ssrc=2419710186 ] }@1411733581,
Jicofo 2020-04-14 21:41:01.105 INFO: [29] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC test@muc.meet.jitsi/87fae9d6 SID: cp2ugn557s8u Sources{ video: [ssrc=2630541080 ssrc=2670583912 ssrc=3991768623 ] audio: [ssrc=210775104 ssrc=416339752 ssrc=2419710186 ] }@928878331 source_Groups{ }@92521811,
Jicofo 2020-04-14 21:41:01.108 INFO: [29] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC test@muc.meet.jitsi/6867b93e SID: bh5g1093r5g12 Sources{ video: [ssrc=2630541080 ssrc=2670583912 ssrc=3991768623 ] audio: [ssrc=210775104 ssrc=416339752 ssrc=2419710186 ] }@928878331 source_Groups{ }@92521811,
Jicofo 2020-04-14 21:41:03.278 INFO: [29] org.jitsi.jicofo.Bridge.log() Video stream count for: jvbbrewery@internal-muc.meet.jitsi/66c8be14007c: 9,

In the moderator’s browser console (Chromium, ubuntu 19.10, host of docker):

word.js:37 2020-04-14T20:18:33.371Z [modules/RTC/BridgeChannel.js] <e.value>:  Bridge Channel send: no opened channel.
o @ word.js:37
value @ word.js:37
value @ word.js:37
value @ word.js:37
ee.sendEndpointMessage @ word.js:37
ee.broadcastEndpointMessage @ word.js:37
value @ word.js:37
value @ word.js:37
c.emit @ word.js:37
f._processAndEmitReport @ word.js:37
f.processStatsReport @ word.js:37
(anonymous) @ word.js:37
word.js:37 2020-04-14T20:18:35.372Z [modules/RTC/BridgeChannel.js] <e.value>:  Bridge Channel send: no opened channel.
o @ word.js:37
value @ word.js:37
value @ word.js:37
value @ word.js:37
ee.sendEndpointMessage @ word.js:37
ee.broadcastEndpointMessage @ word.js:37
value @ word.js:37
value @ word.js:37
c.emit @ word.js:37
f._processAndEmitReport @ word.js:37
f.processStatsReport @ word.js:37
(anonymous) @ word.js:37
word.js:37 2020-04-14T20:18:35.675Z [modules/xmpp/ChatRoom.js] <t.value>:  entered test@muc.meet.jitsi/4bddd928 {affiliation: "none", role: "participant", jid: "2wzxeqy_sdbzwjj4@guest.meet.jitsi/hqLCK6Qr", isFocus: false, isHiddenDomain: false, …}
ButtonGroup.js:23 2020-04-14T20:18:35.751Z [conference.js] <c.<anonymous>>:  USER 4bddd928 connnected: e {_jid: "test@muc.meet.jitsi/4bddd928", _id: "4bddd928", _conference: ee, _displayName: undefined, _supportsDTMF: false, …}
word.js:37 2020-04-14T20:18:35.754Z [JitsiConference.js] <ee._maybeStartOrStopP2P>:  Will stop P2P with: test@muc.meet.jitsi/1a615fb2
word.js:37 2020-04-14T20:18:35.754Z [JitsiConference.js] <ee._resumeMediaTransferForJvbConnection>:  Resuming media transfer over the JVB connection...
word.js:37 2020-04-14T20:18:35.755Z [modules/xmpp/JingleSessionPC.js] <t.value>:  Queued make video active, audio active task...
word.js:37 2020-04-14T20:18:35.755Z [JitsiConference.js] <ee._removeRemoteTracks>:  Removing remote P2P track: RemoteTrack[userID: 1a615fb2, type: audio, ssrc: 1962553396, p2p: true, status: readyState: live, muted: false, enabled: true]
ButtonGroup.js:23 2020-04-14T20:18:35.759Z [modules/UI/videolayout/RemoteVideo.js] <_.removeRemoteStreamElement>:  Audio removed 1a615fb2 k.fn.init [audio#remoteAudio_1ef57a2f-f126-4b9e-958b-19269982bb09-1]
word.js:37 2020-04-14T20:18:35.765Z [JitsiConference.js] <ee._removeRemoteTracks>:  Removing remote P2P track: RemoteTrack[userID: 1a615fb2, type: video, ssrc: 2034304003, p2p: true, status: readyState: live, muted: false, enabled: true]
ButtonGroup.js:23 2020-04-14T20:18:35.770Z [modules/UI/videolayout/RemoteVideo.js] <_.removeRemoteStreamElement>:  Video removed 1a615fb2 k.fn.init [video#remoteVideo_08de03fc-591e-4667-bca1-06afd52a8993-1]
word.js:37 2020-04-14T20:18:35.783Z [JitsiConference.js] <ee._stopP2PSession>:  Stopping remote stats for P2P connection
word.js:37 2020-04-14T20:18:35.783Z [JitsiConference.js] <ee._stopP2PSession>:  Stopping CallStats for P2P connection
word.js:37 2020-04-14T20:18:35.784Z [modules/xmpp/JingleSessionPC.js] <t.value>:  Sending session-terminate <iq to="test@muc.meet.jitsi/1a615fb2" type="set" xmlns="jabber:client" id="17b122cc-ad34-4529-8227-7ab22b8da09f:sendIQ">…</iq>
word.js:37 2020-04-14T20:18:35.785Z [modules/xmpp/JingleSessionPC.js] <t.value>:  Session terminated JingleSessionPC[p2p=true,initiator=false,sid=e7cc5fada79d] undefined undefined
word.js:37 2020-04-14T20:18:35.785Z [JitsiConference.js] <ee._setP2PStatus>:  Peer to peer connection closed!
word.js:37 2020-04-14T20:18:35.796Z [JitsiConference.js] <ee._addRemoteTracks>:  Adding remote JVB track: RemoteTrack[userID: 1a615fb2, type: audio, ssrc: 234417108, p2p: false, status: readyState: live, muted: false, enabled: true]
word.js:37 2020-04-14T20:18:35.807Z [JitsiConference.js] <ee._addRemoteTracks>:  Adding remote JVB track: RemoteTrack[userID: 1a615fb2, type: video, ssrc: 3542207089, p2p: false, status: readyState: live, muted: true, enabled: true]
ButtonGroup.js:23 2020-04-14T20:18:35.824Z [modules/UI/videolayout/LargeVideoManager.js] hover in %s 1a615fb2
word.js:37 2020-04-14T20:18:35.860Z [modules/RTC/TraceablePeerConnection.js] <w.close>:  Closing TPC[6,p2p:true]...
word.js:37 2020-04-14T20:18:35.960Z [modules/xmpp/SdpConsistency.js] <e.value>:  TPC[5,p2p:false] sdp-consistency replacing new ssrc2685775166 with cached 2685775166
word.js:37 2020-04-14T20:18:35.995Z [JitsiConference.js] Resumed media transfer over the JVB connection!
word.js:37 2020-04-14T20:18:36.461Z [modules/RTC/BridgeChannel.js] <e.value>:  Bridge Channel send: no opened channel.
o @ word.js:37
value @ word.js:37
value @ word.js:37
value @ word.js:37
ee.sendEndpointMessage @ word.js:37
ee.broadcastEndpointMessage @ word.js:37
value @ word.js:37
value @ word.js:37
c.emit @ word.js:37
f._processAndEmitReport @ word.js:37
f.processStatsReport @ word.js:37
(anonymous) @ word.js:37
word.js:37 2020-04-14T20:18:36.483Z [modules/xmpp/strophe.jingle.js] <s.value>:  on jingle session-terminate from test@muc.meet.jitsi/1a615fb2 <iq xmlns="jabber:client" from="test@muc.meet.jitsi/1a615fb2" id="X3ptMWhiYWloNjFhNGVseUBndWVzdC5tZWV0LmppdHNpL05teEZkYk1NAGFjODlhZjc2LTQ1NzctNDMxZi05NThjLWM5ODYwNjU2OTA2MjpzZW5kSVEAdgKiZBgavxhBLVxt2T7KQQ==" to="_zm1hbaih61a4ely@guest.meet.jitsi/NmxFdbMM" type="set">…</iq>
word.js:37 2020-04-14T20:18:36.484Z [modules/xmpp/strophe.jingle.js] <s.value>:  invalid session id <iq xmlns="jabber:client" from="test@muc.meet.jitsi/1a615fb2" id="X3ptMWhiYWloNjFhNGVseUBndWVzdC5tZWV0LmppdHNpL05teEZkYk1NAGFjODlhZjc2LTQ1NzctNDMxZi05NThjLWM5ODYwNjU2OTA2MjpzZW5kSVEAdgKiZBgavxhBLVxt2T7KQQ==" to="_zm1hbaih61a4ely@guest.meet.jitsi/NmxFdbMM" type="set">…</iq>
o @ word.js:37
value @ word.js:37
run @ word.js:37
(anonymous) @ word.js:37
forEachChild @ word.js:37
_dataRecv @ word.js:37
_onRequestStateChange @ word.js:37
XMLHttpRequest.send (async)
l @ word.js:37
_processRequest @ word.js:37
_throttledRequestHandler @ word.js:37
_onIdle @ word.js:37
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_send @ word.js:37
send @ word.js:37
sendIQ @ word.js:37
value @ word.js:37
ee._stopP2PSession @ word.js:37
ee._maybeStartOrStopP2P @ word.js:37
ee.onMemberJoined @ word.js:37
c.emit @ word.js:37
value @ word.js:37
value @ word.js:37
run @ word.js:37
(anonymous) @ word.js:37
forEachChild @ word.js:37
_dataRecv @ word.js:37
_onRequestStateChange @ word.js:37
XMLHttpRequest.send (async)
l @ word.js:37
_processRequest @ word.js:37
_throttledRequestHandler @ word.js:37
_onIdle @ word.js:37
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_onIdle @ word.js:37
(anonymous) @ word.js:37
setTimeout (async)
_send @ word.js:37
send @ word.js:37
sendIQ @ word.js:37
value @ word.js:37
(anonymous) @ word.js:37
word.js:37 2020-04-14T20:18:38.461Z [modules/RTC/BridgeChannel.js] <e.value>:  Bridge Channel send: no opened channel.
o @ word.js:37
value @ word.js:37
value @ word.js:37
value @ word.js:37
ee.sendEndpointMessage @ word.js:37
ee.broadcastEndpointMessage @ word.js:37
value @ word.js:37
value @ word.js:37
c.emit @ word.js:37
f._processAndEmitReport @ word.js:37
f.processStatsReport @ word.js:37
(anonymous) @ word.js:37
word.js:37 2020-04-14T20:18:39.640Z [modules/RTC/BridgeChannel.js] <e.value>:  Bridge Channel send: no opened channel.
o @ word.js:37
value @ word.js:37
value @ word.js:37
value @ word.js:37
ee.sendEndpointMessage @ word.js:37
ee.sendMessage @ word.js:37
(anonymous) @ word.js:37
value @ word.js:37
word.js:37 2020-04-14T20:18:39.640Z [JitsiConference.js] <e.sendMessage>:  Failed to send a ping request or response.
o @ word.js:37
(anonymous) @ word.js:37
value @ word.js:37
word.js:37 2020-04-14T20:18:40.461Z [modules/RTC/BridgeChannel.js] <e.value>:  Bridge Channel send: no opened channel.
o @ word.js:37
value @ word.js:37
value @ word.js:37
value @ word.js:37
ee.sendEndpointMessage @ word.js:37
ee.broadcastEndpointMessage @ word.js:37
value @ word.js:37
value @ word.js:37
c.emit @ word.js:37
f._processAndEmitReport @ word.js:37
f.processStatsReport @ word.js:37
(anonymous) @ word.js:37

Pippermail seach is gone …

What’s going wrong with the videobridge now?
Thanks

kzpm · April 14, 2020, 9:48pm

Did you try to disable p2p? I understood that p2p causes sometimes problems when > 2 users are joining.

j2l2 · April 15, 2020, 9:30am

@kzpm, thanks but I didn’t change p2p settings.
It was working with the same p2p settings.

j2l2 · April 15, 2020, 12:26pm

My guess is it’s a SSL issue an/or folder rights.

So I restarted from scratch (using latest docker release, 4384) to understand when it starts to work and when it stops.
I noticed a few interesting things in the process:

Folders owner and group are changed a lot. deleting content and keeping original folder structure doesn’t work. prosody/ fails to recreate certs/ and data/ content, (because certs/ and data/ become root property and content can’t be changed by owner systemd-network?)
Restarting with fresh folders, with enable_letsencrypt=1 from start, breaks web/

Better to start without enable_letsencrypt.
Wait for propagation and test http://yousub.domain.net (from docker host since propagation may reach your browser before your server)
Then re-run with enable_letsencrypt.
Browser: Certificate is issued by jitsi.org (OU=Jitsi Server) resulting in NET::ERR_CERT_AUTHORITY_INVALID

This info is deep into the web container:
./etc/cont-init.d/10-config: SUBJECT="/C=US/ST=TX/L=Austin/O=jitsi.org/OU=Jitsi Server/CN="
I never changed it, so why is it popping out now?
Locally it’s at:
./web/rootfs/etc/cont-init.d/10-config: SUBJECT="/C=US/ST=TX/L=Austin/O=jitsi.org/OU=Jitsi Server/CN="

kzpm · April 16, 2020, 10:18am

Maybe an answer from damencho in thies forum can help you:

j2l2 · April 16, 2020, 1:20pm

@kzpm thanks for your help and search, I really appreciate,

It’s finally fixed!
I found multiple errors while I was testing:
We need to enable_letsencrypt to prevent 10-config from using self-signed certs from scratch and keeping them AFTER enabling letsencrypt.
Problem is, sometimes, since nginx files get written AFTER generating the certificate and the challenge is accessing nginx through http to be able to generate, it doesn’t see the website and fail to generate. Do it a few more times and you just burnt your letsencrypt rate limit (I did burn 2 subdomains, and I know I have 50/w for TLD, so I’d better be more careful! Deleting .jitsi-meet/ and docker-compose up -d again without reading the logs is not the solution).
In 10-config, line 10 states # generate keys (maybe) for a reason

DNS settings were also mixed-up. Dev mode must be ON during testing (obvious but forgotten), Proxied records prevented seeing the server for SSL (false negative with valid certificate but issued from DNS, not testing my server in fact), and don’t forget you can’t enforce http tp https while certbot tries to access your http version.

Validating SSL (using https://www.ssllabs.com/ssltest/analyze.html?d=) before going further is paramount.
Need an A+ TLS 1.2 (since actual jitsi docker nginx is not able to do TLS 1.3).

I also noticed I chown(ed) and chmod(ed) 777 some files while it should have stay to 700, so I had to diff every file using ls -al.

I also updated images to last stable version. Not sure if it helped though.

I had to cancel multiple calls and I found sleep at 5:30am. It was 2 horrible days, but I learnt quite some stuff in the process.

Now, I can call back the volunteers to have calls for anxious quarantined people again.
Yep, it was a production platform and I did tests on it. Lord, forgive me.