Jitsi-meet: Can not invite participant -- no bridge available.

[ghost]

Hi!

This is a long running jitsi installation (0.5 year) that after some time started failing.

After some time jitsi-meet is running, when someone tries to do a conference both browser clients crash.

jvb.log says:

JVB 2017-11-14 10:10:09.829 FINE: [501] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 83a76-51612): <iq id="83a76-51612" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:09.829 FINE: [501] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV: <iq id="83a76-51612" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:11.138 FINE: [503] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId AkQL6-236189): <iq type="get" to="jitsi-videobridge.meet.guifi.net" from="[email protected]/focus1071006487923453" id="AkQL6-236189"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>
JVB 2017-11-14 10:10:11.138 FINE: [503] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId AkQL6-236189).
JVB 2017-11-14 10:10:11.138 FINE: [503] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId AkQL6-236189) with: <iq type="result" id="AkQL6-236189" from="jitsi-videobridge.meet.guifi.net" to="[email protected]/focus1071006487923453"><query 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 2017-11-14 10:10:19.830 FINE: [36] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 83a76-51613): <iq id="83a76-51613" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:19.830 FINE: [36] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV: <iq id="83a76-51613" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:29.830 FINE: [26] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 83a76-51614): <iq id="83a76-51614" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:29.830 FINE: [26] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV: <iq id="83a76-51614" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:39.830 FINE: [613] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId 83a76-51615): <iq id="83a76-51615" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:39.830 FINE: [613] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV: <iq id="83a76-51615" type="result" to="jitsi-videobridge.meet.guifi.net" from="meet.guifi.net"/>
JVB 2017-11-14 10:10:41.138 FINE: [30] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId AkQL6-236201): <iq type="get" to="jitsi-videobridge.meet.guifi.net" from="[email protected]/focus1071006487923453" id="AkQL6-236201"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>
JVB 2017-11-14 10:10:41.138 FINE: [30] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId AkQL6-236201).

meanwhile jvb.log is FINE:

Jicofo 2017-11-14 09:56:40.598 INFO: [86] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Lip-sync enabled in [email protected]
Jicofo 2017-11-14 09:56:40.598 INFO: [86] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Joining the room: [email protected]
Jicofo 2017-11-14 09:56:40.599 INFO: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@1fced781 member=ChatMember[[email protected]/focus, jid: null]@283587152]
Jicofo 2017-11-14 09:56:40.599 WARNING: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Focus role unknown
Jicofo 2017-11-14 09:56:40.599 INFO: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Obtained focus role: OWNER
Jicofo 2017-11-14 09:56:40.599 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member [email protected]/focus joined.
Jicofo 2017-11-14 09:56:40.600 INFO: [86] org.jitsi.jicofo.JitsiMeetRecording.log() No recorder service discovered.
Jicofo 2017-11-14 09:56:40.719 INFO: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@1fced781 member=ChatMember[[email protected]/8b338772, jid: null]@1031193953]
Jicofo 2017-11-14 09:56:40.720 INFO: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Granted owner to [email protected]/8b338772
Jicofo 2017-11-14 09:56:40.720 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member [email protected]/8b338772 joined.
Jicofo 2017-11-14 10:10:36.131 INFO: [63] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().396 Focus request for room: [email protected]
Jicofo 2017-11-14 10:10:36.172 INFO: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@1fced781 member=ChatMember[[email protected]/781016a4, jid: null]@1264931942]
Jicofo 2017-11-14 10:10:36.172 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member [email protected]/781016a4 joined.
Jicofo 2017-11-14 10:10:36.173 SEVERE: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available.
Jicofo 2017-11-14 10:10:36.173 SEVERE: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available.
Jicofo 2017-11-14 10:10:36.460 INFO: [55] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@1fced781 member=ChatMember[[email protected]/781016a4, jid: null]@1264931942]
Jicofo 2017-11-14 10:10:36.460 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member [email protected]/781016a4 is leaving
Jicofo 2017-11-14 10:10:36.460 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, [email protected]/781016a4

You can try yourself at: meet.guifi.net

Its nearly vanilla configuration (unchecked third party software like random gravatars). But inside this machine, there is a matrix.org and rocketchat (docker). Perhaps all these applications are fighting with the ports?

This is a stable jitsi installation:

# apt-cache show jitsi
Package: jitsi
Architecture: amd64
Version: 2.10.5550-1

Thanks!
Pedro

[damencho]

