Frequent disconnections issue

Good morning Community

We are experiencing frequent disconnections even with good network connections, during meetings of no more than 10 participants. Our server is in the United States and has good resources (32Gb RAM, up to 1GB/s of available bandwidth) and most of us connect from Mexico, so RTT shouldn’t be a problem. We are using JVB2.0 with prosody 0.11.3. No turn servers available. Simulcast enabled.

So far the information we have obtained from Analytics is as follows:

error_type=connection.otherError&error_message=giving-up&suspend_time=0&time_since_last_success=null&permanent_browser_name=chrome&permanent_conference_name=1679072350
error_type=connection.otherError&error_message=improper-addressing&suspend_time=0&time_since_last_success=1&permanent_browser_name=chrome&permanent_conference_name=1315313212&permanent_created_ms=1592800477308&permanent_octo_enabled=false
error_type=connection.otherError&error_message=item-not-found&suspend_time=0&time_since_last_success=1&permanent_browser_name=chrome&permanent_conference_name=2343850981&permanent_created_ms=1592799765577&permanent_octo_enabled=false

Also attached jvb logs disconnectErrors.log (1.2 MB) from which I can highlight the following messages:

2020-06-19 16:58:43.038 INFO: [10499] [confId=14eab300dc9167f0 epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu gid=fffed3 conf_name=3230401174 ufrag=7ob9d1eb6o9aeu] Agent.gatherCandidates#662: Gathering candidates for component stream-46c22d1c.RTP.
2020-06-19 16:58:44.163 INFO: [10499] [confId=14eab300dc9167f0 epId=46c22d1c gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174] DtlsTransport.setSetupAttribute#120: The remote side is acting as DTLS server, we'll act as client
2020-06-19 16:58:44.163 INFO: [10499] [confId=14eab300dc9167f0 epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-06-19 16:58:44.164 INFO: [10499] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] Agent.triggerCheck#1773: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7961835276064522239):
	LocalCandidate=candidate:1 1 udp 2130706431 172.31.4.139 10000 typ host
	RemoteCandidate=candidate:10000 1 udp 1853759231 187.191.42.254 20197 typ prflx

2020-06-19 16:58:44.165 INFO: [10499] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b componentId=1 conf_name=3230401174 ufrag=7ob9d1eb6o9aeu name=stream-46c22d1c epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-46c22d1c.RTP: 192.168.100.20:33696/udp
2020-06-19 16:58:44.165 INFO: [10499] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b componentId=1 conf_name=3230401174 ufrag=7ob9d1eb6o9aeu name=stream-46c22d1c epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] Component.updateRemoteCandidates#481: new Pair added: 172.31.4.139:10000/udp/host -> 192.168.100.20:33696/udp/host (stream-46c22d1c.RTP).

2020-06-19 16:58:44.165 INFO: [10499] [confId=14eab300dc9167f0 epId=46c22d1c gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174] Endpoint.describe#1333: Transport description:
 <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='5pqen1p8giq7961ctt6tji4o7s' ufrag='7ob9d1eb6o9aeu'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>E2:A1:81:0C:60:62:3E:29:F0:28:C0:62:7E:40:C0:27:8E:26:07:36:C2:BC:C2:6C:7D:24:55:6E:A4:6B:33:7D</fingerprint><candidate component='1' foundation='1' generation='0' id='2ee3d85256dee4f01c418c11' network='0' priority='2130706431' protocol='udp' type='host' ip='172.31.4.139' port='10000'/><candidate component='1' foundation='2' generation='0' id='503e206356dee4f0ffffffff9300e585' network='0' priority='1694498815' protocol='udp' type='srflx' ip='34.222.93.255' port='10000' rel-addr='172.31.4.139' rel-port='10000'/></transport>
2020-06-19 16:58:44.205 INFO: [10939] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 172.31.4.139:10000/udp/host -> 192.168.100.20:33696/udp/host (stream-46c22d1c.RTP)
2020-06-19 16:58:44.205 INFO: [10938] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 172.31.4.139:10000/udp/host -> 192.168.100.20:33696/udp/host (stream-46c22d1c.RTP)
2020-06-19 16:58:44.293 INFO: [10935] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.4.139:10000/udp/host -> 187.191.42.254:20197/udp/prflx (stream-46c22d1c.RTP).
2020-06-19 16:58:44.294 INFO: [10935] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b componentId=1 conf_name=3230401174 ufrag=7ob9d1eb6o9aeu name=stream-46c22d1c epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 187.191.42.254:20197/udp
2020-06-19 16:58:44.294 INFO: [10935] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 34.222.93.255:10000/udp/srflx -> 187.191.42.254:20197/udp/prflx (stream-46c22d1c.RTP).
2020-06-19 16:58:44.294 INFO: [10944] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.4.139:10000/udp/host -> 187.191.42.254:20197/udp/prflx (stream-46c22d1c.RTP).

