Jibri Failed to send start Jibri IQ: org.jitsi.jicofo.recording.jibri.JibriSession$StartException: Unexpected response

Can you share how to do that safely ?

Hi @bbaldino ,

As you said I have upgraded the packages I’m still getting the same error.

Jicofo:

Jicofo 2021-01-20 07:11:41.592 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:11:41.592 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 for stream ID: null in room: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:11:56.594 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unexpected response to start request: null
Jicofo 2021-01-20 07:11:56.595 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Failed to send start Jibri IQ: org.jitsi.jicofo.recording.jibri.JibriSession$StartException$UnexpectedResponse: Unexpected response
org.jitsi.jicofo.recording.jibri.JibriSession$StartException$UnexpectedResponse: Unexpected response
	at org.jitsi.jicofo.recording.jibri.JibriSession.sendJibriStartIq(JibriSession.java:564)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:349)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriRecorder.handleStartRequest(JibriRecorder.java:173)
	at org.jitsi.jicofo.recording.jibri.CommonJibriStuff.handleIQRequest(CommonJibriStuff.java:249)
	at org.jitsi.jicofo.recording.jibri.OperationSetJibri.handleIQRequest(OperationSetJibri.java:98)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
	at java.base/java.lang.Thread.run(Thread.java:832)
Jicofo 2021-01-20 07:11:56.596 INFO: [32] org.jitsi.jicofo.xmpp.BaseBrewery.log() Jid member jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 had a transient error, moving to the backof the queue
Jicofo 2021-01-20 07:11:56.596 INFO: [32] org.jitsi.jicofo.xmpp.BaseBrewery.log() Removed brewery instance: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:11:56.596 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 went offline
Jicofo 2021-01-20 07:11:56.597 WARNING: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri went offline: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 for room: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:11:56.597 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 has status off and failure reason error, current Jibri jid is jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:11:56.598 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
Jicofo 2021-01-20 07:11:56.598 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri failed, trying to fall back to another Jibri
Jicofo 2021-01-20 07:11:56.598 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unable to find an available Jibri, can't start
Jicofo 2021-01-20 07:11:56.599 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Failed to fall back to another Jibri, this session has now failed: org.jitsi.jicofo.recording.jibri.JibriSession$StartException$NotAvailable: No Jibris available
org.jitsi.jicofo.recording.jibri.JibriSession$StartException$NotAvailable: No Jibris available
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:342)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:625)
	at org.jitsi.jicofo.recording.jibri.JibriSession.handleJibriStatusUpdate(JibriSession.java:695)
	at org.jitsi.jicofo.recording.jibri.JibriSession.access$900(JibriSession.java:47)
	at org.jitsi.jicofo.recording.jibri.JibriSession$JibriDetectorEventHandler.instanceOffline(JibriSession.java:910)
	at org.jitsi.jicofo.recording.jibri.JibriDetector.lambda$notifyInstanceOffline$2(JibriDetector.java:126)
	at org.jitsi.utils.event.EventEmitter.fireEvent(EventEmitter.kt:25)
	at org.jitsi.jicofo.recording.jibri.JibriDetector.notifyInstanceOffline(JibriDetector.java:124)
	at org.jitsi.jicofo.xmpp.BaseBrewery.removeInstance(BaseBrewery.java:409)
	at org.jitsi.jicofo.xmpp.BaseBrewery.memberHadTransientError(BaseBrewery.java:280)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:356)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriRecorder.handleStartRequest(JibriRecorder.java:173)
	at org.jitsi.jicofo.recording.jibri.CommonJibriStuff.handleIQRequest(CommonJibriStuff.java:249)
	at org.jitsi.jicofo.recording.jibri.OperationSetJibri.handleIQRequest(OperationSetJibri.java:98)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
	at java.base/java.lang.Thread.run(Thread.java:832)
