Unable To Connect To Jibri Instances...Focus Error

Install & Config
1

I am having an issue where I am able to connect to Jibri instances as of recent. First weird error I get that MIGHT be related but not sure is this when I start a jitsi meeting in the browser, I get:

2021-11-17T15:23:34.983Z [modules/xmpp/moderator.js] <l._allocateConferenceFocusError>: Focus error, retry after 1000 <iq xmlns=​"jabber:​client" type=​"error" from=​"focus.meet.example.com" to=​"23296ba9-8d78-4573-b791-b9484c314a97@meet.example.com/​DVhZ2WWS" id=​"440f3555-1109-465e-a655-3b35195e0c0b:​sendIQ">​<error type=​"modify">​…​</error>​</iq>​

I say MIGHT because the webrtc is still working and the focus error might be relevant to below. When I try to start a stream or recording, an http POST request is sent to jisti like this:

https://meet.example.com/http-bind?token=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJiaW5nZXdhdmUtd2VicnRjIiwiaXNzIjoiYmluZ2V3YXZlLXdlYnJ0YyIsInN1YiI6Idffdfdfdm1lZXQuYmluZ2V3YXZlLmNvbSIsInJvb20iOiIqIn0.NUvbPsKW9ahAyeTVMVEIGWrhLoPH8UJfRCvUbWhi5u0

And the response is this:

<body xmlns='http://jabber.org/protocol/httpbind' sid='b1085b55-c59a-4259-8d31-360baafcf5d5' xmlns:stream='http://etherx.jabber.org/streams'><iq from='b9f9d55f-10cd-4c01-b8c2-d807a196617d@conference.meet.bingewave.com/focus' xmlns='jabber:client' id='fe719b49-05fd-406a-9bba-814f1a1ee670:sendIQ' to='edbddb71-23e2-4909-80ae-5ae539ca86cc@meet.example.com/FHVbHqWk' type='error'><error type='cancel'><internal-server-error xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xml:lang='en' xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Internal server error</text></error></iq></body>

And the Jicofo logs report this:

icofo 2021-11-17 15:17:17.060 INFO: [230] [type=jibri brewery=jibribrewery] BaseBrewery.memberHadTransientError#244: Jid member jibribrewery@internal.auth.meet.example.com/jibri-nickname had a transient error, moving to the back of the queue
Jicofo 2021-11-17 15:17:17.060 INFO: [230] [type=jibri brewery=jibribrewery] BaseBrewery.removeInstance#350: Removed brewery instance: jibribrewery@internal.auth.meet.example.com/jibri-nickname
Jicofo 2021-11-17 15:17:17.060 INFO: [230] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#338: Added brewery instance: jibribrewery@internal.auth.meet.example.com/jibri-nickname
Jicofo 2021-11-17 15:17:17.061 WARNING: [230] [room=b9f9d55f-10cd-4c01-b8c2-d807a196617d@conference.meet.example.com meeting_id=e15b29fe-4635-4b7c-94cd-d89cd68e8067] JibriRecorder.handleStartRequest#128: Failed to start a Jibri session: Internal server error
org.jitsi.jicofo.jibri.JibriSession$StartException$InternalServerError: Internal server error
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:333)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:586)
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:329)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:586)
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:329)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:586)
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:329)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:586)
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:329)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriRecorder.handleStartRequest(JibriRecorder.kt:112)
	at org.jitsi.jicofo.jibri.BaseJibri.doHandleIQRequest(BaseJibri.kt:166)
	at org.jitsi.jicofo.jibri.BaseJibri.access$doHandleIQRequest(BaseJibri.kt:42)
	at org.jitsi.jicofo.jibri.BaseJibri$incomingIqQueue$1.handlePacket(BaseJibri.kt:53)
	at org.jitsi.jicofo.jibri.BaseJibri$incomingIqQueue$1.handlePacket(BaseJibri.kt:42)
	at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:380)
	at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:133)
	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 2021-11-17 15:17:17.061 INFO: [232] JibriSession.startInternal#316: Starting session with Jibri jibribrewery@internal.auth.meet.example.com/jibri-nickname
