Bridges get lost under load

Hello,

I’m running a scallable setup with standalone installations - not in docker. One jitsi meet server handles 13-15 JVBs. Every machine in this setup is 4 Cores, 8 Gb RAM. HAProxy in front of this farm makes sure that all meet servers get some work to do and it happens pretty fair. It also ensures, that users of one conference land on the same meet server. So each meet server handles around 100 conferences with like 80-100 users on a single JVB. At a spike times, when total number of users rapidly grows (say from 2000 to 3500 within 2 minutes), it happens that one or other meet server looses connection to all his JVB at the same moment of time - it says “One of our bridges failed” for each connected JVB. All users of this meet server are kicked out and cannot reconnect quickly. For certain period of time meet reports “Can not invite participant – no bridge available”.

Further on, during the day when there is already no such big load (just 30-40 users per JVB) and also no spike changes in users count, it still happens than one or another bridge is lost from time to time. Installation runs the most recent stable version of apps.

Below is extract of meet log around a time, when this happens (domain & IP addresses - obfuscated).
Meet (see record at 10:38:45.439)

Jicofo 2021-02-18 10:38:43.397 WARNING: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No jingle session yet for msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com/37f39109
Jicofo 2021-02-18 10:38:43.897 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@74400cc6 member=ChatMember[msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c, jid: null]@697605859]
Jicofo 2021-02-18 10:38:43.897 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c joined.
Jicofo 2021-02-18 10:38:43.898 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c, bridge=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-jssnq
Jicofo 2021-02-18 10:38:43.898 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=77539: [[null, null, null, null, null, null, null, null, null, null, null, null, null]]
Jicofo 2021-02-18 10:38:43.899 INFO: [1854] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c
Jicofo 2021-02-18 10:38:43.899 INFO: [1854] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c in 1
Jicofo 2021-02-18 10:38:43.899 INFO: [1854] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-jssnq to allocate channels for: Participant[msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c]@1559105172
Jicofo 2021-02-18 10:38:44.071 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@43bdead7 member=ChatMember[msg-604f4da1-c077-4776-8f12-95c95f2888ee@conference.meet.mydomain.com/183e27a1, jid: null]@1850684663]
Jicofo 2021-02-18 10:38:44.071 WARNING: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Focus role unknown
Jicofo 2021-02-18 10:38:44.072 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Obtained focus role: OWNER
Jicofo 2021-02-18 10:38:44.216 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member msg-604f4da1-c077-4776-8f12-95c95f2888ee@conference.meet.mydomain.com/183e27a1 joined.
Jicofo 2021-02-18 10:38:44.219 INFO: [1854] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: msg-20fbc693-15ba-4b66-9f3a-9e6b7ff1ca2d@conference.meet.mydomain.com/75a74f6c
Jicofo 2021-02-18 10:38:44.414 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com/37f39109
Jicofo 2021-02-18 10:38:44.419 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com/37f39109 with accepted sources:Sources{ audio: [ssrc=3567603206 ] }@458919635
Jicofo 2021-02-18 10:38:44.420 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: msg-d6f48585-5396-4a1e-9ccf-8f08af75dc32@conference.meet.mydomain.com/621cd882
Jicofo 2021-02-18 10:38:44.425 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from msg-d6f48585-5396-4a1e-9ccf-8f08af75dc32@conference.meet.mydomain.com/621cd882 with accepted sources:Sources{ video: [ssrc=3673454136 ssrc=2028597808 ssrc=2560759716 ] audio: [ssrc=359732348 ] }@1462301135
Jicofo 2021-02-18 10:38:44.775 INFO: [55] org.jitsi.jicofo.xmpp.IqHandler.log() Logout IQ received: <iq to='focus.meet.mydomain.com' from='46af5e4c-8de0-4820-b811-426b537ce86c@guest.meet.mydomain.com/XBbkReJ3' id='f9af4b66-da8f-407c-b7c8-0ecbc337efa8:sendIQ' type='set'><conference xmlns='http://jitsi.org/protocol/focus' room='dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com' machine-uid='fd02312c8e4b6174eb7daf30c68f6b47'><property xmlns='http://jitsi.org/protocol/focus' name='disableRtx' value='false'/></conference></iq>
Jicofo 2021-02-18 10:38:44.775 INFO: [55] org.jitsi.jicofo.xmpp.ConferenceIqHandler.log() Focus request for room: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com
Jicofo 2021-02-18 10:38:44.809 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: msg-96b8ada0-fd47-40e0-add5-54f2ecd7c2a1@conference.meet.mydomain.com/2ddd1695
Jicofo 2021-02-18 10:38:44.822 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from msg-96b8ada0-fd47-40e0-add5-54f2ecd7c2a1@conference.meet.mydomain.com/2ddd1695 with accepted sources:Sources{ video: [ssrc=1898467920 ssrc=114626701 ssrc=4140874370 ] audio: [ssrc=2495614679 ] }@632142180
Jicofo 2021-02-18 10:38:45.163 INFO: [50] org.jitsi.jicofo.xmpp.IqHandler.log() Logout IQ received: <iq to='focus.meet.mydomain.com' from='df64b924-a72f-4af2-a8e1-4b3cf6574ce8@guest.meet.mydomain.com/01Y2SCHa' id='4a1315e2-2e96-4dba-bcaf-46668d182749:sendIQ' type='set'><conference xmlns='http://jitsi.org/protocol/focus' room='msg-96b8ada0-fd47-40e0-add5-54f2ecd7c2a1@conference.meet.mydomain.com' machine-uid='97fc349e53f2da090df4a062a3b59dfe'><property xmlns='http://jitsi.org/protocol/focus' name='disableRtx' value='false'/></conference></iq>
Jicofo 2021-02-18 10:38:45.163 INFO: [50] org.jitsi.jicofo.xmpp.ConferenceIqHandler.log() Focus request for room: msg-96b8ada0-fd47-40e0-add5-54f2ecd7c2a1@conference.meet.mydomain.com
Jicofo 2021-02-18 10:38:45.379 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@47ea70f0 member=ChatMember[dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c, jid: null]@1919168633]
Jicofo 2021-02-18 10:38:45.380 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c joined.
Jicofo 2021-02-18 10:38:45.380 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c, bridge=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc
Jicofo 2021-02-18 10:38:45.380 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null, null, null, null]]
Jicofo 2021-02-18 10:38:45.380 INFO: [1852] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c
Jicofo 2021-02-18 10:38:45.381 INFO: [1852] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c in 1
Jicofo 2021-02-18 10:38:45.381 INFO: [1852] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc to allocate channels for: Participant[dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c]@1730155427
Jicofo 2021-02-18 10:38:45.438 SEVERE: [1852] org.jitsi.jicofo.AbstractChannelAllocator.log() jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc - conference ID not found (expired?):null
Jicofo 2021-02-18 10:38:45.439 SEVERE: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() One of our bridges failed: jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc
Jicofo 2021-02-18 10:38:45.439 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null, null, null]]
Jicofo 2021-02-18 10:38:45.439 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870 on: Bridge[jid=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc, relayId=null, region=null, stress=0.33]
Jicofo 2021-02-18 10:38:45.440 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null, null]]
Jicofo 2021-02-18 10:38:45.440 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636 on: Bridge[jid=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc, relayId=null, region=null, stress=0.33]
Jicofo 2021-02-18 10:38:45.440 WARNING: [1852] org.jitsi.jicofo.AbstractParticipant.log() Canceling ParticipantChannelAllocator[BridgeSession[id=99858_7954a2, bridge=Bridge[jid=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-yefzc, relayId=null, region=null, stress=0.33]]@520489821, Participant[dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c]@1730155427]@930327647
Jicofo 2021-02-18 10:38:45.440 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null]]
Jicofo 2021-02-18 10:38:45.441 INFO: [1852] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Selected initial bridge Bridge[jid=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn, relayId=null, region=null, stress=0.19] with reported stress=0.18544 for participantRegion=null using strategy SingleBridgeSelectionStrategy
Jicofo 2021-02-18 10:38:45.441 INFO: [1852] org.jitsi.impl.protocol.xmpp.colibri.OperationSetColibriConferenceImpl.log() Conference created: org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl@6690154c
Jicofo 2021-02-18 10:38:45.442 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870, bridge=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn
Jicofo 2021-02-18 10:38:45.442 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null, null]]
Jicofo 2021-02-18 10:38:45.442 INFO: [1854] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870
Jicofo 2021-02-18 10:38:45.442 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636, bridge=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn
Jicofo 2021-02-18 10:38:45.443 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null, null, null]]
Jicofo 2021-02-18 10:38:45.443 INFO: [1834] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636
Jicofo 2021-02-18 10:38:45.443 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c, bridge=jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn
Jicofo 2021-02-18 10:38:45.443 INFO: [1854] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870 in 0
Jicofo 2021-02-18 10:38:45.443 INFO: [1852] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=99858: [[null, null, null, null]]
Jicofo 2021-02-18 10:38:45.443 INFO: [1848] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c
Jicofo 2021-02-18 10:38:45.443 INFO: [1848] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c in 0
Jicofo 2021-02-18 10:38:45.444 INFO: [1848] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn to allocate channels for: Participant[dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c]@1730155427
Jicofo 2021-02-18 10:38:45.444 INFO: [1834] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636 in 0
Jicofo 2021-02-18 10:38:45.444 INFO: [1834] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn to allocate channels for: Participant[dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636]@898223115
Jicofo 2021-02-18 10:38:45.444 INFO: [1854] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet.mydomain.com/de-jitsi-lgcrf-cylvn to allocate channels for: Participant[dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870]@663940560
Jicofo 2021-02-18 10:38:45.503 INFO: [1848] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/46af5e4c
Jicofo 2021-02-18 10:38:45.531 INFO: [1854] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending transport-replace to: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870
Jicofo 2021-02-18 10:38:45.531 INFO: [1854] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() RE-INVITE PEER: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/307f5870
Jicofo 2021-02-18 10:38:45.534 INFO: [1834] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending transport-replace to: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636
Jicofo 2021-02-18 10:38:45.535 INFO: [1834] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() RE-INVITE PEER: dsc-abb69fac-5571-49e6-9b24-b2c05d73c86d@conference.meet.mydomain.com/b9b67636
Jicofo 2021-02-18 10:38:46.779 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@4f2c783 member=ChatMember[msg-703614ae-ab44-4c23-b229-9e8f2bf86e2b@conference.meet.mydomain.com/8bed8947, jid: 8bed8947-3598-49d0-9e8d-ab9748ffb707@guest.meet.mydomain.com/Thq1PuXa]@546374481]
Jicofo 2021-02-18 10:38:46.780 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member msg-703614ae-ab44-4c23-b229-9e8f2bf86e2b@conference.meet.mydomain.com/8bed8947 is leaving