Jicofo 2021-01-20 07:11:56.600 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Got jibri status off and failure error
Jicofo 2021-01-20 07:11:56.601 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Publishing new jibri-recording-status: <jibri-recording-status xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error' session_id='xbprwmftlziyvujl' recording_mode='file'/> in: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:11:56.602 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Cleaning up current JibriSession
Jicofo 2021-01-20 07:11:56.602 INFO: [32] org.jitsi.jicofo.xmpp.BaseBrewery.log() Added brewery instance: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:11:56.602 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:11:56.604 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 for stream ID: null in room: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:12:11.607 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unexpected response to start request: null
Jicofo 2021-01-20 07:12:11.608 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Failed to send start Jibri IQ: org.jitsi.jicofo.recording.jibri.JibriSession$StartException$UnexpectedResponse: Unexpected response
org.jitsi.jicofo.recording.jibri.JibriSession$StartException$UnexpectedResponse: Unexpected response
	at org.jitsi.jicofo.recording.jibri.JibriSession.sendJibriStartIq(JibriSession.java:564)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:349)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:625)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:360)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriRecorder.handleStartRequest(JibriRecorder.java:173)
	at org.jitsi.jicofo.recording.jibri.CommonJibriStuff.handleIQRequest(CommonJibriStuff.java:249)
	at org.jitsi.jicofo.recording.jibri.OperationSetJibri.handleIQRequest(OperationSetJibri.java:98)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
	at java.base/java.lang.Thread.run(Thread.java:832)
Jicofo 2021-01-20 07:12:11.608 INFO: [32] org.jitsi.jicofo.xmpp.BaseBrewery.log() Jid member jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 had a transient error, moving to the backof the queue
Jicofo 2021-01-20 07:12:11.609 INFO: [32] org.jitsi.jicofo.xmpp.BaseBrewery.log() Removed brewery instance: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:12:11.609 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 went offline
Jicofo 2021-01-20 07:12:11.609 INFO: [32] org.jitsi.jicofo.xmpp.BaseBrewery.log() Added brewery instance: jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:12:11.609 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76
Jicofo 2021-01-20 07:12:11.610 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 for stream ID: null in room: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:12:11.610 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Rescheduling pending timeout task for room: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:12:16.062 INFO: [31] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 status <jibri-status xmlns='http://jitsi.org/protocol/jibri'><busy-status xmlns='http://jitsi.org/protocol/jibri' status='busy'/><health-status xmlns='http://jitsi.org/protocol/health' status='healthy'/></jibri-status>
Jicofo 2021-01-20 07:12:16.125 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri jibribrewery@internal.auth.meet-qa.example.com/jibri-ip-10-11-1-76 was busy
Jicofo 2021-01-20 07:12:16.126 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Failed to send start Jibri IQ: org.jitsi.jicofo.recording.jibri.JibriSession$StartException$OneBusy: This Jibri instance was busy
org.jitsi.jicofo.recording.jibri.JibriSession$StartException$OneBusy: This Jibri instance was busy
	at org.jitsi.jicofo.recording.jibri.JibriSession.sendJibriStartIq(JibriSession.java:571)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:349)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:625)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:360)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:625)
	at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:360)
	at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:315)
	at org.jitsi.jicofo.recording.jibri.JibriRecorder.handleStartRequest(JibriRecorder.java:173)
	at org.jitsi.jicofo.recording.jibri.CommonJibriStuff.handleIQRequest(CommonJibriStuff.java:249)
	at org.jitsi.jicofo.recording.jibri.OperationSetJibri.handleIQRequest(OperationSetJibri.java:98)
	at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
	at java.base/java.lang.Thread.run(Thread.java:832)