Where I have repeatedly found the following errors:

2020-06-19 16:58:44.205 INFO: [10939] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174 ufrag=7ob9d1eb6o9aeu epId=46c22d1c local_ufrag=7ob9d1eb6o9aeu] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 172.31.4.139:10000/udp/host -> 192.168.100.20:33696/udp/host (stream-46c22d1c.RTP)

2020-06-19 16:58:44.393 INFO: [10945] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Chadrick-ymk componentId=1 conf_name=3230401174 ufrag=4ioib1eb6o9avr name=stream-0583844c epId=0583844c local_ufrag=4ioib1eb6o9avr] Component.addUpdateRemoteCandidates#369: Not adding duplicate remote candidate: 192.168.68.104:51197/udp

2020-06-19 16:58:44.745 INFO: [10950] [confId=14eab300dc9167f0 gid=fffed3 conf_name=3230401174] Conference.dominantSpeakerChanged#446: ds_change ds_id=0583844c
Got sctp association state update: 1
sctp is now up.  was ready? false
Got sctp association state update: 1

2020-06-19 16:58:45.912 WARNING: [10950] [confId=14eab300dc9167f0 epId=46c22d1c gid=fffed3 stats_id=Gavin-Q6b conf_name=3230401174] AbstractEndpointMessageTransport.onClientEndpointMessage#219: Unable to find endpoint 4a7ae37a to send EndpointMessage
2020-06-19 16:58:45.946 WARNING: [10948] [confId=14eab300dc9167f0 epId=0583844c gid=fffed3 stats_id=Chadrick-ymk conf_name=3230401174] AbstractEndpointMessageTransport.onClientEndpointMessage#219: Unable to find endpoint 4a7ae37a to send EndpointMessage

2020-06-19 16:58:47.784 INFO: [10939] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Hazle-YQ3 conf_name=3230401174 ufrag=cop5t1eb6o9ecf epId=4a7ae37a local_ufrag=cop5t1eb6o9ecf] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 172.31.4.139:10000/udp/host -> 192.168.100.5:63690/udp/host (stream-4a7ae37a.RTP)
2020-06-19 16:58:47.784 INFO: [10938] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Hazle-YQ3 conf_name=3230401174 ufrag=cop5t1eb6o9ecf epId=4a7ae37a local_ufrag=cop5t1eb6o9ecf] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 172.31.4.139:10000/udp/host -> 192.168.100.5:63690/udp/host (stream-4a7ae37a.RTP)

2020-06-19 17:03:15.348 INFO: [10961] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174 ufrag=5p2cs1eb6oeqt6 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6] ConnectivityCheckClient.processTimeout#857: timeout for pair: 34.222.93.255:10000/udp/srflx -> 189.216.56.47:3626/udp/prflx (stream-543f6c79.RTP), failing.
2020-06-19 17:03:15.895 INFO: [10937] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Kaya-TJe conf_name=3230401174 ufrag=ccam71eb6ohgn3 epId=fcab45ea local_ufrag=ccam71eb6ohgn3] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-06-19 17:03:15.895 INFO: [10937] [confId=14eab300dc9167f0 epId=fcab45ea local_ufrag=ccam71eb6ohgn3 gid=fffed3 stats_id=Kaya-TJe conf_name=3230401174] IceTransport.iceStateChanged#328: ICE state changed old=Completed new=Terminated
2020-06-19 17:03:18.009 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] AbstractEndpoint.expire#301: Expiring.
2020-06-19 17:03:18.010 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] Transceiver.teardown#315: Tearing down
2020-06-19 17:03:18.010 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] RtpReceiverImpl.tearDown#287: Tearing down
2020-06-19 17:03:18.010 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] RtpSenderImpl.tearDown#263: Tearing down
2020-06-19 17:03:18.011 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] DtlsTransport.stop#180: Stopping
2020-06-19 17:03:18.011 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] IceTransport.stop#242: Stopping
2020-06-19 17:03:18.011 INFO: [10972] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Emanuel-HeZ componentId=1 conf_name=3230401174 ufrag=5p2cs1eb6oeqt6 name=stream-543f6c79 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6] MergingDatagramSocket$SocketContainer.runInReaderThread#770: Failed to receive: java.net.SocketException: Socket closed
2020-06-19 17:03:18.011 INFO: [10966] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Emanuel-HeZ componentId=1 conf_name=3230401174 ufrag=5p2cs1eb6oeqt6 name=stream-543f6c79 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6] MergingDatagramSocket.close#142: Closing.
2020-06-19 17:03:18.011 WARNING: [10972] [confId=14eab300dc9167f0 gid=fffed3 stats_id=Emanuel-HeZ componentId=1 conf_name=3230401174 ufrag=5p2cs1eb6oeqt6 name=stream-543f6c79 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6] MergingDatagramSocket.doRemove#349: Removing the active socket. Won't be able to send until a new one is elected.
2020-06-19 17:03:18.011 INFO: [10968] [confId=14eab300dc9167f0 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] IceTransport.startReadingData#201: Socket closed, stopping reader
2020-06-19 17:03:18.012 INFO: [10968] [confId=14eab300dc9167f0 epId=543f6c79 local_ufrag=5p2cs1eb6oeqt6 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] IceTransport.startReadingData#213: No longer running, stopped reading packets
2020-06-19 17:03:18.012 INFO: [10966] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] Endpoint.expire#803: Expired.