Related JVB:

 2021-02-18 10:38:43.490 INFO: [4505] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
 2021-02-18 10:38:43.490 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=f0db31euqbgnp5 epId=7a5d6f1a local_ufrag=f0db31euqbgnp5] Agent.logCandTypes#1986: Harvester used for selected pair for stream-7a5d6f1a.RTP: host
 2021-02-18 10:38:43.513 INFO: [4505] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] TlsServerImpl.notifyClientVersion#191: Negotiated DTLS version DTLS 1.2
 2021-02-18 10:38:43.554 INFO: [4505] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint.lambda$setupDtlsTransport$2#442: DTLS handshake complete
 2021-02-18 10:38:43.554 INFO: [4680] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint.lambda$acceptSctpConnection$8#953: Attempting to establish SCTP socket connection
 2021-02-18 10:38:43.654 INFO: [4680] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$5.onReady#895: SCTP connection is ready, creating the Data channel stack
 2021-02-18 10:38:43.654 INFO: [4680] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$5.onReady#922: Will wait for the remote side to open the data channel.
 2021-02-18 10:38:43.654 INFO: [4659] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
 2021-02-18 10:38:43.655 INFO: [4659] [confId=ed474f60031f2396 epId=7a5d6f1a gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$5.lambda$onReady$1#903: Remote side opened a data channel.
 2021-02-18 10:38:43.662 WARNING: [71] [confId=9d68378e0182d57b epId=f6125c70 gid=74223 stats_id=Tara-wPb conf_name=msg-354fd25a-2b85-44be-af71-d668883587a0@conference.meet.mydomain.com] SendSideBandwidthEstimation.getRttMs#598: RTT suspiciously high (1153ms), capping to 1000ms.
 2021-02-18 10:38:43.866 INFO: [4734] [confId=5dfc0b7fb7b0fd51 gid=66112 conf_name=dsc-30bb573b-891b-4585-910d-84628514bb2f@conference.meet.mydomain.com] Conference.dominantSpeakerChanged#420: ds_change ds_id=d70f9954
 2021-02-18 10:38:44.116 INFO: [4695] [confId=46f70fc367c741c5 gid=100283 conf_name=msg-344129fc-f3a9-474f-9fb7-21b8c6fd1306@conference.meet.mydomain.com] Conference.dominantSpeakerChanged#420: ds_change ds_id=b0690dc3
 2021-02-18 10:38:44.169 INFO: [4695] [confId=ed474f60031f2396 gid=106603 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Conference.dominantSpeakerChanged#420: ds_change ds_id=7a5d6f1a
 2021-02-18 10:38:44.172 INFO: [4708] [confId=ed474f60031f2396 gid=106603 stats_id=Mayra-Mgd conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=4jf2a1euqb9g2t epId=a29e262f local_ufrag=4jf2a1euqb9g2t] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 158.181.*.*:40963/udp/prflx (stream-a29e262f.RTP), failing.
 2021-02-18 10:38:44.343 INFO: [4708] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=69ec51euqbcpbl epId=a3564a41 local_ufrag=69ec51euqbcpbl] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 89.247.*.*:3002/udp/prflx (stream-a3564a41.RTP), failing.
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DtlsTransport.setSetupAttribute#120: The remote side is acting as DTLS client, we'll act as server
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Component.addRemoteCandidate#330: Add remote candidate for stream-37f39109.RTP: 192.168.*.*:61127/udp/host
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 epId=37f39109 local_ufrag=7bgrl1euqbgs6j gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] IceTransport.startConnectivityEstablishment#178: Starting the agent with remote candidates.
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.startConnectivityEstablishment#713: Start ICE connectivity establishment.
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.initCheckLists#949: Init checklist for stream stream-37f39109
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.setState#923: ICE state changed from Waiting to Running.
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 epId=37f39109 local_ufrag=7bgrl1euqbgs6j gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] IceTransport.iceStateChanged#323: ICE state changed old=Waiting new=Running
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.startConnectivityEstablishment#735: Trigger checks for pairs that were received before running state
 2021-02-18 10:38:44.427 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.triggerCheck#1714: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7926369428998979583):
 2021-02-18 10:38:44.428 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
 2021-02-18 10:38:44.453 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-37f39109.RTP: 192.168.*.*:61127/udp
 2021-02-18 10:38:44.453 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Component.addUpdateRemoteCandidates#369: Not adding duplicate remote candidate: 192.168.*.*:61127/udp
 2021-02-18 10:38:44.453 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-37f39109.RTP: 192.168.*.*:61127/udp
 2021-02-18 10:38:44.453 INFO: [37] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Component.addUpdateRemoteCandidates#369: Not adding duplicate remote candidate: 192.168.*.*:61127/udp
 2021-02-18 10:38:44.468 INFO: [4712] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.2.*.*:10000/udp/host -> 192.168.*.*:61127/udp/host (stream-37f39109.RTP)
 2021-02-18 10:38:44.477 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 181.109.*.*:10000/udp/host -> 89.247.*.*:2983/udp/prflx (stream-37f39109.RTP).
 2021-02-18 10:38:44.477 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 89.247.*.*:2983/udp
 2021-02-18 10:38:44.477 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 181.109.*.*:10000/udp/host -> 89.247.*.*:2983/udp/prflx (stream-37f39109.RTP).
 2021-02-18 10:38:44.478 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 181.109.*.*:10000/udp/host -> 89.247.*.*:2983/udp/prflx (stream-37f39109.RTP).
 2021-02-18 10:38:44.478 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.nominate#1787: verify if nominated pair answer again
 2021-02-18 10:38:44.478 WARNING: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj componentId=1 conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] MergingDatagramSocket.initializeActive#599: Active socket already initialized.
 2021-02-18 10:38:44.478 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
 2021-02-18 10:38:44.509 INFO: [4717] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 181.109.*.*:10000/udp/host -> 192.168.*.*:61127/udp/host (stream-37f39109.RTP)
 2021-02-18 10:38:44.519 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 181.109.*.*:10000/udp/host -> 89.247.*.*:2983/udp/prflx (stream-37f39109.RTP).
 2021-02-18 10:38:44.519 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
 2021-02-18 10:38:44.519 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 181.109.*.*:10000/udp/host -> 89.247.*.*:2983/udp/prflx (stream-37f39109.RTP).
 2021-02-18 10:38:44.520 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j name=stream-37f39109 epId=37f39109 local_ufrag=7bgrl1euqbgs6j] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-37f39109.RTP: 181.109.*.*:10000/udp/host -> 89.247.*.*:2983/udp/prflx (stream-37f39109.RTP)
 2021-02-18 10:38:44.520 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.checkListStatesUpdated#1878: CheckList of stream stream-37f39109 is COMPLETED
 2021-02-18 10:38:44.520 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.setState#923: ICE state changed from Running to Completed.
 2021-02-18 10:38:44.520 INFO: [4699] [confId=ed474f60031f2396 epId=37f39109 local_ufrag=7bgrl1euqbgs6j gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] IceTransport.iceStateChanged#323: ICE state changed old=Running new=Completed
 2021-02-18 10:38:44.520 INFO: [4699] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$4.connected#411: ICE connected
 2021-02-18 10:38:44.520 INFO: [4659] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
 2021-02-18 10:38:44.520 INFO: [4699] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.logCandTypes#1986: Harvester used for selected pair for stream-37f39109.RTP: host
 2021-02-18 10:38:44.520 INFO: [4659] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] TlsServerImpl.notifyClientVersion#191: Negotiated DTLS version DTLS 1.2
 2021-02-18 10:38:44.554 INFO: [4659] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint.lambda$setupDtlsTransport$2#442: DTLS handshake complete
 2021-02-18 10:38:44.555 INFO: [4734] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint.lambda$acceptSctpConnection$8#953: Attempting to establish SCTP socket connection
 2021-02-18 10:38:44.655 INFO: [4734] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$5.onReady#895: SCTP connection is ready, creating the Data channel stack
 2021-02-18 10:38:44.655 INFO: [4734] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$5.onReady#922: Will wait for the remote side to open the data channel.
 2021-02-18 10:38:44.655 SEVERE: [4733] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 0
 2021-02-18 10:38:44.655 SEVERE: [4733] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 0
 2021-02-18 10:38:44.655 INFO: [4733] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
 2021-02-18 10:38:44.655 INFO: [4733] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] Endpoint$5.lambda$onReady$1#903: Remote side opened a data channel.
 2021-02-18 10:38:45.203 INFO: [4722] [confId=ed474f60031f2396 gid=106603 stats_id=Philip-CrF conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=dg8s91euqb20pj epId=8ba5a174 local_ufrag=dg8s91euqb20pj] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 188.103.*.*:54246/udp/prflx (stream-8ba5a174.RTP), failing.
 2021-02-18 10:38:45.316 INFO: [4521] [confId=46f70fc367c741c5 gid=100283 conf_name=msg-344129fc-f3a9-474f-9fb7-21b8c6fd1306@conference.meet.mydomain.com] Conference.dominantSpeakerChanged#420: ds_change ds_id=a31648b8
 2021-02-18 10:38:46.267 INFO: [4740] [confId=9d68378e0182d57b gid=74223 conf_name=msg-354fd25a-2b85-44be-af71-d668883587a0@conference.meet.mydomain.com] Conference.dominantSpeakerChanged#420: ds_change ds_id=53fa917a
 2021-02-18 10:38:46.406 INFO: [4708] [confId=fe0fd0455c3c7a4d gid=115211 stats_id=Afton-pGN conf_name=dsc-b7e973e6-e674-46b2-869c-5cd19aa67e71@conference.meet.mydomain.com ufrag=3tqfk1euqaihra epId=b27985d1 local_ufrag=3tqfk1euqaihra] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 46.80.*.*:59140/udp/prflx (stream-b27985d1.RTP), failing.
 2021-02-18 10:38:46.490 INFO: [55] [confId=ed474f60031f2396 gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=f0db31euqbgnp5 epId=7a5d6f1a local_ufrag=f0db31euqbgnp5] Agent.setState#923: ICE state changed from Completed to Terminated.
 2021-02-18 10:38:46.490 INFO: [55] [confId=ed474f60031f2396 epId=7a5d6f1a local_ufrag=f0db31euqbgnp5 gid=106603 stats_id=Dan-mcA conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] IceTransport.iceStateChanged#323: ICE state changed old=Completed new=Terminated
 2021-02-18 10:38:46.817 INFO: [4740] [confId=46f70fc367c741c5 gid=100283 conf_name=msg-344129fc-f3a9-474f-9fb7-21b8c6fd1306@conference.meet.mydomain.com] Conference.dominantSpeakerChanged#420: ds_change ds_id=b0690dc3
 2021-02-18 10:38:47.172 INFO: [4708] [confId=ed474f60031f2396 gid=106603 stats_id=Mayra-Mgd conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=4jf2a1euqb9g2t epId=a29e262f local_ufrag=4jf2a1euqb9g2t] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 158.181.*.*:40963/udp/prflx (stream-a29e262f.RTP), failing.
 2021-02-18 10:38:47.343 INFO: [4708] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=69ec51euqbcpbl epId=a3564a41 local_ufrag=69ec51euqbcpbl] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 89.247.*.*:3002/udp/prflx (stream-a3564a41.RTP), failing.
 2021-02-18 10:38:47.520 INFO: [55] [confId=ed474f60031f2396 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=7bgrl1euqbgs6j epId=37f39109 local_ufrag=7bgrl1euqbgs6j] Agent.setState#923: ICE state changed from Completed to Terminated.
 2021-02-18 10:38:47.521 INFO: [55] [confId=ed474f60031f2396 epId=37f39109 local_ufrag=7bgrl1euqbgs6j gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] IceTransport.iceStateChanged#323: ICE state changed old=Completed new=Terminated
 2021-02-18 10:38:48.204 INFO: [4708] [confId=ed474f60031f2396 gid=106603 stats_id=Philip-CrF conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com ufrag=dg8s91euqb20pj epId=8ba5a174 local_ufrag=dg8s91euqb20pj] ConnectivityCheckClient.processTimeout#860: timeout for pair: 181.109.*.*:10000/udp/host -> 188.103.*.*:54246/udp/prflx (stream-8ba5a174.RTP), failing.
 2021-02-18 10:38:48.375 INFO: [24] HealthChecker.run#170: Performed a successful health check in PT0S. Sticky failure: false
 2021-02-18 10:38:48.677 WARNING: [71] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=100, Ssrc=1707244814, SeqNum=9907, M=true, X=true, Ts=4198811873, sources=
 2021-02-18 10:38:48.679 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=100, Ssrc=3489953774, SeqNum=7789, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.681 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16543, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.715 WARNING: [71] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=100, Ssrc=1707244814, SeqNum=9908, M=true, X=true, Ts=4198817723, sources=
 2021-02-18 10:38:48.716 WARNING: [71] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=100, Ssrc=3489953774, SeqNum=7790, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.716 WARNING: [71] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16544, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.814 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16545, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.815 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16546, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.815 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16547, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.815 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16548, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.815 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16550, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.816 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16549, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.817 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16551, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.817 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16552, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.818 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16554, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.818 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16553, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.819 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16556, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.819 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16555, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.819 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16558, M=true, X=true, Ts=591877481, sources=
 2021-02-18 10:38:48.819 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16557, M=true, X=true, Ts=591883331, sources=
 2021-02-18 10:38:48.820 WARNING: [65] [confId=ed474f60031f2396 epId=37f39109 gid=106603 stats_id=Henry-hnj conf_name=msg-dac519e6-a045-4a03-935f-cfe39c53f791@conference.meet.mydomain.com] VideoParser.transform#77: Unable to find encoding matching packet! packet=RtpPacket: PT=96, Ssrc=2634151745, SeqNum=16559, M=true, X=true, Ts=591883331, sources=2