Jicofo 2021-01-20 07:12:16.126 SEVERE: [32] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unable to find an available Jibri, can't start
Jicofo 2021-01-20 07:12:16.127 INFO: [32] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Failed to start a Jibri session, all Jibris were busy
Jicofo 2021-01-20 07:12:22.401 INFO: [66] org.jitsi.jicofo.xmpp.IqHandler.log() Logout IQ received: <iq to='focus.meet-qa.example.com' from='recorder@recorder.meet-qa.example.com/OpihWzj-' id='ba521358-5c5c-41c2-87e2-088780a913eb:sendIQ' type='set'><conference xmlns='http://jitsi.org/protocol/focus' room='test@conference.meet-qa.example.com' machine-uid='230b2214264bf0137eedbaf7edce016a'><property xmlns='http://jitsi.org/protocol/focus' name='disableRtx' value='false'/></conference></iq>
Jicofo 2021-01-20 07:12:22.402 INFO: [66] org.jitsi.jicofo.xmpp.ConferenceIqHandler.log() Focus request for room: test@conference.meet-qa.example.com
Jicofo 2021-01-20 07:12:22.543 INFO: [31] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@5599e4b6 member=ChatMember[test@conference.meet-qa.example.com/8378ca20, jid: null]@480028993]
Jicofo 2021-01-20 07:12:22.544 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.meet-qa.example.com/8378ca20 joined.
Jicofo 2021-01-20 07:12:22.554 INFO: [31] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Selected initial bridge Bridge[jid=jvbbrewery@internal.auth.meet-qa.example.com/fcb81373-9815-4e43-b8cb-911e740fd370, relayId=null, region=null, stress=0.00] with reported stress=0.0 for participantRegion=null using strategy SingleBridgeSelectionStrategy
Jicofo 2021-01-20 07:12:22.562 INFO: [31] org.jitsi.impl.protocol.xmpp.colibri.OperationSetColibriConferenceImpl.log() Conference created: org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl@372611c3
Jicofo 2021-01-20 07:12:22.564 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= test@conference.meet-qa.example.com/8378ca20, bridge=jvbbrewery@internal.auth.meet-qa.example.com/fcb81373-9815-4e43-b8cb-911e740fd370
Jicofo 2021-01-20 07:12:22.564 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=39100: [[null, null]]
Jicofo 2021-01-20 07:12:22.567 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= test@conference.meet-qa.example.com/d88ed807, bridge=jvbbrewery@internal.auth.meet-qa.example.com/fcb81373-9815-4e43-b8cb-911e740fd370
Jicofo 2021-01-20 07:12:22.568 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=39100: [[null, null, null]]
Jicofo 2021-01-20 07:12:22.570 INFO: [120] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for test@conference.meet-qa.example.com/8378ca20
Jicofo 2021-01-20 07:12:22.578 INFO: [121] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for test@conference.meet-qa.example.com/d88ed807
Jicofo 2021-01-20 07:12:22.933 INFO: [120] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for test@conference.meet-qa.example.com/8378ca20 in 363
Jicofo 2021-01-20 07:12:22.954 INFO: [120] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet-qa.example.com/fcb81373-9815-4e43-b8cb-911e740fd370 to allocate channels for: Participant[test@conference.meet-qa.example.com/8378ca20]@1395320706
Jicofo 2021-01-20 07:12:23.953 INFO: [121] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for test@conference.meet-qa.example.com/d88ed807 in 1375
Jicofo 2021-01-20 07:12:23.953 INFO: [121] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.meet-qa.example.com/fcb81373-9815-4e43-b8cb-911e740fd370 to allocate channels for: Participant[test@conference.meet-qa.example.com/d88ed807]@516223297
Jicofo 2021-01-20 07:12:24.485 INFO: [120] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: test@conference.meet-qa.example.com/8378ca20
Jicofo 2021-01-20 07:12:24.519 INFO: [121] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: test@conference.meet-qa.example.com/d88ed807
Jicofo 2021-01-20 07:12:25.115 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: test@conference.meet-qa.example.com/8378ca20
Jicofo 2021-01-20 07:12:25.125 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from test@conference.meet-qa.example.com/8378ca20 with accepted sources:Sources{ }@383904496
Jicofo 2021-01-20 07:12:25.134 WARNING: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No jingle session yet for test@conference.meet-qa.example.com/d88ed807
Jicofo 2021-01-20 07:12:27.018 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: test@conference.meet-qa.example.com/d88ed807
Jicofo 2021-01-20 07:12:27.021 INFO: [31] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from test@conference.meet-qa.example.com/d88ed807 with accepted sources:Sources{ audio: [ssrc=3372232330 ] }@1542886505

Jibri:

2021-01-20 07:11:41.627 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.meet-qa.example.com/Nm3hCSV7' from='jibribrewery@internal.auth.meet-qa.example.com/focus' id='amlicmlAYXV0aC5tZWV0LXFhLmVuZ2F0aS5jb20vTm0zaENTVjcAUVViVWMtMjExAMZhyYvuVXgsvZ3ypYAK2U0=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='test@conference.meet-qa.example.com' session_id='xbprwmftlziyvujl' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=meetserver11.qa.example.local hostname=meetserver11.qa.example.local]
2021-01-20 07:11:41.628 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request, starting service
2021-01-20 07:11:41.718 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://meet-qa.example.com, callName=test, urlParams=[])
2021-01-20 07:11:41.720 INFO: [40] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://meet-qa.example.com, callName=test, urlParams=[])), sessionId=xbprwmftlziyvujl, callLoginParams=XmppCredentials(domain=recorder.meet-qa.example.com, username=recorder, password=PAfj5v7XmbMYUjtm858fmRvY))
2021-01-20 07:11:41.734 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.call-status-checks.default-call-empty-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:11:41.741 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.call-status-checks.default-call-empty-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:11:41.763 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.chrome.flags' from source 'config' as type kotlin.collections.List<kotlin.String>
2021-01-20 07:11:41.765 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.chrome.flags' from source 'config' as type kotlin.collections.List<kotlin.String>
2021-01-20 07:11:48.742 FINE: [16] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
2021-01-20 07:11:56.638 INFO: [53] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.meet-qa.example.com/Nm3hCSV7' from='jibribrewery@internal.auth.meet-qa.example.com/focus' id='amlicmlAYXV0aC5tZWV0LXFhLmVuZ2F0aS5jb20vTm0zaENTVjcAUVViVWMtMjI1AMZhyYvuVXgsvZ3ypYAK2U0=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='test@conference.meet-qa.example.com' session_id='xbprwmftlziyvujl' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=meetserver11.qa.example.local hostname=meetserver11.qa.example.local]
2021-01-20 07:11:56.646 INFO: [53] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request, starting service
2021-01-20 07:11:56.657 INFO: [53] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://meet-qa.example.com, callName=test, urlParams=[])
2021-01-20 07:12:01.075 FINE: [54] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Got health request
2021-01-20 07:12:01.076 FINE: [54] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Returning health JibriHealth(status=JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), environmentContext=null)
2021-01-20 07:12:11.643 INFO: [55] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.meet-qa.example.com/Nm3hCSV7' from='jibribrewery@internal.auth.meet-qa.example.com/focus' id='amlicmlAYXV0aC5tZWV0LXFhLmVuZ2F0aS5jb20vTm0zaENTVjcAUVViVWMtMjMzAMZhyYvuVXgsvZ3ypYAK2U0=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='test@conference.meet-qa.example.com' session_id='xbprwmftlziyvujl' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=meetserver11.qa.example.local hostname=meetserver11.qa.example.local]
2021-01-20 07:12:11.643 INFO: [55] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request, starting service
2021-01-20 07:12:11.648 INFO: [55] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://meet-qa.example.com, callName=test, urlParams=[])
2021-01-20 07:12:15.975 INFO: [40] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
2021-01-20 07:12:16.061 FINE: [40] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.<init>() Detected os as OS: LINUX
2021-01-20 07:12:16.069 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
  LambdaSupplier: 'JibriConfig::recordingDirectory'
  ConfigSourceSupplier: key: 'jibri.recording.recordings-directory', type: 'kotlin.String', source: 'config'
2021-01-20 07:12:16.071 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::recordingDirectory
2021-01-20 07:12:16.072 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: failed to find value via LambdaSupplier: 'JibriConfig::recordingDirectory': org.jitsi.metaconfig.ConfigException$UnableToRetrieve$Error: class kotlin.KotlinNullPointerException
2021-01-20 07:12:16.072 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.recording.recordings-directory' from source 'config' as type kotlin.String
2021-01-20 07:12:16.073 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.recording.recordings-directory' from source 'config' as type kotlin.String
2021-01-20 07:12:16.073 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: value found via ConfigSourceSupplier: key: 'jibri.recording.recordings-directory', type: 'kotlin.String', source: 'config'
2021-01-20 07:12:16.074 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
  LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath'
  ConfigSourceSupplier: key: 'jibri.recording.finalize-script', type: 'kotlin.String', source: 'config'