Jicofo 2021-11-17 15:17:17.061 INFO: [232] JibriSession.sendJibriStartIq#478: Starting Jibri jibribrewery@internal.auth.meet.examplecom/jibri-nickname for stream ID: rtmp://ingest.example.com/live/b9f9d55f-10cd-4c01-b8c2-d807a196617d-broadcast?sign=1637767020-390613d6f30851911eeac41a6ea7e30a in room: b9f9d55f-10cd-4c01-b8c2-d807a196617d@conference.meet.example.com
Jicofo 2021-11-17 15:17:17.061 INFO: [232] JibriSession.reschedulePendingTimeout#554: Rescheduling pending timeout task for room: b9f9d55f-10cd-4c01-b8c2-d807a196617d@conference.meet.example.com
Jicofo 2021-11-17 15:17:17.304 SEVERE: [232] JibriSession.sendJibriStartIq#536: Unexpected status received in response to the start IQ: <iq to='focus@auth.meet.examplpe/focus' from='jibribrewery@internal.auth.meet.example/jibri-nickname' id='yT8Yq-1322' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error' should_retry='true'/></iq>
Jicofo 2021-11-17 15:17:17.304 SEVERE: [232] JibriSession.startInternal#322: Failed to send start Jibri IQ: org.jitsi.jicofo.jibri.JibriSession$StartException$UnexpectedResponse: Unexpected response
org.jitsi.jicofo.jibri.JibriSession$StartException$UnexpectedResponse: Unexpected response
	at org.jitsi.jicofo.jibri.JibriSession.sendJibriStartIq(JibriSession.java:540)
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:318)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:586)
	at org.jitsi.jicofo.jibri.JibriSession.handleJibriStatusUpdate(JibriSession.java:654)
	at org.jitsi.jicofo.jibri.JibriSession.access$900(JibriSession.java:48)
	at org.jitsi.jicofo.jibri.JibriSession$JibriDetectorEventHandler.instanceOffline(JibriSession.java:864)
	at org.jitsi.jicofo.jibri.JibriDetector$notifyInstanceOffline$1.invoke(JibriDetector.kt:73)
	at org.jitsi.jicofo.jibri.JibriDetector$notifyInstanceOffline$1.invoke(JibriDetector.kt:37)
	at org.jitsi.utils.event.AsyncEventEmitter$fireEventAsync$$inlined$forEach$lambda$1$1.invoke(EventEmitter.kt:54)
	at org.jitsi.utils.event.AsyncEventEmitter$fireEventAsync$$inlined$forEach$lambda$1$1.invoke(EventEmitter.kt:50)
	at org.jitsi.utils.event.EventEmitter.wrap(EventEmitter.kt:43)
	at org.jitsi.utils.event.AsyncEventEmitter$fireEventAsync$$inlined$forEach$lambda$1.run(EventEmitter.kt:54)
	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 2021-11-17 15:17:17.304 INFO: [232] [type=jibri brewery=jibribrewery] BaseBrewery.memberHadTransientError#244: Jid member jibribrewery@internal.auth.meet.bingewave.com/jibri-nickname had a transient error, moving to the back of the queue
