Videobridge Failing on Heavy Load

Hi,

We are facing some issues under heavy load and I found that the video bridge will start to fail when there is a “A client tran retransmission failed”. Eventually Jicofo will detect as the videobridge as faulty.

Here are the logs:

JVB

2020-05-20 00:57:28.177 INFO: [67169] org.ice4j.stack.StunClientTransaction$Retransmitter.run: A client tran retransmission failed
java.nio.channels.ClosedByInterruptException
	at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:475)
	at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
	at java.nio.channels.Channels.writeFully(Channels.java:98)
	at java.nio.channels.Channels.access$000(Channels.java:61)
	at java.nio.channels.Channels$1.write(Channels.java:174)
	at org.ice4j.socket.TCPOutputStream.write(TCPOutputStream.java:95)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:740)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:732)
	at org.ice4j.socket.IceTcpSocketWrapper.send(IceTcpSocketWrapper.java:166)
	at org.ice4j.ice.harvest.AbstractTcpListener$PushBackIceSocketWrapper.send(AbstractTcpListener.java:785)
	at org.ice4j.stack.Connector.sendMessage(Connector.java:328)
	at org.ice4j.stack.NetAccessManager.sendMessage(NetAccessManager.java:654)
	at org.ice4j.stack.NetAccessManager.sendMessage(NetAccessManager.java:600)
	at org.ice4j.stack.StunClientTransaction.sendRequest0(StunClientTransaction.java:267)
	at org.ice4j.stack.StunClientTransaction.access$600(StunClientTransaction.java:51)
	at org.ice4j.stack.StunClientTransaction$Retransmitter.run(StunClientTransaction.java:473)
	at org.ice4j.util.PeriodicRunnable.executeRun(PeriodicRunnable.java:206)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
2020-05-20 00:57:28.179 INFO: [67144] org.ice4j.stack.StunClientTransaction$Retransmitter.run: A client tran retransmission failed
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:267)
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:458)
	at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
	at java.nio.channels.Channels.writeFully(Channels.java:98)
	at java.nio.channels.Channels.access$000(Channels.java:61)
	at java.nio.channels.Channels$1.write(Channels.java:174)
	at org.ice4j.socket.TCPOutputStream.write(TCPOutputStream.java:95)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:740)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:732)
	at org.ice4j.socket.IceTcpSocketWrapper.send(IceTcpSocketWrapper.java:166)
	at org.ice4j.ice.harvest.AbstractTcpListener$PushBackIceSocketWrapper.send(AbstractTcpListener.java:785)
	at org.ice4j.stack.Connector.sendMessage(Connector.java:328)
	at org.ice4j.stack.NetAccessManager.sendMessage(NetAccessManager.java:654)
	at org.ice4j.stack.NetAccessManager.sendMessage(NetAccessManager.java:600)
	at org.ice4j.stack.StunClientTransaction.sendRequest0(StunClientTransaction.java:267)
	at org.ice4j.stack.StunClientTransaction.access$600(StunClientTransaction.java:51)
	at org.ice4j.stack.StunClientTransaction$Retransmitter.run(StunClientTransaction.java:473)
	at org.ice4j.util.PeriodicRunnable.executeRun(PeriodicRunnable.java:206)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
2020-05-20 00:57:28.179 SEVERE: [67297] [confId=b961fd04d8238883 epId=3b2f4121 local_ufrag=mcou1e8npam0m gid=ff37a0 stats_id=Brent-ju7 conf_name=514196c2-958d-3632-551f-d0ed818d870c] IceTransport.send#225: Error sending packet
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:267)
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:458)
	at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
	at java.nio.channels.Channels.writeFully(Channels.java:98)
	at java.nio.channels.Channels.access$000(Channels.java:61)
	at java.nio.channels.Channels$1.write(Channels.java:174)
	at org.ice4j.socket.TCPOutputStream.write(TCPOutputStream.java:95)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:740)
	at org.ice4j.socket.MergingDatagramSocket$SocketContainer.send(MergingDatagramSocket.java:982)
	at org.ice4j.socket.MergingDatagramSocket$SocketContainer.access$100(MergingDatagramSocket.java:635)
	at org.ice4j.socket.MergingDatagramSocket.send(MergingDatagramSocket.java:198)
	at org.ice4j.socket.DelegatingDatagramSocket.send(DelegatingDatagramSocket.java:776)
	at org.jitsi.videobridge.transport.ice.IceTransport.send(IceTransport.kt:222)
	at org.jitsi.videobridge.Endpoint.doSendSrtp(Endpoint.java:470)
	at org.jitsi.nlj.util.PacketInfoQueue$sam$org_jitsi_utils_queue_PacketQueue_PacketHandler$0.handlePacket(PacketInfoQueue.kt)
	at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:575)
	at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:141)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