2021-01-20 07:12:16.074 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::finalizeRecordingScriptPath
2021-01-20 07:12:16.075 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: failed to find value via LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath': org.jitsi.metaconfig.ConfigException$UnableToRetrieve$Error: class kotlin.KotlinNullPointerException
2021-01-20 07:12:16.075 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.recording.finalize-script' from source 'config' as type kotlin.String
2021-01-20 07:12:16.076 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.recording.finalize-script' from source 'config' as type kotlin.String
2021-01-20 07:12:16.076 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: value found via ConfigSourceSupplier: key: 'jibri.recording.finalize-script', type: 'kotlin.String', source: 'config'
2021-01-20 07:12:16.076 INFO: [40] org.jitsi.jibri.service.impl.FileRecordingJibriService.<init>() Writing recording to /recordings/xbprwmftlziyvujl, finalize script path /etc/jitsi/jibri/final.sh
2021-01-20 07:12:16.086 FINE: [40] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
2021-01-20 07:12:16.087 INFO: [40] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
2021-01-20 07:12:16.088 FINE: [40] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
2021-01-20 07:12:16.088 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.updatePresence() Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2021-01-20 07:12:16.090 INFO: [40] org.jitsi.jibri.JibriManager.startService() This service will have a usage timeout of 60 minute(s)
2021-01-20 07:12:16.093 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending 'pending' response to start IQ
2021-01-20 07:12:16.111 INFO: [55] org.jitsi.jibri.JibriManager.throwIfBusy() Jibri is busy, can't start service
2021-01-20 07:12:16.112 FINE: [55] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: busy:recording
2021-01-20 07:12:16.113 SEVERE: [55] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Jibri is currently busy, cannot service this request
2021-01-20 07:12:16.113 INFO: [53] org.jitsi.jibri.JibriManager.throwIfBusy() Jibri is busy, can't start service
2021-01-20 07:12:16.114 FINE: [53] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: busy:recording
2021-01-20 07:12:16.114 SEVERE: [53] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Jibri is currently busy, cannot service this request
2021-01-20 07:12:20.491 FINE: [60] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url https://meet-qa.example.com/test#config.iAmRecorder=true&config.externalConnectUrl=null&config.startWithAudioMuted=true&config.startWithVideoMuted=true&interfaceConfig.APP_NAME="Jibri"&config.analytics.disabled=true&config.p2p.enabled=false&config.prejoinPageEnabled=false&config.requireDisplayName=false
2021-01-20 07:12:21.479 FINE: [60] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
2021-01-20 07:12:21.989 FINE: [60] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
2021-01-20 07:12:23.020 INFO: [60] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Waited 1605 milliseconds for call page to load
2021-01-20 07:12:23.021 INFO: [60] org.jitsi.jibri.selenium.JibriSelenium.<init>() Starting empty call check with a timeout of PT30S
2021-01-20 07:12:23.037 INFO: [60] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Running
2021-01-20 07:12:23.039 INFO: [60] org.jitsi.jibri.service.impl.FileRecordingJibriService.invoke() Selenium joined the call, starting the capturer
2021-01-20 07:12:23.079 INFO: [60] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.launch() Starting ffmpeg with command ffmpeg -y -v info -f x11grab -draw_mouse 0 -r 30 -s 1280x720 -thread_queue_size 4096 -i :0.0+0,0 -f alsa -thread_queue_size 4096 -i plug:bsnoop -acodec aac -strict -2 -ar 44100 -b:a 128k -af aresample=async=1 -c:v libx264 -preset veryfast -profile:v main -level 3.1 -pix_fmt yuv420p -r 30 -crf 25 -g 60 -tune zerolatency -f mp4 /recordings/xbprwmftlziyvujl/test_2021-01-20-07-12-16.mp4 ([ffmpeg, -y, -v, info, -f, x11grab, -draw_mouse, 0, -r, 30, -s, 1280x720, -thread_queue_size, 4096, -i, :0.0+0,0, -f, alsa, -thread_queue_size, 4096, -i, plug:bsnoop, -acodec, aac, -strict, -2, -ar, 44100, -b:a, 128k, -af, aresample=async=1, -c:v, libx264, -preset, veryfast, -profile:v, main, -level, 3.1, -pix_fmt, yuv420p, -r, 30, -crf, 25, -g, 60, -tune, zerolatency, -f, mp4, /recordings/xbprwmftlziyvujl/test_2021-01-20-07-12-16.mp4])
2021-01-20 07:12:28.166 FINE: [16] org.jitsi.jibri.util.ProcessStatePublisher.ffmpeg.invoke() Process ffmpeg hasn't written in 2 seconds, publishing periodic update
2021-01-20 07:12:30.166 FINE: [16] org.jitsi.jibri.util.ProcessStatePublisher.ffmpeg.invoke() Process ffmpeg hasn't written in 2 seconds, publishing periodic update
2021-01-20 07:12:33.036 INFO: [63] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Starting up to Running
2021-01-20 07:12:33.039 INFO: [63] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Running
2021-01-20 07:12:33.045 INFO: [63] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service started up successfully, sending on iq <iq to='jibribrewery@internal.auth.meet-qa.example.com/focus' id='4pAaz-28' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='on'/></iq>
2021-01-20 07:12:38.228 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:12:38.232 FINE: [16] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.call-status-checks.all-muted-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:12:38.244 FINE: [16] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.call-status-checks.all-muted-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:12:38.246 FINE: [16] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.call-status-checks.no-media-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:12:38.250 FINE: [16] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.call-status-checks.no-media-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:12:48.742 FINE: [16] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
2021-01-20 07:12:53.083 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=34, upload=0}, download=34, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:13:01.211 FINE: [43] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Got health request
2021-01-20 07:13:01.211 FINE: [43] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Returning health JibriHealth(status=JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), environmentContext=EnvironmentContext(name=Jitsi))
2021-01-20 07:13:08.092 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=34, upload=0}, download=34, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:13:23.072 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=34, upload=0}, download=34, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:13:38.075 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=33, upload=0}, download=33, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:13:48.742 FINE: [16] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
2021-01-20 07:13:53.073 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=40, upload=0}, download=40, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:14:01.935 FINE: [54] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Got health request
2021-01-20 07:14:01.935 FINE: [54] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Returning health JibriHealth(status=JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), environmentContext=EnvironmentContext(name=Jitsi))
2021-01-20 07:14:08.086 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=34, upload=0}, download=34, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:14:23.075 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=32, upload=0}, download=32, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:14:38.097 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=33, upload=0}, download=33, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:14:48.742 FINE: [16] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
2021-01-20 07:14:53.080 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=35, upload=0}, download=35, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false
2021-01-20 07:15:01.724 FINE: [43] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Got health request
2021-01-20 07:15:01.724 FINE: [43] org.jitsi.jibri.api.http.HttpApi.invokeSuspend() Returning health JibriHealth(status=JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), environmentContext=EnvironmentContext(name=Jitsi))
2021-01-20 07:15:08.072 INFO: [16] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=33, upload=0}, download=33, upload=0, video={download=0, upload=0}}, num participants: 1, numMutedParticipants: 0, numJigasis: 0, all clients muted? false

