[Solved] Permission denied for jibri when using web socket

Greetings,
I have running docker-meet instances which has two jibri (one from same machine and another from remote machine). Connections and authentication is good.

I have recently upgraded the stack to the latest one, and the recording was working fine.

The configurations and the scripts are identical to the official ones, I am using the jwt auth with allow_empty_token = false , also the c2s_require_encryption = false and XMPP_CROSSDOMAIN=true.

Whenever I start recording, the jibri gets 403 permission denied error and tries for several times resulting recording failed to start eror after 2-3 mins.

Recording works with xmpp websocket disabled.

Is there anyway to work it with websocket enabled?

Update:It was certificate issue, I just pointed to the valid public domain.

"GET /xmpp-websocket?room=test HTTP/1.1" 403 281 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"

Logs:

jicofo_1    | Jicofo 2021-01-07 14:34:05.484 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.classroom.mst/focus112736587765608' from='jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780' id='Zm9jdXNAYXV0aC5jbGFzc3Jvb20ubXN0L2ZvY3VzMTEyNzM2NTg3NzY1NjA4AFYxSzRRLTQyNjUAXLKSsNKPWXKwsigR2rL75Q==' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error' should_retry='true'/></iq> for a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jicofo_1    | Jicofo 2021-01-07 14:34:05.484 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 has status off and failure reason error, current Jibri jid is jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780
jicofo_1    | Jicofo 2021-01-07 14:34:05.484 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
jicofo_1    | Jicofo 2021-01-07 14:34:05.485 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri failed, trying to fall back to another Jibri
jicofo_1    | Jicofo 2021-01-07 14:34:05.485 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979
jicofo_1    | Jicofo 2021-01-07 14:34:05.485 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 for stream ID: null in room: a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jibri_1     | 2021-01-07 14:34:05.488 FINE: [40] org.jitsi.xmpp.mucclient.MucClient.log() Received an IQ with type set: IQ Stanza (jibri http://jitsi.org/protocol/jibri) [to=jibri@auth.classroom.mst/EADx4PgL,from=jibribrewery@internal-muc.classroom.mst/focus,id=amlicmlAYXV0aC5jbGFzc3Jvb20ubXN0L0VBRHg0UGdMAEtNRTBuLTIzMQB7XHcbWZqPj55Vj8pKPSSP,type=set,]
jibri_1     | 2021-01-07 14:34:05.490 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.classroom.mst/EADx4PgL' from='jibribrewery@internal-muc.classroom.mst/focus' id='amlicmlAYXV0aC5jbGFzc3Jvb20ubXN0L0VBRHg0UGdMAEtNRTBuLTIzMQB7XHcbWZqPj55Vj8pKPSSP' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst' session_id='gktbrpyniyjmipft' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=xmpp.classroom.mst hostname=xmpp.classroom.mst]
jibri_1     | 2021-01-07 14:34:05.492 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request, starting service
jibri_1     | 2021-01-07 14:34:05.513 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://classroom.mst, callName=a5abecc6-504f-11eb-8d0e-06602663d142, urlParams=[])
jibri_1     | 2021-01-07 14:34:05.516 INFO: [40] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://classroom.mst, callName=a5abecc6-504f-11eb-8d0e-06602663d142, urlParams=[])), sessionId=gktbrpyniyjmipft, callLoginParams=XmppCredentials(domain=recorder.classroom.mst, username=recorder, password=aaa0cbf4b417eac9fedc2ee637f9beac))
jibri_1     | 2021-01-07 14:34:05.523 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
jibri_1     | 2021-01-07 14:34:05.531 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
jibri_1     | 2021-01-07 14:34:05.541 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>
jibri_1     | 2021-01-07 14:34:05.543 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.chrome.flags' from source 'config' as type kotlin.collections.List<kotlin.String>
jibri_1     | Starting ChromeDriver 78.0.3904.105 (60e2d8774a8151efa6a00b1f358371b1e0e07ee2-refs/branch-heads/3904@{#877}) on port 16101
jibri_1     | Only local connections are allowed.
jibri_1     | Please protect ports used by ChromeDriver and related test frameworks to prevent access by malicious code.
jibri_1     | 2021-01-07 14:34:05.900 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http://jitsi.org/protocol/jibri
jicofo_1    | Jicofo 2021-01-07 14:34:05.901 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 status <jibri-status xmlns='http://jitsi.org/protocol/jibri'><busy-status xmlns='http://jitsi.org/protocol/jibri' status='idle'/><health-status xmlns='http://jitsi.org/protocol/health' status='healthy'/></jibri-status>
jicofo_1    | Jicofo 2021-01-07 14:34:05.901 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 available: true
jibri_1     | 2021-01-07 14:34:05.981 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http://jitsi.org/protocol/health
jibri_1     | 2021-01-07 14:34:06.664 INFO: [40] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
jibri_1     | 2021-01-07 14:34:06.698 FINE: [40] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.<init>() Detected os as OS: LINUX
jibri_1     | 2021-01-07 14:34:06.707 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
jibri_1     |   LambdaSupplier: 'JibriConfig::recordingDirectory'
jibri_1     |   ConfigSourceSupplier: key: 'jibri.recording.recordings-directory', type: 'kotlin.String', source: 'config'
jibri_1     | 2021-01-07 14:34:06.707 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::recordingDirectory
jibri_1     | 2021-01-07 14:34:06.708 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: 'JibriConfig::recordingDirectory': found value
jibri_1     | 2021-01-07 14:34:06.708 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: value found via LambdaSupplier: 'JibriConfig::recordingDirectory'
jibri_1     | 2021-01-07 14:34:06.708 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
jibri_1     |   LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath'
jibri_1     |   ConfigSourceSupplier: key: 'jibri.recording.finalize-script', type: 'kotlin.String', source: 'config'
jibri_1     | 2021-01-07 14:34:06.709 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::finalizeRecordingScriptPath
jibri_1     | 2021-01-07 14:34:06.709 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath': found value
jibri_1     | 2021-01-07 14:34:06.713 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: value found via LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath'
jibri_1     | 2021-01-07 14:34:06.713 INFO: [40] org.jitsi.jibri.service.impl.FileRecordingJibriService.<init>() Writing recording to /config/recordings/gktbrpyniyjmipft, finalize script path /etc/jitsi/jibri/finisher
jibri_1     | 2021-01-07 14:34:06.718 FINE: [40] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
jibri_1     | 2021-01-07 14:34:06.719 INFO: [40] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
jibri_1     | 2021-01-07 14:34:06.720 FINE: [40] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
jibri_1     | 2021-01-07 14:34:06.720 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
jibri_1     | 2021-01-07 14:34:06.721 FINE: [40] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@7ff8bae5
jibri_1     | 2021-01-07 14:34:06.721 FINE: [40] org.jitsi.xmpp.mucclient.MucClientManager.log() Replacing presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@48e64352
jibri_1     | 2021-01-07 14:34:06.723 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending 'pending' response to start IQ
jicofo_1    | Jicofo 2021-01-07 14:34:06.725 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 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_1    | Jicofo 2021-01-07 14:34:06.726 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 available: false
jicofo_1    | Jicofo 2021-01-07 14:34:06.727 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.classroom.mst/focus112736587765608' from='jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979' id='KME0n-231' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='pending'/></iq> for a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jicofo_1    | Jicofo 2021-01-07 14:34:06.727 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 has status pending and failure reason null, current Jibri jid is jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979
jicofo_1    | Jicofo 2021-01-07 14:34:06.728 INFO: [55] org.jitsi.jicofo.recording.jibri.JibriSession.log() Successfully resumed session with another Jibri
jibri_1     | 2021-01-07 14:34:06.731 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http://jitsi.org/protocol/jibri
jibri_1     | 2021-01-07 14:34:06.731 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http://jitsi.org/protocol/health
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:06 +0000] "GET / HTTP/2.0" 200 15956 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:06 +0000] "GET /css/all.css?v=4466 HTTP/2.0" 200 24132 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:06 +0000] "GET /libs/do_external_connect.min.js?v=1 HTTP/2.0" 200 1125 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:06 +0000] "GET /libs/lib-jitsi-meet.min.js?v=4466 HTTP/2.0" 200 191144 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:06 +0000] "GET /libs/app.bundle.min.js?v=4466 HTTP/2.0" 200 1157472 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:06 +0000] "GET /static/pwa/registrator.js HTTP/2.0" 200 182 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jibri_1     | 2021-01-07 14:34:08.736 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142#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
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:08 +0000] "GET /a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/2.0" 200 15956 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:08 +0000] "GET /libs/lib-jitsi-meet.min.js?v=4466 HTTP/2.0" 200 191144 "https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:08 +0000] "GET /libs/app.bundle.min.js?v=4466 HTTP/2.0" 200 1157472 "https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:08 +0000] "GET /static/pwa/registrator.js HTTP/2.0" 200 182 "https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:09 +0000] "GET /libs/olm.wasm HTTP/2.0" 200 182910 "https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jicofo_1    | Jicofo 2021-01-07 14:34:09.553 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.019S. Sticky failure: false
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:09 +0000] "GET /pwa-worker.js HTTP/2.0" 200 15956 "https://classroom.mst/pwa-worker.js" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jibri_1     | 2021-01-07 14:34:09.726 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
web_1       | 172.18.0.1 - - [07/Jan/2021:14:34:09 +0000] "GET /xmpp-websocket?room=a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/1.1" 403 281 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jibri_1     | 2021-01-07 14:34:10.235 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jvb_1       | Jan 07, 2021 2:34:13 PM org.jitsi.utils.logging2.LoggerImpl log
jvb_1       | INFO: Performed a successful health check in PT0S. Sticky failure: false
jibri_1     | 2021-01-07 14:34:13.317 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:16.360 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:16.867 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:17.375 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:17.882 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:18.390 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet:
jicofo_1    | Jicofo 2021-01-07 14:34:19.552 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.018S. Sticky failure: false
jibri_1     | 2021-01-07 14:34:19.918 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: 
jicofo_1    | Jicofo 2021-01-07 14:34:22.445 INFO: [15] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Expiring session:AuthSession[ID=d9fec0a3-e826-4d03-ac8f-479d49bd944e@classroom.mst, JID=d9fec0a3-e826-4d03-ac8f-479d49bd944e@classroom.mst/HiuSihQh, SID=c5ea84f6-0a8d-44ad-b45e-520da0bed688, MUID=3b7f39a426761b711dec13d6949da259, LIFE_TM_SEC=63, R=a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst]@522735761
jibri_1     | 2021-01-07 14:34:22.455 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:22.961 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: 
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:34 +0000] "GET /libs/olm.wasm HTTP/2.0" 200 182910 "https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:34:34 +0000] "GET /pwa-worker.js HTTP/2.0" 200 15956 "https://classroom.mst/pwa-worker.js" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.1 - - [07/Jan/2021:14:34:35 +0000] "GET /xmpp-websocket?room=a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/1.1" 403 281 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jibri_1     | 2021-01-07 14:34:35.461 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:35.967 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:36.475 FINE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
jibri_1     | 2021-01-07 14:34:40.038 SEVERE: [54] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Timed out waiting for call page to load
jibri_1     | 2021-01-07 14:34:40.041 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Error: FailedToJoinCall SESSION Failed to join the call
jibri_1     | 2021-01-07 14:34:40.042 INFO: [54] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Error: FailedToJoinCall SESSION Failed to join the call
jibri_1     | 2021-01-07 14:34:40.043 INFO: [54] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service had an error Error: FailedToJoinCall SESSION Failed to join the call, sending error iq <iq to='jibribrewery@internal-muc.classroom.mst/focus' id='1AJaY-32' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error' should_retry='true'/></iq>
jibri_1     | 2021-01-07 14:34:40.044 FINE: [54] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
jibri_1     | 2021-01-07 14:34:40.045 INFO: [54] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
jibri_1     | 2021-01-07 14:34:40.045 INFO: [54] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
jicofo_1    | Jicofo 2021-01-07 14:34:40.046 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.classroom.mst/focus112736587765608' from='jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979' id='Zm9jdXNAYXV0aC5jbGFzc3Jvb20ubXN0L2ZvY3VzMTEyNzM2NTg3NzY1NjA4ADFBSmFZLTMyAGm5To10q60WiSkgfXRVhEM=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error' should_retry='true'/></iq> for a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jicofo_1    | Jicofo 2021-01-07 14:34:40.047 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 has status off and failure reason error, current Jibri jid is jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979
jicofo_1    | Jicofo 2021-01-07 14:34:40.047 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
jicofo_1    | Jicofo 2021-01-07 14:34:40.047 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri failed, trying to fall back to another Jibri
jicofo_1    | Jicofo 2021-01-07 14:34:40.047 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780
jicofo_1    | Jicofo 2021-01-07 14:34:40.048 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 for stream ID: null in room: a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jibri_1     | 2021-01-07 14:34:40.049 INFO: [54] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
jibri_1     | 2021-01-07 14:34:40.049 INFO: [54] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value null
jibri_1     | 2021-01-07 14:34:40.050 INFO: [54] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
jibri_1     | 2021-01-07 14:34:40.057 INFO: [54] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording: []
jibri_1     | 2021-01-07 14:34:40.097 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving call and quitting browser
jibri_1     | 2021-01-07 14:34:40.098 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Recurring call status checks cancelled
jibri_1     | 2021-01-07 14:34:40.116 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 33 log entries for type browser
jibri_1     | 2021-01-07 14:34:40.233 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 1229 log entries for type driver
jibri_1     | 2021-01-07 14:34:40.523 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
jibri_1     | 2021-01-07 14:34:40.523 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
jibri_1     | 2021-01-07 14:34:40.564 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
jibri_1     | 2021-01-07 14:34:40.643 INFO: [54] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Chrome driver quit
jibri_1     | 2021-01-07 14:34:40.643 INFO: [54] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Finalizing the recording
jicofo_1    | Jicofo 2021-01-07 14:34:41.149 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 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>
jibri_1     | 2021-01-07 14:34:41.150 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http://jitsi.org/protocol/jibri
jibri_1     | 2021-01-07 14:34:41.150 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http://jitsi.org/protocol/health
jicofo_1    | Jicofo 2021-01-07 14:34:41.149 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 available: false
jicofo_1    | Jicofo 2021-01-07 14:34:41.164 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.classroom.mst/focus112736587765608' from='jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780' id='KME0n-324' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='pending'/></iq> for a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jicofo_1    | Jicofo 2021-01-07 14:34:41.165 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 has status pending and failure reason null, current Jibri jid is jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780
jicofo_1    | Jicofo 2021-01-07 14:34:41.166 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Successfully resumed session with another Jibri
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:41 +0000] "GET / HTTP/2.0" 200 15956 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:41 +0000] "GET /css/all.css?v=4466 HTTP/2.0" 200 24132 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:41 +0000] "GET /libs/do_external_connect.min.js?v=1 HTTP/2.0" 200 1125 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:41 +0000] "GET /libs/lib-jitsi-meet.min.js?v=4466 HTTP/2.0" 200 191144 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:41 +0000] "GET /libs/app.bundle.min.js?v=4466 HTTP/2.0" 200 1157472 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:41 +0000] "GET /static/pwa/registrator.js HTTP/2.0" 200 182 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jibri_1     | 2021-01-07 14:34:42.318 INFO: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.call() panic: runtime error: slice bounds out of range [:2] with capacity 1
jibri_1     | 2021-01-07 14:34:42.318 INFO: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.call()
jibri_1     | 2021-01-07 14:34:42.318 INFO: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.call() goroutine 1 [running]:
jibri_1     | 2021-01-07 14:34:42.318 INFO: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.call() main.main()
jibri_1     | 2021-01-07 14:34:42.319 INFO: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.call() 	/home/debendra/projects/innovatetech/record/send/main.go:73 +0x8b0
jibri_1     | 2021-01-07 14:34:42.319 INFO: [54] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Recording finalize script finished with exit value 2
jibri_1     | 2021-01-07 14:34:42.320 FINE: [54] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
jibri_1     |   LambdaSupplier: 'JibriConfig::singleUseMode'
jibri_1     |   ConfigSourceSupplier: key: 'jibri.single-use-mode', type: 'kotlin.Boolean', source: 'config'
jibri_1     | 2021-01-07 14:34:42.320 FINE: [54] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::singleUseMode
jibri_1     | 2021-01-07 14:34:42.321 FINE: [54] org.jitsi.jibri.config.debug() FallbackSupplier: failed to find value via LambdaSupplier: 'JibriConfig::singleUseMode': org.jitsi.metaconfig.ConfigException$UnableToRetrieve$Error: class kotlin.KotlinNullPointerException
jibri_1     | 2021-01-07 14:34:42.321 FINE: [54] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Trying to retrieve key 'jibri.single-use-mode' from source 'config' as type kotlin.Boolean
jibri_1     | 2021-01-07 14:34:42.322 FINE: [54] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.single-use-mode' from source 'config' as type kotlin.Boolean
jibri_1     | 2021-01-07 14:34:42.323 FINE: [54] org.jitsi.jibri.config.debug() FallbackSupplier: value found via ConfigSourceSupplier: key: 'jibri.single-use-mode', type: 'kotlin.Boolean', source: 'config'
jibri_1     | 2021-01-07 14:34:42.323 INFO: [54] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: BUSY -> IDLE
jibri_1     | 2021-01-07 14:34:42.323 FINE: [54] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
jibri_1     | 2021-01-07 14:34:42.324 INFO: [54] org.jitsi.jibri.api.xmpp.XmppApi.updatePresence() Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
jibri_1     | 2021-01-07 14:34:42.324 FINE: [54] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@46d8e386
jibri_1     | 2021-01-07 14:34:42.325 FINE: [54] org.jitsi.xmpp.mucclient.MucClientManager.log() Replacing presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@7ff8bae5
jicofo_1    | Jicofo 2021-01-07 14:34:42.328 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 status <jibri-status xmlns='http://jitsi.org/protocol/jibri'><busy-status xmlns='http://jitsi.org/protocol/jibri' status='idle'/><health-status xmlns='http://jitsi.org/protocol/health' status='healthy'/></jibri-status>
jicofo_1    | Jicofo 2021-01-07 14:34:42.328 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 available: true
jibri_1     | 2021-01-07 14:34:42.332 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http://jitsi.org/protocol/jibri
jibri_1     | 2021-01-07 14:34:42.333 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http://jitsi.org/protocol/health
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:42 +0000] "GET /libs/olm.wasm HTTP/2.0" 200 182910 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:42 +0000] "GET /PsychologicalGearsSwearOccasionally HTTP/2.0" 200 15956 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:42 +0000] "GET /libs/do_external_connect.min.js?v=1 HTTP/2.0" 200 1125 "https://classroom.mst/PsychologicalGearsSwearOccasionally" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:42 +0000] "GET /libs/lib-jitsi-meet.min.js?v=4466 HTTP/2.0" 200 191144 "https://classroom.mst/PsychologicalGearsSwearOccasionally" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:42 +0000] "GET /libs/app.bundle.min.js?v=4466 HTTP/2.0" 200 1157472 "https://classroom.mst/PsychologicalGearsSwearOccasionally" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:42 +0000] "GET /static/pwa/registrator.js HTTP/2.0" 200 182 "https://classroom.mst/PsychologicalGearsSwearOccasionally" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jvb_1       | Jan 07, 2021 2:34:43 PM org.jitsi.utils.logging2.LoggerImpl log
jvb_1       | INFO: Performed a successful health check in PT0S. Sticky failure: false
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:43 +0000] "GET /libs/olm.wasm HTTP/2.0" 200 182910 "https://classroom.mst/PsychologicalGearsSwearOccasionally" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:43 +0000] "GET /images/avatar.png HTTP/2.0" 200 5995 "https://classroom.mst/PsychologicalGearsSwearOccasionally" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:34:45 +0000] "GET /xmpp-websocket?room=a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/1.1" 403 281 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jicofo_1    | Jicofo 2021-01-07 14:34:49.544 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.01S. Sticky failure: false
jvb_1       | Jan 07, 2021 2:34:53 PM org.jitsi.utils.logging2.LoggerImpl log
jvb_1       | INFO: Performed a successful health check in PT0S. Sticky failure: false
jvb_1       | Jan 07, 2021 2:34:53 PM org.jitsi.utils.logging2.LoggerImpl log
jvb_1       | INFO: Running expire()
jibri_1     | 2021-01-07 14:34:54.969 FINE: [16] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
jicofo_1    | Jicofo 2021-01-07 14:35:09.544 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.01S. Sticky failure: false
web_1       | 192.168.206.186 - - [07/Jan/2021:14:35:10 +0000] "GET /a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/2.0" 200 15956 "https://classroom.mst/a5abecc6-504f-11eb-8d0e-06602663d142" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 192.168.206.186 - - [07/Jan/2021:14:35:11 +0000] "GET /xmpp-websocket?room=a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/1.1" 403 281 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jvb_1       | Jan 07, 2021 2:35:13 PM org.jitsi.utils.logging2.LoggerImpl log
jvb_1       | INFO: Performed a successful health check in PT0S. Sticky failure: false
jicofo_1    | Jicofo 2021-01-07 14:35:15.157 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.classroom.mst/focus112736587765608' from='jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780' id='Zm9jdXNAYXV0aC5jbGFzc3Jvb20ubXN0L2ZvY3VzMTEyNzM2NTg3NzY1NjA4AFYxSzRRLTQyNzkAXLKSsNKPWXKwsigR2rL75Q==' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error' should_retry='true'/></iq> for a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jicofo_1    | Jicofo 2021-01-07 14:35:15.157 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 has status off and failure reason error, current Jibri jid is jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780
jicofo_1    | Jicofo 2021-01-07 14:35:15.157 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
jicofo_1    | Jicofo 2021-01-07 14:35:15.157 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri failed, trying to fall back to another Jibri
jicofo_1    | Jicofo 2021-01-07 14:35:15.157 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979
jicofo_1    | Jicofo 2021-01-07 14:35:15.158 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 for stream ID: null in room: a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jibri_1     | 2021-01-07 14:35:15.161 FINE: [40] org.jitsi.xmpp.mucclient.MucClient.log() Received an IQ with type set: IQ Stanza (jibri http://jitsi.org/protocol/jibri) [to=jibri@auth.classroom.mst/EADx4PgL,from=jibribrewery@internal-muc.classroom.mst/focus,id=amlicmlAYXV0aC5jbGFzc3Jvb20ubXN0L0VBRHg0UGdMAEtNRTBuLTQwMAB7XHcbWZqPj55Vj8pKPSSP,type=set,]
jibri_1     | 2021-01-07 14:35:15.162 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.classroom.mst/EADx4PgL' from='jibribrewery@internal-muc.classroom.mst/focus' id='amlicmlAYXV0aC5jbGFzc3Jvb20ubXN0L0VBRHg0UGdMAEtNRTBuLTQwMAB7XHcbWZqPj55Vj8pKPSSP' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst' session_id='gktbrpyniyjmipft' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=xmpp.classroom.mst hostname=xmpp.classroom.mst]
jibri_1     | 2021-01-07 14:35:15.165 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request, starting service
jibri_1     | 2021-01-07 14:35:15.172 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://classroom.mst, callName=a5abecc6-504f-11eb-8d0e-06602663d142, urlParams=[])
jibri_1     | 2021-01-07 14:35:15.173 INFO: [40] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://classroom.mst, callName=a5abecc6-504f-11eb-8d0e-06602663d142, urlParams=[])), sessionId=gktbrpyniyjmipft, callLoginParams=XmppCredentials(domain=recorder.classroom.mst, username=recorder, password=aaa0cbf4b417eac9fedc2ee637f9beac))
jibri_1     | 2021-01-07 14:35:15.176 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>
jibri_1     | 2021-01-07 14:35:15.177 FINE: [40] org.jitsi.jibri.config.debug() ConfigSourceSupplier: Successfully retrieved key 'jibri.chrome.flags' from source 'config' as type kotlin.collections.List<kotlin.String>
jibri_1     | Starting ChromeDriver 78.0.3904.105 (60e2d8774a8151efa6a00b1f358371b1e0e07ee2-refs/branch-heads/3904@{#877}) on port 28984
jibri_1     | Only local connections are allowed.
jibri_1     | Please protect ports used by ChromeDriver and related test frameworks to prevent access by malicious code.
jicofo_1    | Jicofo 2021-01-07 14:35:15.465 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 status <jibri-status xmlns='http://jitsi.org/protocol/jibri'><busy-status xmlns='http://jitsi.org/protocol/jibri' status='idle'/><health-status xmlns='http://jitsi.org/protocol/health' status='healthy'/></jibri-status>
jicofo_1    | Jicofo 2021-01-07 14:35:15.465 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal-muc.classroom.mst/jibri-instanse-096397780 available: true
jibri_1     | 2021-01-07 14:35:15.466 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http://jitsi.org/protocol/jibri
jibri_1     | 2021-01-07 14:35:15.467 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http://jitsi.org/protocol/health
jibri_1     | 2021-01-07 14:35:15.834 INFO: [40] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
jibri_1     | 2021-01-07 14:35:15.844 FINE: [40] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.<init>() Detected os as OS: LINUX
jibri_1     | 2021-01-07 14:35:15.845 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
jibri_1     |   LambdaSupplier: 'JibriConfig::recordingDirectory'
jibri_1     |   ConfigSourceSupplier: key: 'jibri.recording.recordings-directory', type: 'kotlin.String', source: 'config'
jibri_1     | 2021-01-07 14:35:15.846 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::recordingDirectory
jibri_1     | 2021-01-07 14:35:15.847 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: 'JibriConfig::recordingDirectory': found value
jibri_1     | 2021-01-07 14:35:15.847 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: value found via LambdaSupplier: 'JibriConfig::recordingDirectory'
jibri_1     | 2021-01-07 14:35:15.849 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: checking for value via suppliers:
jibri_1     |   LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath'
jibri_1     |   ConfigSourceSupplier: key: 'jibri.recording.finalize-script', type: 'kotlin.String', source: 'config'
jibri_1     | 2021-01-07 14:35:15.849 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: Trying to retrieve value via JibriConfig::finalizeRecordingScriptPath
jibri_1     | 2021-01-07 14:35:15.851 FINE: [40] org.jitsi.jibri.config.debug() LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath': found value
jibri_1     | 2021-01-07 14:35:15.853 FINE: [40] org.jitsi.jibri.config.debug() FallbackSupplier: value found via LambdaSupplier: 'JibriConfig::finalizeRecordingScriptPath'
jibri_1     | 2021-01-07 14:35:15.853 INFO: [40] org.jitsi.jibri.service.impl.FileRecordingJibriService.<init>() Writing recording to /config/recordings/gktbrpyniyjmipft, finalize script path /etc/jitsi/jibri/finisher
jibri_1     | 2021-01-07 14:35:15.854 FINE: [40] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
jibri_1     | 2021-01-07 14:35:15.855 INFO: [40] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
jibri_1     | 2021-01-07 14:35:15.856 FINE: [40] org.jitsi.jibri.webhooks.v1.WebhookClient.invokeSuspend() Updating 0 subscribers of status
jibri_1     | 2021-01-07 14:35:15.858 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
jibri_1     | 2021-01-07 14:35:15.858 FINE: [40] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@485a98a0
jibri_1     | 2021-01-07 14:35:15.860 FINE: [40] org.jitsi.xmpp.mucclient.MucClientManager.log() Replacing presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@46d8e386
jicofo_1    | Jicofo 2021-01-07 14:35:15.863 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 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_1    | Jicofo 2021-01-07 14:35:15.863 INFO: [29] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 available: false
jibri_1     | 2021-01-07 14:35:15.864 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http://jitsi.org/protocol/jibri
jibri_1     | 2021-01-07 14:35:15.865 FINE: [37] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http://jitsi.org/protocol/health
jibri_1     | 2021-01-07 14:35:15.870 INFO: [40] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending 'pending' response to start IQ
jicofo_1    | Jicofo 2021-01-07 14:35:15.872 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.classroom.mst/focus112736587765608' from='jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979' id='KME0n-400' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='pending'/></iq> for a5abecc6-504f-11eb-8d0e-06602663d142@muc.classroom.mst
jicofo_1    | Jicofo 2021-01-07 14:35:15.873 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979 has status pending and failure reason null, current Jibri jid is jibribrewery@internal-muc.classroom.mst/jibri-instanse-793110979
jicofo_1    | Jicofo 2021-01-07 14:35:15.873 INFO: [82] org.jitsi.jicofo.recording.jibri.JibriSession.log() Successfully resumed session with another Jibri
web_1       | 172.18.0.6 - - [07/Jan/2021:14:35:15 +0000] "GET / HTTP/2.0" 200 15956 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:35:15 +0000] "GET /css/all.css?v=4466 HTTP/2.0" 200 24132 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:35:15 +0000] "GET /libs/do_external_connect.min.js?v=1 HTTP/2.0" 200 1125 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.6 - - [07/Jan/2021:14:35:15 +0000] "GET /libs/lib-jitsi-meet.min.js?v=4466 HTTP/2.0" 200 191144 "https://classroom.mst/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
jibri_1     | 2021-01-07 14:35:18.732 FINE: [57] org.jitsi.jibri.selenium.pageobjects.CallPage.apply() Not joined yet: Cannot read property 'isJoined' of undefined
web_1       | 172.18.0.6 - - [07/Jan/2021:14:35:18 +0000] "GET /pwa-worker.js HTTP/2.0" 200 15956 "https://classroom.mst/pwa-worker.js" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
web_1       | 172.18.0.1 - - [07/Jan/2021:14:35:18 +0000] "GET /xmpp-websocket?room=a5abecc6-504f-11eb-8d0e-06602663d142 HTTP/1.1" 403 281 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"
...