Unstable connections after some minutes

stagil · October 4, 2019, 11:06am

Hello Jitsi Community,

it’s my first message here.
I install an Jitsi-Meet to an AWS EC2 instance. The installation was fine and the web interface is also functional. It’s possible to meet with other participants in the session, but the connection will be closed after some minutes / sometimes over an hour.
In the jvb.log is something like: “org.ice4j.socket.MergingDatagramSocket.log() Removing the active socket. Won’t be able to send until a new one is elected.” and “org.ice4j.stack.Connector.run() Connector died”.

Any help would be appreciated!

Thank in advance,
Max

stagil · October 7, 2019, 12:15pm

Here’s an extraction of the jvb.log (because i couldn’t upload files as a new users) where a session crashed:

JVB 2019-10-07 14:05:37.779 FINE: [132] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId 5focs-197012).
JVB 2019-10-07 14:05:37.780 FINE: [132] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId 5focs-197012) with: <iq to="focus@auth.meet.stagil.com/focus339710841211865" from="jitsi-videobridge.meet.stagil.com" id="5focs-197012" type="result"/>
JVB 2019-10-07 14:05:40.109 FINE: [134] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId W3omI-107328): <iq id="W3omI-107328" type="result" to="jitsi-videobridge.meet.stagil.com" from="meet.stagil.com"/>
JVB 2019-10-07 14:05:45.052 INFO: [18] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=5b5f0564191d2e47 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9
JVB 2019-10-07 14:05:45.062 INFO: [18] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 10ms. Sticky failure: false
JVB 2019-10-07 14:05:47.779 FINE: [136] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 5focs-197019): <iq type="get" to="jitsi-videobridge.meet.stagil.com" from="focus@auth.meet.stagil.com/focus339710841211865" id="5focs-197019"><healthcheck xml
ns="http://jitsi.org/protocol/healthcheck"/></iq>
JVB 2019-10-07 14:05:47.779 FINE: [136] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId 5focs-197019).
JVB 2019-10-07 14:05:47.780 FINE: [136] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId 5focs-197019) with: <iq to="focus@auth.meet.stagil.com/focus339710841211865" from="jitsi-videobridge.meet.stagil.com" id="5focs-197019" type="result"/>
JVB 2019-10-07 14:05:48.328 FINE: [159] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 5focs-197023): <iq type="get" to="jitsi-videobridge.meet.stagil.com" from="focus@auth.meet.stagil.com/focus339710841211865" id="5focs-197023"><query xmlns="ht
tp://jabber.org/protocol/disco#info"/></iq>
JVB 2019-10-07 14:05:48.328 FINE: [159] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId 5focs-197023).
JVB 2019-10-07 14:05:48.328 FINE: [159] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId 5focs-197023) with: <iq type="result" id="5focs-197023" from="jitsi-videobridge.meet.stagil.com" to="focus@auth.meet.stagil.com/focus339710841211865"><quer
y xmlns="http://jabber.org/protocol/disco#info"><identity category="component" type="conference" name="JitsiVideobridge"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="urn:xmpp:ping"/><feature var="jabber:iq:last"/><feature var="urn:xmpp:time"/><feature var="http://jitsi.org/protocol/colibri
"/><feature var="http://jitsi.org/protocol/healthcheck"/><feature var="urn:xmpp:jingle:apps:dtls:0"/><feature var="urn:xmpp:jingle:transports:ice-udp:1"/><feature var="urn:xmpp:jingle:transports:raw-udp:1"/><feature var="jabber:iq:version"/></query></iq>
JVB 2019-10-07 14:05:50.110 FINE: [165] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId W3omI-107332): <iq id="W3omI-107332" type="result" to="jitsi-videobridge.meet.stagil.com" from="meet.stagil.com"/>
JVB 2019-10-07 14:05:51.796 WARNING: [569550] org.ice4j.stack.Connector.run() Connector died: <internal_ip>:4443/tcp -> <public_ip>:64741/tcp
java.net.SocketException: Failed to receive data from socket.
        at org.ice4j.socket.DelegatingSocket.receiveFromChannel(DelegatingSocket.java:686)
        at org.ice4j.socket.DelegatingSocket.receive(DelegatingSocket.java:648)
        at org.ice4j.socket.MultiplexingSocket.multiplexingXXXSocketSupportDoReceive(MultiplexingSocket.java:339)
        at org.ice4j.socket.MultiplexingSocket.access$000(MultiplexingSocket.java:34)
        at org.ice4j.socket.MultiplexingSocket$1.doReceive(MultiplexingSocket.java:77)
        at org.ice4j.socket.MultiplexingXXXSocketSupport.receive(MultiplexingXXXSocketSupport.java:649)
        at org.ice4j.socket.MultiplexingSocket.receive(MultiplexingSocket.java:419)
        at org.ice4j.socket.MultiplexedSocket.receive(MultiplexedSocket.java:161)
        at org.ice4j.socket.IceTcpSocketWrapper.receive(IceTcpSocketWrapper.java:146)
        at org.ice4j.ice.harvest.AbstractTcpListener$PushBackIceSocketWrapper.receive(AbstractTcpListener.java:775)
        at org.ice4j.stack.Connector.run(Connector.java:207)
        at java.base/java.lang.Thread.run(Thread.java:834)