Package versions:

jibri                          8.0-61-g99288dc-1 
jicofo                         1.0-691-hf-1
jitsi-meet                     2.0.5390-2
jitsi-meet-prosody             1.0.4628-1
jitsi-meet-tokens              1.0.4628-1
jitsi-meet-turnserver          1.0.4628-1
jitsi-meet-web                 1.0.4628-1
jitsi-meet-web-config          1.0.4628-1
jitsi-videobridge2             2.1-416-g2f43d1b4-1

So this looks like something is up with your Jibri. It receives a start request, and starts a recording, but then things just stop:

2021-01-20 07:11:41.627 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.meet-qa.example.com/Nm3hCSV7' from='jibribrewery@internal.auth.meet-qa.example.com/focus' id='amlicmlAYXV0aC5tZWV0LXFhLmVuZ2F0aS5jb20vTm0zaENTVjcAUVViVWMtMjExAMZhyYvuVXgsvZ3ypYAK2U0=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='test@conference.meet-qa.example.com' session_id='xbprwmftlziyvujl' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=meetserver11.qa.example.local hostname=meetserver11.qa.example.local]
2021-01-20 07:11:41.628 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request, starting service
2021-01-20 07:11:41.718 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://meet-qa.example.com, callName=test, urlParams=[])
2021-01-20 07:11:41.720 INFO: [40] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://meet-qa.example.com, callName=test, urlParams=[])), sessionId=xbprwmftlziyvujl, callLoginParams=XmppCredentials(domain=recorder.meet-qa.example.com, username=recorder, password=PAfj5v7XmbMYUjtm858fmRvY))
2021-01-20 07:11:41.734 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.call-status-checks.default-call-empty-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:11:41.741 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.call-status-checks.default-call-empty-timeout' from source 'config' as type java.time.Duration
2021-01-20 07:11:41.763 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.chrome.flags' from source 'config' as type kotlin.collections.List<kotlin.String>
2021-01-20 07:11:41.765 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.chrome.flags' from source 'config' as type kotlin.collections.List<kotlin.String>
2021-01-20 07:11:48.742 FINE: [16] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
2021-01-20 07:11:56.638 INFO: [53] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.meet-qa.example.com/Nm3hCSV7' from='jibribrewery@internal.auth.meet-qa.example.com/focus' id='amlicmlAYXV0aC5tZWV0LXFhLmVuZ2F0aS5jb20vTm0zaENTVjcAUVViVWMtMjI1AMZhyYvuVXgsvZ3ypYAK2U0=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='test@conference.meet-qa.example.com' session_id='xbprwmftlziyvujl' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=meetserver11.qa.example.local hostname=meetserver11.qa.example.local]