Jicofo 2021-11-17 15:17:17.304 INFO: [232] [type=jibri brewery=jibribrewery] BaseBrewery.removeInstance#350: Removed brewery instance: jibribrewery@internal.auth.meet.example.com/jibri-nickname
Jicofo 2021-11-17 15:17:17.304 INFO: [232] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#338: Added brewery instance: jibribrewery@internal.auth.meet.example.com/jibri-nickname
Jicofo 2021-11-17 15:17:17.304 WARNING: [232] JibriSession.handleJibriStatusUpdate#661: Failed to fall back to another Jibri, this session has now failed: org.jitsi.jicofo.jibri.JibriSession$StartException$InternalServerError: Internal server error
org.jitsi.jicofo.jibri.JibriSession$StartException$InternalServerError: Internal server error
	at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:333)
	at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:284)
	at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:586)
	at org.jitsi.jicofo.jibri.JibriSession.handleJibriStatusUpdate(JibriSession.java:654)
	at org.jitsi.jicofo.jibri.JibriSession.access$900(JibriSession.java:48)
	at org.jitsi.jicofo.jibri.JibriSession$JibriDetectorEventHandler.instanceOffline(JibriSession.java:864)
	at org.jitsi.jicofo.jibri.JibriDetector$notifyInstanceOffline$1.invoke(JibriDetector.kt:73)
	at org.jitsi.jicofo.jibri.JibriDetector$notifyInstanceOffline$1.invoke(JibriDetector.kt:37)
	at org.jitsi.utils.event.AsyncEventEmitter$fireEventAsync$$inlined$forEach$lambda$1$1.invoke(EventEmitter.kt:54)
	at org.jitsi.utils.event.AsyncEventEmitter$fireEventAsync$$inlined$forEach$lambda$1$1.invoke(EventEmitter.kt:50)
	at org.jitsi.utils.event.EventEmitter.wrap(EventEmitter.kt:43)
	at org.jitsi.utils.event.AsyncEventEmitter$fireEventAsync$$inlined$forEach$lambda$1.run(EventEmitter.kt:54)
	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 2021-11-17 15:17:17.305 SEVERE: [232] [room=b9f9d55f-10cd-4c01-b8c2-d807a196617d@conference.meet.example.com meeting_id=e15b29fe-4635-4b7c-94cd-d89cd68e8067] JibriRecorder.onSessionStateChanged#145: onSessionStateChanged for unknown session: org.jitsi.jicofo.jibri.JibriSession@4d4df5f3
Jicofo 2021-11-17 15:17:17.305 INFO: [232] JibriSession.cleanupSession#394: Cleaning up current JibriSession

Now I have 2 Jibri instances, both which are showing a health status when I do a /jibri/api/v1.0/health. Any thoghts on what could be happening?

2

Check Jibri logs.

3

@damencho My logs in jibri.

2021-11-17 15:26:04.690 INFO: [1] org.jitsi.jibri.Main.log() Jibri run with args [--config, /etc/jitsi/jibri/config.json]
2021-11-17 15:26:04.796 INFO: [1] org.jitsi.jibri.Main.log() Checking legacy config file /etc/jitsi/jibri/config.json
2021-11-17 15:26:04.796 INFO: [1] org.jitsi.jibri.Main.log() Legacy config file /etc/jitsi/jibri/config.json doesn't exist
2021-11-17 15:26:05.163 INFO: [1] org.jitsi.jibri.Main.log() Jibri starting up with id instance-2
2021-11-17 15:26:05.883 INFO: [1] org.jitsi.jibri.webhooks.v1.JwtInfo.log() got jwtConfig: {}

2021-11-17 15:26:05.883 INFO: [1] org.jitsi.jibri.webhooks.v1.JwtInfo.log() Unable to create JwtInfo: com.typesafe.config.ConfigException$Missing: /etc/jitsi/jibri/jibri.conf: 87: No configuration setting found for key 'signing-key-path'
2021-11-17 15:26:06.048 INFO: [1] org.jitsi.jibri.Main.log() Using port 3333 for internal HTTP API
2021-11-17 15:26:06.091 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:26:06.560 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.log() Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2021-11-17 15:26:06.569 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.log() Connecting to xmpp environment on meet.example.com with config XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[meet.example.com], xmppDomain=meet.example.com, baseUrl=null, controlLogin=XmppCredentials(domain=auth.meet.example.com, port=null, username=jibri, password=*****), controlMuc=XmppMuc(domain=internal.auth.meet.example.com, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.meet.example.com, port=null, username=recorder, password=*****), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)
2021-11-17 15:26:06.570 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.log() The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2021-11-17 15:26:06.597 INFO: [1] org.jitsi.jibri.Main.log() Using port 2222 for HTTP API
2021-11-17 15:26:06.600 WARNING: [28] org.jitsi.xmpp.mucclient.MucClient.log() Disabling certificate verification!
2021-11-17 15:26:06.995 INFO: [28] org.jitsi.xmpp.mucclient.MucClient.log() Connected.
2021-11-17 15:26:06.996 INFO: [28] org.jitsi.xmpp.mucclient.MucClient.log() Logging in.
2021-11-17 15:26:07.065 INFO: [28] org.jitsi.xmpp.mucclient.MucClient.log() Joined MUC: jibribrewery@internal.auth.meet.example.com
2021-11-17 15:27:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:28:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:29:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:30:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:31:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:32:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:33:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:34:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:35:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:36:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:37:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:38:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:39:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:40:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:41:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:42:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:43:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status
2021-11-17 15:44:06.044 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status

