Jibri Removed from JibriBrewery after 2+ hrs of standby

Hi, all - wondering if anyone else has encountered this issue before?

I setup a Jibri instance which is able to connect, authenticate, record and stream without issue. However, after 1-2hrs of standby, the Jibri will just get kicked out of the JibriBrewery as if it was disconnected, but the Jibri is still running fine.

In jicofo logs, we can see when the Jibri joins and then an ~1.5hrs later, is removed:

Jicofo 2022-01-26 01:58:10.864 INFO: [6192] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#341: Added brewery instance: jibribrewery@internal.auth.jitsi-meet.mydomain.com/689b57ba-7e4b-11ec-8f40-001dd84034f1
Jicofo 2022-01-26 01:58:10.864 INFO: [6192] JibriDetector.onInstanceStatusChanged#95: Creating a new instance for jibribrewery@internal.auth.jitsi-meet.mydomain.com/689b57ba-7e4b-11ec-8f40-001dd84034f1, available = true
Jicofo 2022-01-26 03:29:31.011 INFO: [6218] [type=jibri brewery=jibribrewery] BaseBrewery.removeInstance#353: Removed brewery instance: jibribrewery@internal.auth.jitsi-meet.mydomain.com/689b57ba-7e4b-11ec-8f40-001dd84034f1
Jicofo 2022-01-26 03:29:31.012 INFO: [6218] JibriDetector.notifyInstanceOffline#118: Removing instance jibribrewery@internal.auth.jitsi-meet.mydomain.com/689b57ba-7e4b-11ec-8f40-001dd84034f1

I am not sure what could be causing this given that the Jibri instances work perfectly fine otherwise.

Checking the Jibri logs shows that the Jibri connected to the MUC and is standing by without issue

2022-01-26 01:58:08.716 INFO: [1] MainKt.handleCommandLineArgs#185: Jibri run with args [--config, /etc/jitsi/jibri/config.json]
2022-01-26 01:58:08.833 INFO: [1] MainKt.setupLegacyConfig#210: Checking legacy config file /etc/jitsi/jibri/config.json
2022-01-26 01:58:08.833 INFO: [1] MainKt.setupLegacyConfig#213: Legacy config file /etc/jitsi/jibri/config.json doesn't exist
2022-01-26 01:58:09.147 INFO: [1] MainKt.main#55: Jibri starting up with id 
2022-01-26 01:58:09.626 INFO: [1] JwtInfo$Companion.fromConfig#154: got jwtConfig: {}

2022-01-26 01:58:09.627 INFO: [1] JwtInfo$Companion.fromConfig#164: Unable to create JwtInfo: com.typesafe.config.ConfigException$Missing: reference.conf @ jar:file:/opt/jitsi/jibri/jibri.jar!/reference.conf: 62: No configuration setting found for key 'signing-key-path'
2022-01-26 01:58:09.789 INFO: [1] MainKt.main#125: Using port 3333 for internal HTTP API
2022-01-26 01:58:09.816 FINE: [18] WebhookClient$updateStatus$1.invokeSuspend#107: Updating 0 subscribers of status
2022-01-26 01:58:10.246 INFO: [1] XmppApi.updatePresence#144: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-01-26 01:58:10.255 INFO: [1] XmppApi.start#97: Connecting to xmpp environment on jitsi-meet.mydomain.com with config XmppEnvironmentConfig(name=Jibri Sessions, xmppServerHosts=[jitsi-meet.mydomain.com], xmppDomain=jitsi-meet.mydomain.com, baseUrl=null, controlLogin=XmppCredentials(domain=auth.jitsi-meet.mydomain.com, port=null, username=jibri, password=*****), controlMuc=XmppMuc(domain=internal.auth.jitsi-meet.mydomain.com, roomName=JibriBrewery, nickname=689b57ba-7e4b-11ec-8f40-001dd84034f1), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.jitsi-meet.mydomain.com, port=null, username=recorder, password=*****), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true, securityMode=null)
2022-01-26 01:58:10.259 INFO: [1] XmppApi.start#109: The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2022-01-26 01:58:10.292 INFO: [1] MainKt.main#151: Using port 2222 for HTTP API
2022-01-26 01:58:10.295 INFO: [29] [hostname=jitsi-meet.mydomain.com id=jitsi-meet.mydomain.com] MucClient.initializeConnectAndJoin#272: Initializing a new MucClient for [ org.jitsi.xmpp.mucclient.MucClientConfiguration id=jitsi-meet.mydomain.com domain=auth.jitsi-meet.mydomain.com hostname=jitsi-meet.mydomain.com port=null username=jibri mucs=[jibribrewery@internal.auth.jitsi-meet.mydomain.com] mucNickname=689b57ba-7e4b-11ec-8f40-001dd84034f1 disableCertificateVerification=true]
2022-01-26 01:58:10.344 WARNING: [29] MucClient.createXMPPTCPConnectionConfiguration#114: Disabling certificate verification!
2022-01-26 01:58:10.382 INFO: [29] [hostname=jitsi-meet.mydomain.com id=jitsi-meet.mydomain.com] MucClient.initializeConnectAndJoin#331: Dispatching a thread to connect and login.
2022-01-26 01:58:10.717 INFO: [29] [hostname=jitsi-meet.mydomain.com id=jitsi-meet.mydomain.com] MucClient$2.connected#304: Connected.
2022-01-26 01:58:10.718 INFO: [29] [hostname=jitsi-meet.mydomain.com id=jitsi-meet.mydomain.com] MucClient.lambda$getConnectAndLoginCallable$8#628: Logging in.
2022-01-26 01:58:10.800 INFO: [29] [hostname=jitsi-meet.mydomain.com id=jitsi-meet.mydomain.com] MucClient$2.authenticated#310: Authenticated, b=false
2022-01-26 01:58:10.850 INFO: [29] [hostname=jitsi-meet.mydomain.com id=jitsi-meet.mydomain.com] MucClient$MucWrapper.join#748: Joined MUC: jibribrewery@internal.auth.jitsi-meet.mydomain.com
2022-01-26 01:59:09.781 FINE: [18] WebhookClient$updateStatus$1.invokeSuspend#107: Updating 0 subscribers of status
2022-01-26 02:00:09.781 FINE: [18] WebhookClient$updateStatus$1.invokeSuspend#107: Updating 0 subscribers of status
2022-01-26 02:01:09.781 FINE: [18] WebhookClient$updateStatus$1.invokeSuspend#107: Updating 0 subscribers of status