I don’t think, that hardware resources might be the bottleneck. On meet servers CPU is max 25% and memory - 50% used. On JVB it depends on number of users, but memory reaches like 25%, CPU 50-70%.

Do you have any idea, where is the problem and how it can be solved?

@brjasha hi, I don’t have solution to your question but I want ask can you share your haproxy config for your setup? It sound very good. I want do the same

Since you have 4 cores and Prosody can only use 1 core, 25% CPU load can be symptom of a Prosody failure

Here you go. We use also MaxMind GeoIP database to lead DE users to servers, located in Germany and all others - to Austrian servers. There are two HAProxies running to ensure, that stick table survives server restart. Finally, we have specially named rooms, therefore you can see regexes to parse it. Name is composed of 3 chars, minus, GUID. Like this: msg-8F2D44B9-5EC7-4E5E-9191-E7DB88269C4A. For other room names you have to rewrite the regex, which finds room name either in URL or in ?room=… parameter.
So if room isn’t yet in stick table, user goes to “jitsi-meet-de” or “jitsi-meet-at” backend, if room is found - then to “jitsi-meet”, where all servers are listed.

haproxy.txt (4.6 KB)

This config was inspired by GitHub - hpi-schul-cloud/jitsi-deployment: Auto-scalable Jitsi Meet for Kubernetes