For some reason jicofo thinks there is no jvb instance. It is stopped or something went wrong. Uploading the whole log files may reveal more.
Restarting jvb will fix it in short term.
The version you had pointed is the jitsi-desktop client and has nothing to do with jitsi-meet.

[ghost]

For some reason jicofo thinks there is no jvb instance. It is stopped or something went wrong.

# service jitsi-videobridge status
● jitsi-videobridge.service - LSB: Jitsi Videobridge
   Loaded: loaded (/etc/init.d/jitsi-videobridge; generated; vendor preset: enabled)
   Active: active (running) since Wed 2017-11-08 10:47:48 CET; 6 days ago
     Docs: man:systemd-sysv-generator(8)
    Tasks: 86 (limit: 4915)
   Memory: 243.9M
      CPU: 43min 48.395s
   CGroup: /system.slice/jitsi-videobridge.service
           └─8372 java -Xmx3072m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp -Djava.library.path=/usr/share/jitsi-videobridge/lib/native/linux-64 -Dnet.java.s

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.

Uploading the whole log files may reveal more.

Should we proceed this way? -> https://github.com/jitsi/jitsi-meet/issues/1390#issuecomment-290500479

Restarting jvb will fix it in short term.

Exactly... but it fails after some time running

The version you had pointed is the jitsi-desktop client and has nothing to do with jitsi-meet.

Ouch!

# dpkg -l | grep jitsi
ii  jitsi-meet                      1.0.2467-1                     all          WebRTC JavaScript video conferences
ii  jitsi-meet-prosody              1.0.2301-1                     all          Prosody configuration for Jitsi Meet
ii  jitsi-meet-web                  1.0.2301-1                     all          WebRTC JavaScript video conferences
ii  jitsi-meet-web-config           1.0.2301-1                     all          Configuration for web serving of Jitsi Meet
ii  jitsi-videobridge               995-1                          amd64        WebRTC compatible Selective Forwarding Unit (SFU)
# dpkg -l | grep jicofo
ii  jicofo                          1.0-371-1                      amd64        JItsi Meet COnference FOcus

[damencho]

As a start, just upload all jvb and jicofo logs from /var/log/jitsi

[damencho]

I see this in the logs.
Jicofo 2017-11-13 20:20:47.580 WARNING: [38] org.jitsi.jicofo.JvbDoctor.log() Health check failed on: jitsi-videobridge.meet.guifi.net error: java.net.SocketException: Too many open files (Error creating socket)

We haven't seen this for months now, that is strange. So my proposal is to restart jvb and jicofo and when you see the problem can you collect the logs as described in the #1390 (comment) and send it to me so I can take a look.

Thanks for the report and the cooperation.

[ghost]

Hi again,

right now I had to resize the virtual disk for this virtual machine (after some little security upgrades): no space left said (~40 MB left). Is this error an early alert that jitsi-meet is not having enough space to continue working?

It had 4 GB (yes, I know is very tiny), now it has 8 GB. We will see

[damencho]

No this is not free disk space. There is a limitation of the number of open file handles by a user/process that can be used. And it seems it reaches this limit. There is a ulimit command to make it higher.
But also reaching that it means there can be a bug, at least the previous time we found one and fixed it and we haven't seen reports for that recently, till now.

[olivierb2]

+1

[damencho]

@olivierb2 Can you give more details, are you seeing the same error in jicofo logs:
Health check failed on: jitsi-videobridge.meet.guifi.net error: java.net.SocketException: Too many open files (Error creating socket)
If you experience that can you try doing the heap dump as explained

[olivierb2]

Hi @damencho
Apologies for the +1, I just realize later that I was using the unstable build, I redone the installation from the stable, and yet it seems much more better. I come back to you if I discover any issue.

[paulvt]

I have encountered the problem too. The logs (both jicofo and jvb) report nothing out of the ordinary, i.e. not on the INFO/FINE log level, except for:

org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available

I can see that both jicofo and jvb are running.

I had to reboot the machine (it's a production instance) and that solved the issue for now. I will report back if I find out more.

[saghul]

OK, I'm going to close this then. Please let us know if you still face issues.

[TheReal1604]

@saghul @damencho i am facing the exactly same error as @paulvt on a very rare used instance. Usually we use this instance all 2-3~ Weeks for one meeting. Everytime I start an meeting after this spare time the exact same message is logged:

org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available

This can only be resolved if I restart jicofo. After that it seems to be okay.

[damencho]

@TheReal1604 it will be helpful when that happens, to check all the logs or send it to me privately if you want and let me check it. All files in /var/log/jitsi.
In the jicofo log there should be a failed healthcheck against jvb and it should have some message about why that failed. And also at the same time what were the logs in jvb.

[TheReal1604]

@damencho send you an email with a link to my logs. We will report here soon.. :-)

