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