JVB Error: Overwriting a previous data channel!

Hi @damencho @bbaldino,
Yesterday we had a few simultaneous meetings held on our server and we encountered some errors in our jvb1 which caused all ~14 participants of the only meeting on this faulty jvb kicked away and hence jicofo switched the meeting to another jvb named jvb6.

JVB log:

INFO: Expired.
Sep 14, 2020 6:13:43 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Failed to receive: java.net.SocketException: Socket closed
Sep 14, 2020 6:13:43 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: timeout for pair: 79.175.132.85:9876/udp/srflx -> 188.210.187.30:33113/udp/prflx (stream-2d8acc0a.RTP), failing.
Sep 14, 2020 6:13:43 PM org.jitsi.utils.logging2.LoggerImpl log
WARNING: Unable to find endpoint 91f4fc18 to send EndpointMessage
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Received data channel open message
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Remote side opened a data channel.
Exception in thread “Global IO pool-5644” java.lang.Error: Overwriting a previous data channel!
at org.jitsi.videobridge.EndpointMessageTransport.setDataChannel(EndpointMessageTransport.java:415)
at org.jitsi.videobridge.Endpoint$7.lambda$onReady$1(Endpoint.java:891)
at org.jitsi.videobridge.datachannel.DataChannelStack.onIncomingDataChannelPacket(DataChannelStack.java:74)
at org.jitsi.videobridge.Endpoint$DataChannelHandler.consume(Endpoint.java:1225)
at org.jitsi.videobridge.Endpoint.lambda$null$4(Endpoint.java:928)
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)
Exception in thread “Global IO pool-5552” java.lang.NullPointerException
Exception in thread “Global IO pool-5642” java.lang.NullPointerException
Exception in thread “Global IO pool-5648” java.lang.NullPointerException
Exception in thread “Global IO pool-5649” java.lang.NullPointerException
Exception in thread “Global IO pool-5650” java.lang.NullPointerException
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing
Exception in thread “Global IO pool-5651” java.lang.NullPointerException
Exception in thread “Global IO pool-5652” java.lang.NullPointerException
Exception in thread “Global IO pool-5625” java.lang.NullPointerException
Exception in thread “Global IO pool-5654” java.lang.NullPointerException
Exception in thread “Global IO pool-5655” java.lang.NullPointerException
Exception in thread “Global IO pool-5656” java.lang.NullPointerException
Exception in thread “Global IO pool-5657” java.lang.NullPointerException
Exception in thread “Global IO pool-5640” java.lang.NullPointerException
Exception in thread “Global IO pool-5659” java.lang.NullPointerException
Exception in thread “Global IO pool-5660” java.lang.NullPointerException
Exception in thread “Global IO pool-5661” java.lang.NullPointerException
Exception in thread “Global IO pool-5662” java.lang.NullPointerException
Exception in thread “Global IO pool-5663” java.lang.NullPointerException
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing
Sep 14, 2020 6:13:44 PM org.jitsi.utils.logging1.LoggerImpl log
WARNING: RTT suspiciously high (1041ms), capping to 1000ms.
Sep 14, 2020 6:13:45 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing
Sep 14, 2020 6:13:45 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: close_notify received, connection closing

and jicofo log:

Jicofo 2020-09-14 18:13:43.047 SEVERE: [6726] org.jitsi.jicofo.AbstractChannelAllocator.log() jvbbrewery@internal.auth.room.myserver.ir/jvb1 - failed to allocate channels, will consider the bridge faulty: XMPP error:
org.jitsi.protocol.xmpp.colibri.exception.ColibriException: XMPP error:
at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.maybeThrowOperationFailed(ColibriConferenceImpl.java:378)
at org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl.createColibriChannels(ColibriConferenceImpl.java:282)
at org.jitsi.protocol.xmpp.colibri.ColibriConference.createColibriChannels(ColibriConference.java:112)
at org.jitsi.jicofo.ParticipantChannelAllocator.doAllocateChannels(ParticipantChannelAllocator.java:111)
at org.jitsi.jicofo.AbstractChannelAllocator.allocateChannels(AbstractChannelAllocator.java:271)
at org.jitsi.jicofo.AbstractChannelAllocator.doRun(AbstractChannelAllocator.java:190)
at org.jitsi.jicofo.AbstractChannelAllocator.run(AbstractChannelAllocator.java:150)
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-09-14 18:13:43.048 SEVERE: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() One of our bridges failed: jvbbrewery@internal.auth.room.myserver.ir/jvb1
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null, null]]
Jicofo 2020-09-14 18:13:43.048 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null, null]]
Jicofo 2020-09-14 18:13:43.049 WARNING: [6726] org.jitsi.jicofo.AbstractParticipant.log() Canceling ParticipantChannelAllocator[BridgeSession[id=11190_742b1f, bridge=Bridge[jid=jvbbrewery@internal.auth.room.myserver.ir/jvb1, relayId=null, region=null, stress=0.08]]@639698603, Participant[540ec509-f7e7-4ad1-85f3-b9ae0c381767@conference.room.myserver.ir/91f4fc18]@199901272]@1871922637
Jicofo 2020-09-14 18:13:43.049 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=11190 octo_enabled= false: [[null]]
Jicofo 2020-09-14 18:13:43.049 INFO: [6726] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Selected initial bridge Bridge[jid=jvbbrewery@internal.auth.room.myserver.ir/jvb6, relayId=null, region=null, stress=0.00] with packetRate=0 for participantRegion=null
Jicofo 2020-09-14 18:13:43.049 INFO: [6726] org.jitsi.impl.protocol.xmpp.colibri.OperationSetColibriConferenceImpl.log() Conference created: org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl@6baccce7
Jicofo 2020-09-14 18:13:43.049 INFO: [6726] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= 540ec509-f7e7-4ad1-85f3-b9ae0c381767@conference.room.myserver.ir/f98f1335, bridge=jvbbrewery@internal.auth.room.myserver.ir/jvb6

Can you please help me what causes this strange java Error? I searched in the community but could not find any related topic or message.

Related jitsi-videobridge source codes:

any help would be much appreciated.

@bbaldino @damencho
Can you please help me with this problem?

I have never seen this occur before, but I would highly recommend looking into setting up websockets in your deployment and disabling SCTP/datachannels. We don’t use datachannels anymore in our environments.

1 Like

Thank you @bbaldino for your help.
We also receive this warning when our dockerized jvb starts:

WARNING: Running with open files limit 1048576 (hard 1048576), thread limit null (hard null). These values are too low and they will limit the number of participants that the bridge can serve simultaneously.

Thread limit is null, can this cause further problem?
Why executing ulimit -u command returns null? Is it normal? Should we take any action?

Thanks

@bbladino
Have you any idea about this strange thread limit value?

Finally found out that running the command “ulimit -u” in jvb docker container returns unlimited which is not an integer so the jvb code prints it as null.

1 Like