[ZsZs73]

Hi,
Apparently I have the same problem or very similar.
My jvb log also reports "Too many open files".
Below there are two health checks. The first one without error and the second one with error.
```JVB 2018-04-26 01:24:56.126 FINE: [24] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId Sln4t-92193):
JVB 2018-04-26 01:24:56.126 FINE: [24] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId Sln4t-92193).
JVB 2018-04-26 01:24:56.126 FINE: [24] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV:
JVB 2018-04-26 01:24:56.126 INFO: [24] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=9ecc0c877669b296 conf_name=null,logging=false,conf_count=1,ch_count=0,v_streams=0
JVB 2018-04-26 01:24:56.130 INFO: [24] org.jitsi.impl.neomedia.VideoMediaStreamImpl.log() Creating a BandwidthEstimator for stream org.jitsi.impl.neomedia.VideoMediaStreamImpl@55bacc0a
JVB 2018-04-26 01:24:56.134 INFO: [24] org.jitsi.impl.neomedia.VideoMediaStreamImpl.log() Creating a BandwidthEstimator for stream org.jitsi.impl.neomedia.VideoMediaStreamImpl@51401e8b
JVB 2018-04-26 01:24:56.145 FINE: [24] org.jitsi.videobridge.xmpp.ComponentImpl.log() SENT:
JVB 2018-04-26 01:24:56.145 FINE: [24] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId Sln4t-92193) with:

JVB 2018-04-26 01:24:58.281 FINE: [34] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId puSV8-181423):
JVB 2018-04-26 01:24:58.281 FINE: [34] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV:

JVB 2018-04-26 01:25:06.126 FINE: [184] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Processing IQ (packetId Sln4t-92197):
JVB 2018-04-26 01:25:06.126 FINE: [184] org.jitsi.videobridge.xmpp.ComponentImpl.processIQRequest() (serving component 'JitsiVideobridge') Processing IQ request (packetId Sln4t-92197).
JVB 2018-04-26 01:25:06.131 FINE: [184] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV:
JVB 2018-04-26 01:25:06.132 INFO: [184] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=55a3018dcfc90a68 conf_name=null,logging=false,conf_count=1,ch_count=0,v_streams=0
JVB 2018-04-26 01:25:06.135 INFO: [184] org.jitsi.impl.neomedia.VideoMediaStreamImpl.log() Creating a BandwidthEstimator for stream org.jitsi.impl.neomedia.VideoMediaStreamImpl@3c9f1f0f
JVB 2018-04-26 01:25:06.141 INFO: [184] org.jitsi.impl.neomedia.VideoMediaStreamImpl.log() Creating a BandwidthEstimator for stream org.jitsi.impl.neomedia.VideoMediaStreamImpl@f4ddaa2
JVB 2018-04-26 01:25:06.150 FINE: [184] org.jitsi.videobridge.xmpp.ComponentImpl.log() SENT: java.net.SocketException: Too many open files (Error creating socket)
JVB 2018-04-26 01:25:06.150 FINE: [184] org.jitsi.videobridge.xmpp.ComponentImpl.processIQ() (serving component 'JitsiVideobridge') Responding to IQ (packetId Sln4t-92197) with: java.net.SocketException: Too many open files (Error creating socket)

There are tons of open UDP sockets:

lsof|grep jvb| grep "protocol: UDP" |wc -l
317305

After restarting `jitsi-videobridge` service everything is back to normal.

edit:
Ooops, forgot to mention that it is the latest available version of jitsi on Debian 9:

dpkg -l|grep jitsi
ii jitsi-meet 1.0.2794-1
ii jitsi-meet-prosody 1.0.2579-1
ii jitsi-meet-web 1.0.2579-1
ii jitsi-meet-web-config 1.0.2579-1
ii jitsi-videobridge 1030-1
```

[damencho]

@ZsZs73

After restarting jvb did the UDP sockets were cleared?

To be able to debug the problem it will be very useful to get a heapdump of jvb. So when you see the problem can you execute as root:
cd /tmp (it should be a folder where user jvb can write)
/usr/share/jitsi-videobridge/collect-dump-logs.sh
Then you can upload it somewhere and send me the link privately damencho AT jitsi.org. And if you can also send me there the output of ifconfig.
Thanks.