2020-05-20 00:57:28.180 WARNING: [67297] CountingErrorHandler.packetHandlingFailed#62: Failed to handle packet: 
java.lang.RuntimeException
	at org.jitsi.videobridge.transport.ice.IceTransport.send(IceTransport.kt:226)
	at org.jitsi.videobridge.Endpoint.doSendSrtp(Endpoint.java:470)
	at org.jitsi.nlj.util.PacketInfoQueue$sam$org_jitsi_utils_queue_PacketQueue_PacketHandler$0.handlePacket(PacketInfoQueue.kt)
	at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:575)
	at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:141)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
2020-05-20 00:57:28.180 SEVERE: [67281] [confId=b961fd04d8238883 epId=3b2f4121 local_ufrag=mcou1e8npam0m gid=ff37a0 stats_id=Brent-ju7 conf_name=514196c2-958d-3632-551f-d0ed818d870c] IceTransport.send#225: Error sending packet
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:267)
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:458)
	at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
	at java.nio.channels.Channels.writeFully(Channels.java:98)
	at java.nio.channels.Channels.access$000(Channels.java:61)
	at java.nio.channels.Channels$1.write(Channels.java:174)
	at org.ice4j.socket.TCPOutputStream.write(TCPOutputStream.java:95)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:740)
	at org.ice4j.socket.MergingDatagramSocket$SocketContainer.send(MergingDatagramSocket.java:982)
	at org.ice4j.socket.MergingDatagramSocket$SocketContainer.access$100(MergingDatagramSocket.java:635)
	at org.ice4j.socket.MergingDatagramSocket.send(MergingDatagramSocket.java:198)
	at org.ice4j.socket.DelegatingDatagramSocket.send(DelegatingDatagramSocket.java:776)
	at org.jitsi.videobridge.transport.ice.IceTransport.send(IceTransport.kt:222)
	at org.jitsi.videobridge.Endpoint.doSendSrtp(Endpoint.java:470)
	at org.jitsi.nlj.util.PacketInfoQueue$sam$org_jitsi_utils_queue_PacketQueue_PacketHandler$0.handlePacket(PacketInfoQueue.kt)
	at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:575)
	at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:141)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
2020-05-20 00:57:28.180 WARNING: [67281] CountingErrorHandler.packetHandlingFailed#62: Failed to handle packet: 
java.lang.RuntimeException
	at org.jitsi.videobridge.transport.ice.IceTransport.send(IceTransport.kt:226)
	at org.jitsi.videobridge.Endpoint.doSendSrtp(Endpoint.java:470)
	at org.jitsi.nlj.util.PacketInfoQueue$sam$org_jitsi_utils_queue_PacketQueue_PacketHandler$0.handlePacket(PacketInfoQueue.kt)
	at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:575)
	at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:141)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
2020-05-20 00:57:28.180 SEVERE: [67281] [confId=b961fd04d8238883 epId=3b2f4121 local_ufrag=mcou1e8npam0m gid=ff37a0 stats_id=Brent-ju7 conf_name=514196c2-958d-3632-551f-d0ed818d870c] IceTransport.send#225: Error sending packet
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:267)
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:458)
	at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
	at java.nio.channels.Channels.writeFully(Channels.java:98)
	at java.nio.channels.Channels.access$000(Channels.java:61)
	at java.nio.channels.Channels$1.write(Channels.java:174)
	at org.ice4j.socket.TCPOutputStream.write(TCPOutputStream.java:95)
	at org.ice4j.socket.DelegatingSocket.send(DelegatingSocket.java:740)
	at org.ice4j.socket.MergingDatagramSocket$SocketContainer.send(MergingDatagramSocket.java:982)
	at org.ice4j.socket.MergingDatagramSocket$SocketContainer.access$100(MergingDatagramSocket.java:635)
	at org.ice4j.socket.MergingDatagramSocket.send(MergingDatagramSocket.java:198)
	at org.ice4j.socket.DelegatingDatagramSocket.send(DelegatingDatagramSocket.java:776)
	at org.jitsi.videobridge.transport.ice.IceTransport.send(IceTransport.kt:222)
	at org.jitsi.videobridge.Endpoint.doSendSrtp(Endpoint.java:470)
	at org.jitsi.nlj.util.PacketInfoQueue$sam$org_jitsi_utils_queue_PacketQueue_PacketHandler$0.handlePacket(PacketInfoQueue.kt)
	at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:575)
	at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:141)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)