1 Like

Oh wow. This sounds like really good idea… Thank you! Though, I haven’t seen any errors in prosody logs…
But for today I reworked our setup to 17 meet servers, having each just 6 JVBs (instead of 8x13). CPU of meet servers didn’t go above 15% and there were no errors, like mentioned. Even though we had 700 conferences with 6000 users in total.

While the second farm I have kept configured, like yesterday and when CPU crossed 25% - all bridges were lost :worried: I will google, but do you maybe know a solution for this? Is it possible to allow more CPU for prosody?

What is the prosody version? If it’s 0.10.x, upgrading to 0.11.x may help

It’s the 0.11.7-1~bionic4

Then I have no solution/suggestion for now

@brjasha thank you

There is new release prosody 0.11.8 with few performance improvements that we helped track down and fix and were running those for months on meet.jit.si. So that is one improvement you can make.
The other is keeping 4000-4500 participants per shard.

thank you! will give a try with new prosody version.

I wonder, how did you manage 4000 on one shard? Can it be, that websockets use less resources, than WebRTC? Because we are running the later and can’t handle more than 1000 users on one shard.

How many JVBs should I put on one Meet server? We tried to keep not more than 100 users on one JVB. So for 1000 users we were running 10 JVBs, connected to one meet server. Maybe this also increases CPU usage of prosody? Should we try to decrease number of JVBs via using more powerful hardware for it (=more users on one JVB)?