[ZsZs73]

@damencho
Yes, the number of open UDP sockets went back to 0 after restarting jvb, but 5.5 hours later it is already:

lsof|grep jvb| grep "protocol: UDP" |wc -l
48108

This is just a test system, so there might be just a few VCs since jvb restart.
I'll collect the dump/logs once it failing again.

update: ipv6 is disabled

[damencho]

Well, if you see so much for 5 hours, you can collect the logs now and send it to me so I can take a look and will let you know do I need anything more. Thanks!

[damencho]

A quick solution to your problem will be to disable health checking from jicofo.
Add org.jitsi.jicofo.HEALTH_CHECK_INTERVAL=-1 to /etc/jitsi/jicofo/sip-communicator.properties and restart jicofo.

[ghost]

Wow @ZsZs73 ! Great contribution detecting this bug

In my server in some seconds we can see crazy UDP usage (theoretically now the server is not being used). I'm going to send you now the report privately @damencho

[10:13:43] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
66649
[10:13:46] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
49129
[10:14:09] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
50297
[10:14:15] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
50297
[10:14:19] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
50297
[10:14:23] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
51465
[10:14:27] root@host:~# lsof|grep jvb| grep "protocol: UDP" |wc -l
51465

[damencho]

I will check you dumb, but the immediate solution is disabling the health checks from jicofo.
I spent yesterday looking at this, and I was able to reproduce it. There is no memory leak or any problem in the code. All the objects are unreachable in the memory it is that it takes time for GC to collect them and so clean the file descriptors used. But why it takes so much time for the garbage collector to collect them, I have no idea. If you try and force GC with a command # sudo -u jvb jcmd GC.run you will see that that number becomes almost 0.

[ZsZs73]

Hi @damencho amencho,
The forced garbage collector run takes less than a second and I conform that it clears the UDP connections, but it is not enough to make jicofo happy.
It continues to complain about org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available.
Only restarting jicofo made it operational again.
The proposed workaround (disabling health check) seems to work, at least the number of UDP connections do not increase quickly.

[damencho]

You can disable those health checks: org.jitsi.jicofo.HEALTH_CHECK_INTERVAL=-1 adding it to jicofo config and you will not have that problem.

[ZsZs73]

I am trying an another approach right now.
I've just created following cron job:

cat >/etc/cron.d/jvbGC <<'EOF'
# Force runing Garbage Collector
# See https://github.com/jitsi/jitsi-meet/issues/2172
7 * * * * jvb /usr/bin/jcmd $(ps auxw|grep org.jitsi.videobridge.Main|grep -v grep| awk '{print $2}') GC.run
EOF

This runs the garbage collector hourly and keeps the open UDP connections low so far.
I've re-enabled the health check in jicofo config.
Let's see how it works.

[ZsZs73]

@damencho, @pedro-nonfree
The workaround described above works since more than a week.
It is not going to heal the jvb if jicofo is already complaining.
It should be applied together with restart of jvb and jicofo.

[ghost]

@damencho what are the (potential) consequences of holding healthcheck disabled?

[damencho]

Well, health checks are mostly for an environment with multiple jvb instances. When one fails we remove it from the pool of available jvb's and the infrastructure will take care to delete/restart or whatever to try bringing it up again, and in the meanwhile, no conferences will be sent to that jvb till it got healthy again. With one jvb there is no difference whether it is there and it is not working, or it is not there and not working :)

[ZsZs73]

@damencho
That is true, but apparently the scheduled/forced GC keeps jvb working with health check enabled at jicofo.
I am far not familiar with the JVM structure. Is there a built-in GC running by default in the JVM? Does GC produce any logs?

[damencho]

Yep there is GC, but I have no idea why forcing helps, but regular not.

[ZsZs73]

According to this: https://stackoverflow.com/questions/37576330/when-sockets-are-dereferenced-are-they-garbage-collected GC runs only if the available memory/resources are low.
The link seems to contain valuable input about connection handling for those who speak Java.
I am going to enable GC logging hoping that it will shed some light.

[ZsZs73]

Just for the records: How to enable GC logging for jvb
Add following line in /etc/jitsi/videobridge/config right after JVB_OPTS=""

JVB_EXTRA_JVM_PARAMS="-Xloggc:/var/log/jitsi/jvb-gc.log -XX:+PrintGCDetails \
-XX:+PrintGCDateStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation \
-XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=5M"

then restart jvb

[damencho]