.... goes on until all users are moved to another bridge

Jicofo logs

Jicofo 2020-05-20 01:47:33.525 SEVERE: [12217] org.jitsi.jicofo.AbstractChannelAllocator.log() jvbbrewery@internal.auth.call.server.net/335da608-4cc7-4d57-81f4-6ff4761cc048 - failed to allocate channels, will consider the bridge faulty: Timed out waiting for a response.
org.jitsi.protocol.xmpp.colibri.exception.TimeoutException: Timed out waiting for a response.
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.maybeThrowOperationFailed(ColibriConferenceImpl.java:400)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.createColibriChannels(ColibriConferenceImpl.java:315)
	at org.jitsi.protocol.xmpp.colibri.ColibriConference.createColibriChannels(ColibriConference.java:115)
	at org.jitsi.jicofo.ParticipantChannelAllocator.doAllocateChannels(ParticipantChannelAllocator.java:146)
	at org.jitsi.jicofo.AbstractChannelAllocator.allocateChannels(AbstractChannelAllocator.java:262)
	at org.jitsi.jicofo.AbstractChannelAllocator.doRun(AbstractChannelAllocator.java:181)
	at org.jitsi.jicofo.AbstractChannelAllocator.run(AbstractChannelAllocator.java:149)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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)
Jicofo 2020-05-20 01:47:33.527 SEVERE: [12217] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() One of our bridges failed: jvbbrewery@internal.auth.call.server.net/335da608-4cc7-4d57-81f4-6ff4761cc048
Jicofo 2020-05-20 01:47:39.052 SEVERE: [12239] org.jitsi.impl.protocol.xmpp.OpSetSimpleCapsImpl.getFeatures().144 Failed to discover features for 514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/4219a7b1: XMPP error reply received from 514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/4219a7b1: XMPPError: item-not-found - cancel
Jicofo 2020-05-20 01:47:39.097 SEVERE: [44] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 0 (0),5,main] and message was: localChannelsInfo
java.lang.NullPointerException: localChannelsInfo
	at java.util.Objects.requireNonNull(Objects.java:228)
	at org.jitsi.xmpp.extensions.colibri.ColibriBuilder.addSourceInfo(ColibriBuilder.java:753)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.updateSourcesInfo(ColibriConferenceImpl.java:735)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.removeSources(JitsiMeetConferenceImpl.java:2003)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.onRemoveSource(JitsiMeetConferenceImpl.java:1776)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.processJingleIQ(AbstractOperationSetJingle.java:332)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.handleIQRequest(AbstractOperationSetJingle.java:77)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	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)
Jicofo 2020-05-20 01:47:39.145 SEVERE: [12490] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 1 (0),5,main] and message was: localChannelsInfo
java.lang.NullPointerException: localChannelsInfo
	at java.util.Objects.requireNonNull(Objects.java:228)
	at org.jitsi.xmpp.extensions.colibri.ColibriBuilder.addSourceInfo(ColibriBuilder.java:753)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.updateSourcesInfo(ColibriConferenceImpl.java:735)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.onAddSource(JitsiMeetConferenceImpl.java:1738)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.processJingleIQ(AbstractOperationSetJingle.java:328)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.handleIQRequest(AbstractOperationSetJingle.java:77)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	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)