in the context of these “meet servers” (17x6 or 8x13) → are these “full stack shards” with (1x prosody, 1x jicofo, 1x meet-web, 6x JVB (or 13) and haproxy infront?. is OCTO enabled in this setup? curious regarding the 100 users per videobridge, is there way to set a limit per bridge?

yes, you are right. one machine with jicofo, meet-web and prosody + X JVB machines - that’s what I call shard. So I’m running number of such shards and in front of them there is haproxy.
OCTO is not enabled, I couldn’t manage it to work - see Octo is not working properly until Jicofo restart

curious regarding the 100 users per videobridge, is there way to set a limit per bridge?

I don’t know about such possibility. So we are only trying to have this number by manipulating number of JVBs. Jitsi does pretty good job in load-balancing work between its JVBs - even without OCTO.

thanks, that is good to know!

hmm regarding OCTO, i am using it without issues, though i rarely need it in my use case (yet).
the “null” sounds familiar though hmm… double check if you dont have an empty space or like after the MUC_NICKNAME=someuniqueidentifier

It means, one full conference will be on one shard. The load of one large conference will not be shared…

How the Mobile clients and web clients are going to deal with 4000 participatns… ? currently they die at less than 100 participatns…

thanks, config seems to be correct. As mentioned in the other topic, restart of jicofo makes bridges to connect with non-null region. But then new bridges might get connected with null again.

Right. I would love to have OCTO enabled, though, our biggest conference was 70 users. So it is still OK.

4000 does not mean in one conference. We have a limit of 100 participants in a meeting and we are working on increasing that. 4000 per shard total … and that is spread on 10-15 bridges with octo, depending on the jvb machine.

websockets scales better than sctp datachannels. It also behaves better than bosh for the signalling, on meet.jit.si all web participants are using websockets only mobile is still on bosh.

thanks for sharing your deployment experience brjasha. When you say 100 users per JVB, does that mean each user is video enabled?