You can try decreasing the memory used by jvb. I think it is 3gb by default. Maybe reducing it to 1 or 2 will help.

[twoprops]

I'm having a very similar problem. As soon as a second user attempts to connect, I get the "unfortunately, something went wrong" error message. There's nothing above the "FINE" level in jvb.log and the only errors in jicofo.log are a pair of "SEVERE: [37] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available."

I have health checks disabled and, unlike this users above, this error will occur upon a connection attempt even immediately after restarting jvb and jicofo and, in fact, even immediately after a system reboot.

Is there any other place I might look to get any more information?

Thanks.

[damencho]

Check jvb logs after you restart it.

[twoprops]

There are many, many INFO and FINE messages. The only section that vaguely looks like an error or warning is

JVB 2018-08-12 21:59:23.427 INFO: [1] util.NetworkUtils.<clinit>().118 java.net.preferIPv4Stack=null SLF4J: Class path contains multiple SLF4J bindings. SLF4J: Found binding in [jar:file:/usr/share/jitsi-videobridge/lib/slf4j-jdk14-1.7.7.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: Found binding in [jar:file:/usr/share/jitsi-videobridge/lib/slf4j-simple-1.6.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. SLF4J: Actual binding is of type [org.slf4j.impl.JDK14LoggerFactory] JVB 2018-08-12 21:59:23.666 INFO: [11] org.jitsi.service.libjitsi.LibJitsi.log() Successfully started LibJitsi using as implemen tation: org.jitsi.impl.libjitsi.LibJitsiOSGiImpl
Everything else looks like just reporting on options being set and connections being made (bearing in mind that I have a tremendous level of ignorance of the internals of jitsi). The "multiple_bindings" explanation doesn't make sense to me owing to my lack of context.

--Ron

[twoprops]

Upon attempting a connection, I also captured these jvb log items that I'd missed before:

JVB 2018-08-12 22:31:53.109 SEVERE: [121] org.jitsi.sctp4j.Sctp.log() Init'ing brian's patched usrsctp =====>: org_jitsi_sctp4j_Sctp.c calling init =====>: org_jitsi_sctp4j_Sctp.c about to set SCTP_DEBUG_ALL =====>: org_jitsi_sctp4j_Sctp.c setting SCTP_DEBUG_ALL JVB 2018-08-12 22:31:53.258 WARNING: [100] org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.log() Unknown DTLS handshake message type: -101 JVB 2018-08-12 22:31:53.260 WARNING: [100] org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.log() Unknown DTLS handshake message type: 86 JVB 2018-08-12 22:31:53.289 INFO: [100] org.jitsi.impl.neomedia.transform.srtp.OpenSSLWrapperLoader.log() jnopenssl successfully loaded JVB 2018-08-12 22:31:53.313 INFO: [76] org.jitsi.videobridge.Conference.log() CAT=stat ds_change,conf_id=a5c963dab54459cb ds_id=57f7ea89 JVB 2018-08-12 22:31:53.313 WARNING: [76] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57f7ea89 not ready yet. JVB 2018-08-12 22:31:53.313 WARNING: [76] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message JVB 2018-08-12 22:31:53.313 WARNING: [76] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with ddf879ff not ready yet. JVB 2018-08-12 22:31:53.313 WARNING: [76] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message
There were then several other places where the "WARNING...Unknown DTLS handshake message ... No available transport" messages repeat.

Sorry that I didn't see those before.

--r

[damencho]

@twoprops I don't understand. You say you see this in jicofo logs "Can not invite participant -- no bridge available", this means that no jvb is available if this is the case no conference will use jvb so logs as the one from the above should no appear.
Do you no longer see that log in jicofo "no bridge available"?

[twoprops]

You are correct; there were no "can not invite" errors in the jicofo logs this time (nor had I missed the JVB errors before; they were not there). To make matters even more confusing, it actually connected once (audio only, no video and video could not be turned on), then after a bit went back to the previous "something has gone wrong..." behavior.

I think before I waste any more of your time, I'll just nuke the entire server and re-install from scratch. Since this instance ran for many months without a problem, I suspect some deep system corruption.

Thanks for your attention and the work you have done on this. I will let you know if I continue to experience problems with a new install.

--r

[adicatur]

Hi @damencho @ZsZs73

Thanks for this discussion, I have a question, what's your suggestion if we want to have multiple JVB, besides we need to enable the health-check?
Is it only reduce the JVB memory or and using cron to remove the UDP works so far, or do you have additional information?

Thanks