Also my jwtinfo is empty in the config, so according to the instructions its not set.

  jwt-info {
    // The path to a .pem file which will be used to sign JWT tokens used in webhook
    // requests.  If not set, no JWT will be added to webhook requests.
    # signing-key-path = "/path/to/key.pem"

    // The kid to use as part of the JWT
    # kid = "key-id"

    // The issuer of the JWT
    # issuer = "issuer"

    // The audience of the JWT
    # audience = "audience"

    // The TTL of each generated JWT.  Can't be less than 10 minutes.
    # ttl = 1 hour
  }
4

@damencho Last, when I try to start a stream or recording, the http response form the service is this

<body xmlns='http://jabber.org/protocol/httpbind' sid='b1085b55-c59a-4259-8d31-360baafcf5d5' xmlns:stream='http://etherx.jabber.org/streams'><iq from='b9f9d55f-10cd-4c01-b8c2-d807a196617d@conference.meet.example.com/focus' xmlns='jabber:client' id='fe719b49-05fd-406a-9bba-814f1a1ee670:sendIQ' to='edbddb71-23e2-4909-80ae-5ae539ca86cc@meet.bingewave.com/FHVbHqWk' type='error'><error type='cancel'><internal-server-error xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xml:lang='en' xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Internal server error</text></error></iq></body>
5

@damencho Last one, my other Jibri instance has this in its log

2021-11-17 15:46:14.055 WARNING: [59] org.jivesoftware.smack.AbstractXMPPConnection.callConnectionClosedOnErrorListener() Connection XMPPTCPConnection[jibri@auth.meet.example.com/jraJkfBy] (0) closed with error

org.jivesoftware.smack.XMPPException$StreamErrorException: system-shutdown You can read more about the meaning of this stream error at http://xmpp.org/rfcs/rfc6120.html#streams-error-conditions

<stream:error><system-shutdown xmlns='urn:ietf:params:xml:ns:xmpp-streams'/><text>Received SIGTERM</text></stream:error>

at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1064)

at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:1000)

at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:1016)

at java.base/java.lang.Thread.run(Thread.java:829)

2021-11-17 15:46:14.055 WARNING: [59] org.jitsi.xmpp.mucclient.MucClient.log() Closed on error:

org.jivesoftware.smack.XMPPException$StreamErrorException: system-shutdown You can read more about the meaning of this stream error at http://xmpp.org/rfcs/rfc6120.html#streams-error-conditions

<stream:error><system-shutdown xmlns='urn:ietf:params:xml:ns:xmpp-streams'/><text>Received SIGTERM</text></stream:error>

at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1064)

at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:1000)

at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:1016)

at java.base/java.lang.Thread.run(Thread.java:829)

2021-11-17 15:46:33.963 FINE: [19] org.jitsi.jibri.webhooks.v1.WebhookClient.log() Updating 0 subscribers of status

2021-11-17 15:46:34.363 WARNING: [263] org.jitsi.xmpp.mucclient.MucClient.log() Reconnection failed:

org.jivesoftware.smack.SmackException$ConnectionException: The following addresses failed: 'meet.example.com:5222' failed because: meet.example.com/3.92.87.89 exception: java.net.ConnectException: Connection refused (Connection refused)

at org.jivesoftware.smack.SmackException$ConnectionException.from(SmackException.java:278)

at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration(XMPPTCPConnection.java:619)

at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectInternal(XMPPTCPConnection.java:902)

at org.jivesoftware.smack.AbstractXMPPConnection.connect(AbstractXMPPConnection.java:383)

at org.jivesoftware.smack.ReconnectionManager$2.run(ReconnectionManager.java:289)

at java.base/java.lang.Thread.run(Thread.java:829)

2021-11-17 15:46:47.392 INFO: [263] org.jitsi.xmpp.mucclient