JVB 2019-10-07 14:05:51.797 WARNING: [569550] org.ice4j.stack.NetAccessManager.handleFatalError() Removing connector:ice4j.Connector@<internal_ip>:4443/tcp status:  running
java.net.SocketException: Failed to receive data from socket.
        at org.ice4j.socket.DelegatingSocket.receiveFromChannel(DelegatingSocket.java:686)
        at org.ice4j.socket.DelegatingSocket.receive(DelegatingSocket.java:648)
        at org.ice4j.socket.MultiplexingSocket.multiplexingXXXSocketSupportDoReceive(MultiplexingSocket.java:339)
        at org.ice4j.socket.MultiplexingSocket.access$000(MultiplexingSocket.java:34)
        at org.ice4j.socket.MultiplexingSocket$1.doReceive(MultiplexingSocket.java:77)
        at org.ice4j.socket.MultiplexingXXXSocketSupport.receive(MultiplexingXXXSocketSupport.java:649)
        at org.ice4j.socket.MultiplexingSocket.receive(MultiplexingSocket.java:419)
        at org.ice4j.socket.MultiplexedSocket.receive(MultiplexedSocket.java:161)
        at org.ice4j.socket.IceTcpSocketWrapper.receive(IceTcpSocketWrapper.java:146)
        at org.ice4j.ice.harvest.AbstractTcpListener$PushBackIceSocketWrapper.receive(AbstractTcpListener.java:775)
        at org.ice4j.stack.Connector.run(Connector.java:207)
        at java.base/java.lang.Thread.run(Thread.java:834)
JVB 2019-10-07 14:05:52.658 INFO: [569551] org.ice4j.socket.MergingDatagramSocket.log() Failed to receive: java.net.SocketException: Failed to receive data from socket.
JVB 2019-10-07 14:05:54.764 INFO: [571574] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=9
JVB 2019-10-07 14:05:55.050 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=8
JVB 2019-10-07 14:05:55.062 INFO: [18] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=54e43cbfd8005ef5 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9
JVB 2019-10-07 14:05:55.070 INFO: [18] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 8ms. Sticky failure: false
JVB 2019-10-07 14:05:55.350 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=7
JVB 2019-10-07 14:05:55.650 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=6
JVB 2019-10-07 14:05:55.944 INFO: [572752] org.ice4j.ice.ConnectivityCheckClient.log() timeout for pair: 3.122.236.158:10000/udp/srflx -> <public_ip>:63010/udp/prflx (stream.RTP), failing.
JVB 2019-10-07 14:05:55.950 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=5
JVB 2019-10-07 14:05:56.250 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=4
JVB 2019-10-07 14:05:56.550 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=3
JVB 2019-10-07 14:05:56.850 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=2
JVB 2019-10-07 14:05:57.150 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=1
JVB 2019-10-07 14:05:57.450 INFO: [569597] org.jitsi.impl.neomedia.rtp.translator.RTCPFeedbackMessageSender.log() Sending a FIR to ssrc=2763706539 remainingRetries=0
JVB 2019-10-07 14:05:57.780 FINE: [185] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 5focs-197033): <iq type="get" to="jitsi-videobridge.meet.stagil.com" from="focus@auth.meet.stagil.com/focus339710841211865" id="5focs-197033"><healthcheck xmlns="http://jitsi.org/protocol/healthcheck"/></iq>
JVB 2019-10-07 14:05:57.780 FINE: [185] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId 5focs-197033).
JVB 2019-10-07 14:05:57.780 FINE: [185] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId 5focs-197033) with: <iq to="focus@auth.meet.stagil.com/focus339710841211865" from="jitsi-videobridge.meet.stagil.com" id="5focs-197033" type="result"/>
JVB 2019-10-07 14:05:58.944 INFO: [572752] org.ice4j.ice.ConnectivityCheckClient.log() timeout for pair: 3.122.236.158:10000/udp/srflx -> <public_ip>:63010/udp/prflx (stream.RTP), failing.
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 1
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 1
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 0
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 0
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking: 0
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late: 0
JVB 2019-10-07 14:05:59.482 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late by more than MAX_SIZE: 0
JVB 2019-10-07 14:05:59.483 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 0
JVB 2019-10-07 14:05:59.483 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 4
JVB 2019-10-07 14:05:59.483 INFO: [569576] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was enabled
JVB 2019-10-07 14:05:59.483 INFO: [569576] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
JVB 2019-10-07 14:06:00.110 FINE: [179] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId W3omI-107336): <iq id="W3omI-107336" type="result" to="jitsi-videobridge.meet.stagil.com" from="meet.stagil.com"/>
JVB 2019-10-07 14:06:01.945 INFO: [572752] org.ice4j.ice.ConnectivityCheckClient.log() timeout for pair: 3.122.236.158:10000/udp/srflx -> <public_ip>:63010/udp/prflx (stream.RTP), failing.
JVB 2019-10-07 14:06:04.945 INFO: [572752] org.ice4j.ice.ConnectivityCheckClient.log() timeout for pair: 3.122.236.158:10000/udp/srflx -> <public_ip>:63010/udp/prflx (stream.RTP), failing.
JVB 2019-10-07 14:06:05.070 INFO: [18] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=74d4ba370ca437d5 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9
JVB 2019-10-07 14:06:05.081 INFO: [18] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 11ms. Sticky failure: false
JVB 2019-10-07 14:06:07.779 FINE: [183] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 5focs-197038): <iq type="get" to="jitsi-videobridge.meet.stagil.com" from="focus@auth.meet.stagil.com/focus339710841211865" id="5focs-197038"><healthcheck xmlns="http://jitsi.org/protocol/healthcheck"/></iq>

stagil · October 14, 2019, 11:28am

Hello Jitsi community,

i want to push this answer, because we are on the edge to decide for or against jitsi and want look for other alternatives if it won’t work. We did a lot of testing and it would be a Bummer if it’s blocked by a problem like this momentary.

Best,
Max

NathanDo · January 15, 2020, 2:26pm

I have the same issue, any one encounter this ? Once this happens, how to recover or at least retry ?