Notice how there is a big jump in time after 07:11:41: it goes to 07:11:48 with a periodic webhook client update and then to 07:11:56 with another request.

Jicofo is complaining because it doesn’t receive any response from Jibri for its request, so the request times out and gives that null result. So Jibri is getting hung up on something, but it’s hard to tell where: it could be something with chromedriver or chrome, I’d make sure those are up-to-date and are compatible versions.

I’m using the following chrome and chrome driver versions:

ChromeDriver 87.0.4280.88
Google Chrome 87.0.4280.88

Do you have any way of ‘watching’ the Jibri machine to see what happens? I’d also try Jibri with those versions on another machine–ideally one you can ‘watch’ to see if that gives you any clues.

I have setup vncserver on the autoscaled jibri instances and connect to them before starting the recording.

On the first attempt, google chrome is taking some time to startup, other than that everything looks good.

I think this is the issue. Is this fixed ?

If this is the issue, some minor hack can help. Autostart chromium or chrome when icewm starts and kill it after some seconds

/home/jibri/.icewm/startup

#!/bin/bash

chromium https://your.jitsi.host &
(sleep 20 && pkill --oldest --signal TERM '(chromium|chrome|google-chrome)' &

set the execute permission

chmod 755 /home/jibri/.icewm/startup
3 Likes

Wow. This worked. You are a lifesaver.
Thanks a lot, @emrah @bbaldino

1 Like

Hm, this is not the failure mode I remembered for a slow chrome start-up though–that’s pretty lousy. I also don’t ever remember chrome taking this long…this was like over 15 seconds? Maybe we’ll need a timeout there.

Yeah. I think icewm on the first startup takes some time to bring up chrome. I think this can be fixed from the code itself by adding a timeout.

or adding an option to bring up a chrome window to do a test-run to make sure jibri is actually healthy.

Sharing the script I’m using on my setup.

#!/bin/bash
/usr/bin/google-chrome https://{{ jitsi_hostname }} &
PID=$!
sleep 10
kill $PID
1 Like

We had the same problem on our deployment. We’re using jibri in docker on AWS cloud and also use auto scaling. The first time recording was started on a particular jibri, jitsi always said it failed to start but the jibri went busy and actually recorded the session.
@Vyshak_M we used your script to launch Google Chrome, however we had to increase sleep to 30 seconds before killing Chrome because 10 seconds was not enough to launch it.

IIRC chrome forks itself and the original pid is no longer exist after 10 secs

Try increasing docker resources.
I was using a t3a.large instance and it took 5 to 10 seconds for chrome to come up. But in my experience, I think killing chrome before it getting started is not an issue because, bringing up chrome is staring up the graphical services which is required for actually running jibri.

Thank you for the scripts and the possible solution.
I’m running into problems trying to use your fix, it seems like Jibri is not running the script.

I’ve given all necessary permissions to run it, I’ve written the script inside startup in /home/jibri/.icewm/ but it just doesn’t work.

Can you help me find the reason why Jibri is not executing the script? Is there any additional setup I need to work on to make Jibri run it?

Thank you in advance!

Did you restart the jibri-xorg service?

Not sure if this is going to help.

There is a package called x11vnc. You can try installing that on the jibri server and connect to it from your local to see what’s going on the jibri server.

I’ve tried restarting it today but it doesn’t seem to work.
I’ve added a file creation inside the script for debugging but the file is not being created so I guess the script is not executing yet.

@Vyshak_M can it help me to understand why jibri is not executing my script?

Thank you very much to both of you for your time

ls -alh /home/jibri
ls -alh /home/jibri/.icewm

This is what I get. I think permissions are valid, right?

drwxr-xr-x 2 root root 4.0K Feb 22 12:31 .icewm
-rwxr-xr-x 1 root root 158 Feb 20 12:53 startup