After a while the log is filled with the following messages:

2020-06-19 17:03:20.217 INFO: [10982] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] Endpoint.lambda$acceptSctpConnection$6#936: Attempting to establish SCTP socket connection
2020-06-19 17:03:20.539 WARNING: [48] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 13, size is 1000.
2020-06-19 17:03:20.579 WARNING: [54] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 16, size is 1000.
2020-06-19 17:03:20.638 WARNING: [57] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 19, size is 1000.
2020-06-19 17:03:20.678 WARNING: [48] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 21, size is 1000.
2020-06-19 17:03:20.738 WARNING: [48] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 25, size is 1000.
2020-06-19 17:03:20.779 WARNING: [48] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 27, size is 1000.
................
2020-06-19 17:03:20.938 WARNING: [54] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 37, size is 1000. Latest RTT is 126.370728 ms.
2020-06-19 17:03:20.995 WARNING: [55] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 41, size is 1000. Latest RTT is 126.370728 ms.
2020-06-19 17:03:21.038 WARNING: [53] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 43, size is 1000. Latest RTT is 126.370728 ms.
2020-06-19 17:03:21.088 WARNING: [50] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 47, size is 1000. Latest RTT is 126.370728 ms.
020-06-19 17:03:23.397 WARNING: [56] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 183, size is 1000. Latest RTT is 121.28003 ms.
Got sctp association state update: 1
sctp is now up.  was ready? false
................
2020-06-19 17:04:46.976 WARNING: [55] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 5740-5741. Couldn't find packet detail for the seq nums: 5740-5741. Latest seqNum was 16860, size is 1000. Latest RTT is 26332.81482 ms.
2020-06-19 17:04:46.984 WARNING: [57] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 16867, size is 1000. Latest RTT is 26332.81482 ms.
2020-06-19 17:04:47.027 WARNING: [54] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 5742-5748. Couldn't find packet detail for the seq nums: 5742-5748. Latest seqNum was 16879, size is 1000. Latest RTT is 26332.81482 ms.
2020-06-19 17:04:47.037 WARNING: [54] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 16879, size is 1000. Latest RTT is 26332.81482 ms.
2020-06-19 17:04:47.079 WARNING: [49] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 5749-5755. Couldn't find packet detail for the seq nums: 5749-5755. Latest seqNum was 16899, size is 1000. Latest RTT is 26332.81482 ms.
2020-06-19 17:04:47.093 WARNING: [54] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 15311-15340. Couldn't find packet detail for the seq nums: 15311-15340. Latest seqNum was 16901, size is 1000. Latest RTT is 26332.81482 ms.
2020-06-19 17:04:47.125 WARNING: [55] [confId=14eab300dc9167f0 epId=543f6c79 gid=fffed3 stats_id=Emanuel-HeZ conf_name=3230401174] TransportCcEngine.tccReceived#157: TCC packet contained received sequence numbers: 5756-5758. Couldn't find packet detail for the seq nums: 5756-5758. Latest seqNum was 16909, size is 1000. Latest RTT is 26332.81482 ms.

Does anyone know what these messages mean and what could be the cause?

Thank you very much. Regards

Is there a dinamic routing? Does the outgoing traffic address change?

1 Like

@emrah Our installation runs on a AWS instance: prosody, jifico and jvb are running in the same machine. It is configured using nginx like a proxy to prosody’s bosh port, and is using one single fixed ip.

So do you mean if we know if our users have dynamic ip addresses? Or it changes during a single meeting? Actually I don’t know but I will find a way to know that.

Thank you for your response