Jicofo 2020-05-20 01:47:39.182 SEVERE: [12491] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 2 (0),5,main] and message was: localChannelsInfo
java.lang.NullPointerException: localChannelsInfo
	at java.util.Objects.requireNonNull(Objects.java:228)
	at org.jitsi.xmpp.extensions.colibri.ColibriBuilder.addSourceInfo(ColibriBuilder.java:753)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.updateSourcesInfo(ColibriConferenceImpl.java:735)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.removeSources(JitsiMeetConferenceImpl.java:2003)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.onRemoveSource(JitsiMeetConferenceImpl.java:1776)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.processJingleIQ(AbstractOperationSetJingle.java:332)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.handleIQRequest(AbstractOperationSetJingle.java:77)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	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)
Jicofo 2020-05-20 01:47:39.346 SEVERE: [12492] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 3 (0),5,main] and message was: localChannelsInfo
java.lang.NullPointerException: localChannelsInfo
	at java.util.Objects.requireNonNull(Objects.java:228)
	at org.jitsi.xmpp.extensions.colibri.ColibriBuilder.addSourceInfo(ColibriBuilder.java:753)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.updateSourcesInfo(ColibriConferenceImpl.java:735)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.onAddSource(JitsiMeetConferenceImpl.java:1738)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.processJingleIQ(AbstractOperationSetJingle.java:328)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.handleIQRequest(AbstractOperationSetJingle.java:77)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	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)
Jicofo 2020-05-20 01:47:39.434 SEVERE: [12493] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 4 (0),5,main] and message was: localChannelsInfo
java.lang.NullPointerException: localChannelsInfo
	at java.util.Objects.requireNonNull(Objects.java:228)
	at org.jitsi.xmpp.extensions.colibri.ColibriBuilder.addSourceInfo(ColibriBuilder.java:753)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.updateSourcesInfo(ColibriConferenceImpl.java:735)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.removeSources(JitsiMeetConferenceImpl.java:2003)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.onRemoveSource(JitsiMeetConferenceImpl.java:1776)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.processJingleIQ(AbstractOperationSetJingle.java:332)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.handleIQRequest(AbstractOperationSetJingle.java:77)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	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)
Jicofo 2020-05-20 01:47:39.490 SEVERE: [12494] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 5 (0),5,main] and message was: localChannelsInfo
java.lang.NullPointerException: localChannelsInfo
	at java.util.Objects.requireNonNull(Objects.java:228)
	at org.jitsi.xmpp.extensions.colibri.ColibriBuilder.addSourceInfo(ColibriBuilder.java:753)
	at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.updateSourcesInfo(ColibriConferenceImpl.java:735)
	at org.jitsi.jicofo.JitsiMeetConferenceImpl.onAddSource(JitsiMeetConferenceImpl.java:1738)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.processJingleIQ(AbstractOperationSetJingle.java:328)
	at org.jitsi.protocol.xmpp.AbstractOperationSetJingle.handleIQRequest(AbstractOperationSetJingle.java:77)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	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)
Jicofo 2020-05-20 01:47:42.482 SEVERE: [12405] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.replaceTransport().273 Unexpected response to 'transport-replace' from 514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/a6a57f26: <iq to='focus@auth.call.server.net/focus592494845407566' from='514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/a6a57f26' id='mXQSX-1174517' type='error'><error type='cancel'><item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Recipient not in room</text></error></iq>
Jicofo 2020-05-20 01:47:45.297 SEVERE: [12333] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.replaceTransport().273 Unexpected response to 'transport-replace' from 514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/07f05666: <iq to='focus@auth.call.server.net/focus592494845407566' from='514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/07f05666' id='mXQSX-1175268' type='error'><error type='cancel'><item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Recipient not in room</text></error></iq>
Jicofo 2020-05-20 01:47:47.018 SEVERE: [12257] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.replaceTransport().273 Unexpected response to 'transport-replace' from 514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/6068f34a: <iq to='focus@auth.call.server.net/focus592494845407566' from='514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/6068f34a' id='mXQSX-1175554' type='error'><error type='cancel'><item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Recipient not in room</text></error></iq>
Jicofo 2020-05-20 01:47:47.321 SEVERE: [12298] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.replaceTransport().273 Unexpected response to 'transport-replace' from 514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/77c2288b: <iq to='focus@auth.call.server.net/focus592494845407566' from='514196c2-958d-3632-551f-d0ed818d870c@conference.call.server.net/77c2288b' id='mXQSX-1175587' type='error'><error type='cancel'><item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Recipient not in room</text></error></iq>