Please don’t create multiple threads on the same issue; it’s tantamount to spamming the forum. You can just bump your post if you feel like it hasn’t gotten the visibility you desire.

Per your issue, when you initiate recording after the instance was previously kicked out, does Jibri successfully re-join the brewery? Does it record and stream without issues? Is there any delay in recording/streaming?

Sorry, was hoping to drop the old post as it was in the base category.

No, once the instance is removed from the brewery, Jitsi acts as if no Jibris are available and does not record or stream.

Also, when checking the API (curl localhost:8888/stats), the jibri_detector count/available will go down by X instances that were kicked out.

Restarting the jibri.service on that instance VM will get the Jibri back into the brewery and working fine without issue until it is kicked out again.

That’s weird.
When you try to activate recording after Jibri is kicked out, what does Jibri log show?

I believe it throws the generic error of no service being available
image

But I will restart a couple Jibri instances and test it once they’re kicked out to confirm.

Which jibri version is that. There is a fix for similar issue in the latest one (from unstable repo).

My latest environments that I rebuilt last night are running jibri/stable,now 8.0-116-gca0c772-1

I have been wrestling with this issue for a few weeks now though, each time pulling latest stable.

Did you build the components from source or you installed using Quick Install?

Not a quick installer (e.g. automated shell scripts), but did use a deb package and then manually configured all the required pieces

To be clear, you used this guide and installed with:

sudo apt install jitsi-meet

Is this accurate?

Yes, but my Jibri are on stand alone VMs, separate from Jitsi.

So technically I installed it by adding the Jitsi repository and then using sudo apt install jibri

I’m actually more curious about Jicofo. When you said you ‘rebuilt’, that raised a suspicion that perhaps you deployed your JMS components (Jicofo, nginx, prosody, JVB) manually, in which case, there’s a stronger possibility of misconfiguration.

On the JMS, I installed Jitsi using the deb package, which also installed nginx, jicofo, prosody, and JVB; from there I just added the configurations to enable recording and streaming, as well as JWT authentication.

When I mentioned rebuilding the server, I meant the VMs hosting the Jibri standalone service; I thought I was messing something up during the install/configuration, so I was deleting the VMs and starting over trying different things I could find.

This is the quick install, aka quick start :-/

Oh, sorry. I was thinking “quick” being some of the automated shell scripts out there that try to configure everything in one go.

Confirmed out of 5 Jibri instances brought online last night, 0 remained connected this morning.

I restarted them all around 03:43 and they started dropping off around 11:03:

# connected
Jicofo 2022-02-01 03:43:09.161 INFO: [5487] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#341: Added brewery instance: jibribrewery@internal.auth.jitsi-meet.my-domain.com/gc-instance-3
Jicofo 2022-02-01 03:43:09.161 INFO: [5487] JibriDetector.onInstanceStatusChanged#95: Creating a new instance for jibribrewery@internal.auth.jitsi-meet.my-domain.com/gc-instance-3, available = true
# disconnected
Jicofo 2022-02-01 15:36:27.310 INFO: [5652] [type=jibri brewery=jibribrewery] BaseBrewery.removeInstance#353: Removed brewery instance: jibribrewery@internal.auth.jitsi-meet.my-domain.com/gc-instance-3
Jicofo 2022-02-01 15:36:27.310 INFO: [5652] JibriDetector.notifyInstanceOffline#118: Removing instance jibribrewery@internal.auth.jitsi-meet.my-domain.com/gc-instance-3

# connected
Jicofo 2022-02-01 03:30:26.297 INFO: [5476] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#341: Added brewery instance: jibribrewery@internal.auth.jitsi-meet.my-domain.com/4f2d205e82d511ec81e2001dd800c3a0
Jicofo 2022-02-01 03:30:26.297 INFO: [5476] JibriDetector.onInstanceStatusChanged#95: Creating a new instance for jibribrewery@internal.auth.jitsi-meet.my-domain.com/4f2d205e82d511ec81e2001dd800c3a0, available = true
# disconnected
Jicofo 2022-02-01 11:03:06.925 INFO: [5595] [type=jibri brewery=jibribrewery] BaseBrewery.removeInstance#353: Removed brewery instance: jibribrewery@internal.auth.jitsi-meet.my-domain.com/4f2d205e82d511ec81e2001dd800c3a0
Jicofo 2022-02-01 11:03:06.925 INFO: [5595] JibriDetector.notifyInstanceOffline#118: Removing instance jibribrewery@internal.auth.jitsi-meet.my-domain.com/4f2d205e82d511ec81e2001dd800c3a0

# connected
Jicofo 2022-02-01 03:30:18.676 INFO: [5483] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#341: Added brewery instance: jibribrewery@internal.auth.jitsi-meet.my-domain.com/c71362e682d411ec8215001dd800a117
Jicofo 2022-02-01 03:30:18.676 INFO: [5483] JibriDetector.onInstanceStatusChanged#95: Creating a new instance for jibribrewery@internal.auth.jitsi-meet.my-domain.com/c71362e682d411ec8215001dd800a117, available = true
# disconnected
Jicofo 2022-02-01 11:49:17.870 INFO: [5602] [type=jibri brewery=jibribrewery] BaseBrewery.removeInstance#353: Removed brewery instance: jibribrewery@internal.auth.jitsi-meet.my-domain.com/c71362e682d411ec8215001dd800a117
Jicofo 2022-02-01 11:49:17.870 INFO: [5602] JibriDetector.notifyInstanceOffline#118: Removing instance jibribrewery@internal.auth.jitsi-meet.my-domain.com/c71362e682d411ec8215001dd800a117

Jitsi stats show 0 of 0 Jibris available:

[22-02-01 8:52:37] ➜  curl localhost:8888/stats
{
  "xmpp_service": {
    "total_recv": 375157,
    "total_sent": 128857
  },
  "jibri_detector": {
    "count": 0,
    "available": 0
  },
  "largest_conference": 0,
  "conference_sizes": [
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0,
    0
  ],
  "total_conferences_created": 223,
  "threads": 226,
  "xmpp": {
    "total_recv": 375157,
    "total_sent": 128857
  },
  "jingle": {
    "received": {
      "transport-info": 719,
      "session-terminate": 1,
      "session-accept": 599,
      "source-add": 650,
      "source-remove": 391
    },
    "sent": {
      "session-initiate": 601,
      "session-terminate": 73,
      "source-add": 2114,
      "source-remove": 950
    }
  },
  "bridge_failures": {
    "participants_moved": 0,
    "bridges_removed": 0
  },
  "avg_allocate_channels_req_time_nanos": 0.0,
  "total_participants": 688,
  "participant_notifications": {
    "ice_failed": 0,
    "request_restart": 1
  },
  "queues": {
    "jibri-iq-queue": {
      "added_packets": 170,
      "removed_packets": 170,
      "dropped_packets": 0,
      "duration_s": 1151249.362436167,
      "average_remove_rate_pps": 1.4766566266778363E-4,
      "queue_size_at_remove": {
        "average_queue_size_at_remove": 0.0,
        "max_queue_size_at_remove": 0,
        "total_value": 0,
        "total_count": 170,
        "buckets": {
          "<= 0": 170,
          "<= 1": 0,
          "<= 4": 0,
          "<= 16": 0,
          "<= 64": 0,
          "<= 256": 0,
          "<= 1024": 0,
          "<= 4096": 0,
          "<= 16384": 0,
          "> 16384": 0,
          "p99<=": 0,
          "p999<=": -1
        }
      }
    }
  },
  "jigasi": {},
  "bridge_selector": {
    "total_least_loaded_in_region": 0,
    "total_split_due_to_load": 0,
    "lost_bridges": 0,
    "total_not_loaded_in_region_in_conference": 0,
    "in_shutdown_bridge_count": 0,
    "total_least_loaded_in_region_in_conference": 0,
    "total_not_loaded_in_region": 0,
    "total_split_due_to_region": 0,
    "bridge_count": 1,
    "operational_bridge_count": 1,
    "total_least_loaded_in_conference": 0,
    "total_least_loaded": 134
  },
  "jibri": {
    "total_sip_call_failures": 0,
    "live_streaming_pending": 0,
    "recording_pending": 0,
    "live_streaming_active": 0,
    "total_recording_failures": 5,
    "sip_call_pending": 0,
    "sip_call_active": 0,
    "total_live_streaming_failures": 18,
    "recording_active": 0
  },
  "conferences": 0,
  "participants": 0
}

Attempting to start a recording or stream at this time, fails with the message of it not being available:

image
image

Checking the Jibri service of one of these instances that were kicked out, shows the service is still running (in this case 12hrs later):

[22-02-01 3:43:05] ➜  ~ service jibri status
● jibri.service - Jibri Process
   Loaded: loaded (/etc/systemd/system/jibri.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2022-02-01 03:43:05 UTC; 8s ago
  Process: 15757 ExecStop=/opt/jitsi/jibri/graceful_shutdown.sh (code=exited, status=0/SUCCESS)
 Main PID: 15999 (java)
    Tasks: 44 (limit: 4915)
   CGroup: /system.slice/jibri.service
           └─15999 java -Djava.util.logging.config.file=/etc/jitsi/jibri/logging.properties -Dconfig.file=/etc/jitsi/jibri/jibri.conf -jar /opt/jitsi

Feb 01 03:43:05 instance-3 systemd[1]: Started Jibri Process.
Feb 01 03:43:07 instance-3 launch.sh[15999]: SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
Feb 01 03:43:07 instance-3 launch.sh[15999]: SLF4J: Defaulting to no-operation (NOP) logger implementation
Feb 01 03:43:07 instance-3 launch.sh[15999]: SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

[22-02-01 16:13:33] ➜  ~ service jibri status
● jibri.service - Jibri Process
   Loaded: loaded (/etc/systemd/system/jibri.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2022-02-01 03:43:05 UTC; 12h ago
 Main PID: 15999 (java)
    Tasks: 40 (limit: 4915)
   CGroup: /system.slice/jibri.service
           └─15999 java -Djava.util.logging.config.file=/etc/jitsi/jibri/logging.properties -Dconfig.file=/etc/jitsi/jibri/jibri.conf -jar /opt/jitsi

Feb 01 03:43:05 instance-3 systemd[1]: Started Jibri Process.
Feb 01 03:43:07 instance-3 launch.sh[15999]: SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
Feb 01 03:43:07 instance-3 launch.sh[15999]: SLF4J: Defaulting to no-operation (NOP) logger implementation
Feb 01 03:43:07 instance-3 launch.sh[15999]: SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.```

What’s the output of:

dpkg -l "jitsi-*" "jicofo*" "prosody*" | egrep '^ii'

[22-02-01 16:43:18] ➜  ~ dpkg -l "jitsi-*" "jicofo*" "prosody*" | egrep '^ii'
ii  jicofo                1.0-832-1           all          JItsi Meet COnference FOcus
ii  jitsi-meet            2.0.6726-1          all          WebRTC JavaScript video conferences
ii  jitsi-meet-prosody    1.0.5675-1          all          Prosody configuration for Jitsi Meet
ii  jitsi-meet-tokens     1.0.5675-1          all          Prosody token authentication plugin for Jitsi Meet
ii  jitsi-meet-turnserver 1.0.5675-1          all          Configures coturn to be used with Jitsi Meet
ii  jitsi-meet-web        1.0.5675-1          all          WebRTC JavaScript video conferences
ii  jitsi-meet-web-config 1.0.5675-1          all          Configuration for web serving of Jitsi Meet
ii  jitsi-videobridge2    2.1-595-g3637fda4-1 all          WebRTC compatible Selective Forwarding Unit (SFU)
ii  prosody               0.11.10-1~focal1    amd64        Lightweight Jabber/XMPP server

Is the unstable repo public? I’d love to try out the latest version to see if that resolves the issue.

Brain was not catching up; I will try to setup an instance of latest Jibri from Index of /unstable/ and report back.

Using the unstable jibri_8.0-119-gdcb562a-1_all.deb on a new VM (ubuntu 20.04), I have had a working Jibri instance (functional recording/streaming) running without issue for 16+hrs now!

Thank you! I will be looking forward to this build making into stable!