Were not sure how to handle this and if it is caused by the stun service. Any help would be greatly appreciated. Thank you.

Best regards.
Anthony

Bump on this thread. Any updates @Anthony_Garcia. Thanks

any update, I also got same type of error on heavy load in jvb…

Are you seeing this with the latest versions from unstable?

Thanx a lot for the reply @damencho
no we are aline with jitsi-meet_5142 and yesterday we had a conference around upto 150-160 people in same room. but most of them were video/audio muted only around 5-6 were with audio video. many couldn’t join and got reconnecting in every 2-5 minutes, the main speaker’s video resolution weren’t near what we set and it was worse and struggling to render with frame drops (my pc is core i7 7th gen with 16GB ram, the audio was quite good though for most of the part). Though the meeting was going on, suddenly (after15-20 minutes) the meeting dropped with so many users with only few left. Then we looked at the jvb logs and it looks like the main post.

what is the problem you think? is it because we don’t have pagination and most client pc was struggling to render the ui? but then it crashed from server side (anything to do with the version?). I will look more into the logs today. later we shifted our meeting to zoom and it was fine with no major issues.

Thanx in advance for any help…! :heartbeat:

If you’re using 5142, 150-160 in one room is too much load. The latest unstable has many improvements over 5142 and can handle that kind of load.

Yeah, I see this is a pretty old version … I will ask tomorrow but it also seems to me you are also using jvb TCP connection which by default is disabled (jitsi-videobridge/reference.conf at c6da57bdb2623e3112f8de0cb5a337fe207809ec · jitsi/jitsi-videobridge · GitHub).
For those it is recommended to have a turnserver that handles the TCP connections and leave jvb to be udp only.

What should I do or what do you recommend? shifting to latest version and this problem will be solved?
I have not a great idea about jvb tcp but I checked that my webrtcIceTcp and webrtcIceUdp is both enabled in config. actually what caused the crash? I am little confused about the log.
we had 2 jvb running and the load were in both of them.
here is the samples of my logs in txt file as the main txt is so big. The conference crashed around
01:10

sample_jvb_logs.txt (309.6 KB)

And I have sent you the jicofo log personally (emailed)… conference crashed around 01:05 (11th april).

Can you share your jvb config. There is no point of looking at jcofo logs, you saw timeouting jvb in jicofo logs…so it seems its jvb. Jicofo code has changed so much lately.
I’m not sure is the tcp the problem, with it we have seen jvb to perform poorly. What we have seen though is jvb crashing due to sctp, which you are using so it maybe and that. Sctp was the reason we introduced the websocket connection to the bridge.
And yes updating everything will help a lot… We are expecting new stable release this week (one of the unstable versions from today most probably).

1 Like

I have sent you the jvb files via personal message :heartbeat:

Yeah you have enabled the TCP harvester:

org.jitsi.videobridge.TCP_HARVESTER_PORT=4441
org.jitsi.videobridge.DISABLE_TCP_HARVESTER=false

You better disable that, and do not use it. And you will stop seeing the exception above.
Then the other question that will remain is whether that was the problem you saw or sctp crashing … when we were seeing sctp crashing the jvb process segfaults … but I guess you will see that somewhere in the logs. It it was the sctp indeed switching to websockets for the direct data connection to the bridge is the way to go.

So you need to disable the TCP in the bridge and look forward to update to the latest from stable, later this week when we push the new versions.

1 Like

Thanx a lot. We had a issue so we had to enable it but it is solved now. So disabling it will slve most of the problems that was the reason of crash? and why is that?
yeah we will definitely move to new stable.

Not sure this was the main reason, TCP is not well handled in jvb, that’s the reason we deprecated it and disabled it by default more than an year ago when we introduced the turnserver with the default installations and left coturn to handle the TCP and the bridge to handle the udp traffic only.

Thanks a lot for the help…! so I should install turnserver with jitsi? otherwise I can install it separately and is it necessary?

If you want to have a fallback to tcp, yes. And yes you can install it separately. The easiest is to have it on a separate machine(than nginx) and running on port 443 so it will cover and restricted corporate nats, you need a second dns for that with a valid certificate.

ok thanx a lot :heartbeat: