Issue with recording: Installation of docker-jitsi-meet with Jibri "Recording Failed to Start"

Recording of videoconferences fails in installation following the instructions in the docker-jitsi-meet README in a digital ocean Ubuntu 18.04.3 (LTS) x64

SYMPTOM:

When the user clicks in the browser to start the recording he sees a message stating: “Recording Failed to Start”

LOGS:

When analyzing the logs this line stands out as a SEVERE error:

2020-04-22 12:42:55.159 SEVERE: [71] org.jitsi.jibri.selenium.JibriSelenium.run() An error occurred while joining the call: org.openqa.selenium.WebDriverException: : Failed to read the ‘localStorage’ property from ‘Window’: Access is denied for this document.
(Session info: chrome=81.0.4044.113)

A similar issue is discussed in Failed to read the 'localStorage' property but the person reporting did not install with docker-jitsi-meet and I’m not sure of the relevance of the solution discussed for this case

I copy the logs at ~/.jitsi-meet-cfg/jibri/logs/log.0.txt inside the summary below. (Since as a new user I’m not allowed to post more than two links and the logs have quite a few of them I’ve substituted the {protocol}:// of all those links with {protocol}_ so I can post.)

Summary

2020-04-22 12:42:53.081 FINE: [61] org.jitsi.xmpp.mucclient.MucClient.log() Received an IQ with type set: IQ Stanza (jibri http_jitsi.org/protocol/jibri) [to=jibri@auth.meet.jitsi/PI8Ka5pt,from=jibribrew
ery@internal-muc.meet.jitsi/focus,id=amlicmlAYXV0aC5tZWV0LmppdHNpL1BJOEthNXB0AGJwRFc5LTcyMQAggRzgkjr8k+3xzJy4/Hoq,type=set,]
2020-04-22 12:42:53.083 INFO: [61] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq from environment [MucClient id=xmpp.meet.jitsi hostname=xmpp.meet.jitsi]
2020-04-22 12:42:53.085 INFO: [61] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request
2020-04-22 12:42:53.087 INFO: [61] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending ‘pending’ response to start IQ
2020-04-22 12:42:53.101 INFO: [62] org.jitsi.jibri.api.xmpp.XmppApi.run() Starting service
2020-04-22 12:42:53.221 INFO: [62] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://meet.jitsi, callName=compulsorygoodnessesalignnowadays, urlParams=
)
2020-04-22 12:42:53.227 INFO: [62] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=
https_meet.jitsi, callName=compulsorygoodnessesalignnowadays, urlParams=)), sessionId=wknsbjettzidjgoy, callLoginParams=XmppCredentials(domain=recorder.meet.jitsi, username=recorder, password=bfa88a2ab
14d93a155f88feafabab33e)) finalize script path: /config/finalize.sh and recordings directory: /config/recordings
2020-04-22 12:42:54.701 INFO: [62] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
2020-04-22 12:42:54.749 INFO: [62] org.jitsi.jibri.selenium.JibriSelenium.() Starting empty call check with a timeout of PT30S
2020-04-22 12:42:54.750 FINE: [62] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.() Detected os as OS: LINUX
2020-04-22 12:42:54.751 INFO: [62] org.jitsi.jibri.service.impl.FileRecordingJibriService.() Writing recording to /config/recordings/wknsbjettzidjgoy
2020-04-22 12:42:54.754 FINE: [62] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
2020-04-22 12:42:54.756 INFO: [62] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
2020-04-22 12:42:54.757 INFO: [62] 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
2020-04-22 12:42:54.758 INFO: [62] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@2527e599
2020-04-22 12:42:54.774 FINE: [62] org.jitsi.xmpp.mucclient.MucClientManager.log() Replacing presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@53f73358
2020-04-22 12:42:54.783 FINE: [30] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http_jitsi.org/protocol/jibri
2020-04-22 12:42:54.784 FINE: [30] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http_jitsi.org/protocol/health
2020-04-22 12:42:55.159 SEVERE: [71] org.jitsi.jibri.selenium.JibriSelenium.run() An error occurred while joining the call: org.openqa.selenium.WebDriverException: : Failed to read the ‘localStorage’ property from ‘Window’: Access is denied for this document.
(Session info: chrome=81.0.4044.113)
(Driver info: chromedriver=81.0.4044.69 (6813546031a4bc83f717a2ef7cd4ac6ec1199132-refs/branch-heads/4044@{#776}),platform=Linux 4.15.0-96-generic x86_64) (WARNING: The server did not provide any stacktrace information)
Command duration or timeout: 0 milliseconds
Build info: version: ‘unknown’, revision: ‘unknown’, time: ‘unknown’
System info: host: ‘e34d6cdebd6c’, ip: ‘172.19.0.6’, os.name: ‘Linux’, os.arch: ‘amd64’, os.version: ‘4.15.0-96-generic’, java.version: ‘1.8.0_242’
Driver info: org.openqa.selenium.chrome.ChromeDriver
Capabilities {acceptInsecureCerts: false, acceptSslCerts: false, applicationCacheEnabled: false, browserConnectionEnabled: false, browserName: chrome, chrome: {chromedriverVersion: 81.0.4044.69 (6813546031a4b…, userDataDir: /tmp/.com.google.Chrome.1TaGXV}, cssSelectorsEnabled: true, databaseEnabled: false, goog:chromeOptions: {debuggerAddress: localhost:43711}, handlesAlerts: true, hasTouchScreen: false, javascriptEnabled: true, locationContextEnabled: true, mobileEmulationEnabled: false, nativeEvents: true, networkConnectionEnabled: false, pageLoadStrategy: normal, platform: LINUX, platformName: LINUX, proxy: Proxy(), rotatable: false, setWindowRect: true, strictFileInteractability: false, takesHeapSnapshot: true, takesScreenshot: true, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unexpectedAlertBehaviour: ignore, unhandledPromptBehavior: ignore, version: 81.0.4044.113, webStorageEnabled: true, webauthn:virtualAuthenticators: true}
Session ID: 992bcddef083597fcf7cf687353e81ad with stack:
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
java.lang.reflect.Constructor.newInstance(Constructor.java:423)
org.openqa.selenium.remote.ErrorHandler.createThrowable(ErrorHandler.java:214)
org.openqa.selenium.remote.ErrorHandler.throwIfResponseFailed(ErrorHandler.java:166)
org.openqa.selenium.remote.http.JsonHttpResponseCodec.reconstructValue(JsonHttpResponseCodec.java:40)
org.openqa.selenium.remote.http.AbstractHttpResponseCodec.decode(AbstractHttpResponseCodec.java:80)
org.openqa.selenium.remote.http.AbstractHttpResponseCodec.decode(AbstractHttpResponseCodec.java:44)
org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:158)
org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:83)
org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:543)
org.openqa.selenium.remote.RemoteWebDriver.executeScript(RemoteWebDriver.java:480)
org.jitsi.jibri.selenium.JibriSelenium.setLocalStorageValues(JibriSelenium.kt:175)
org.jitsi.jibri.selenium.JibriSelenium.access$setLocalStorageValues(JibriSelenium.kt:112)
org.jitsi.jibri.selenium.JibriSelenium$joinCall$1.run(JibriSelenium.kt:255)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
java.util.concurrent.FutureTask.run(FutureTask.java:266)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

2020-04-22 12:42:55.161 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Error: SESSION Failed to join call
2020-04-22 12:42:55.162 INFO: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Error: SESSION Failed to join call
2020-04-22 12:42:55.165 INFO: [71] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service had an error, sending error iq
2020-04-22 12:42:55.175 FINE: [71] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
2020-04-22 12:42:55.182 INFO: [71] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2020-04-22 12:42:55.183 INFO: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
2020-04-22 12:42:55.188 INFO: [71] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
2020-04-22 12:42:55.189 INFO: [71] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value null
2020-04-22 12:42:55.192 INFO: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
2020-04-22 12:42:55.215 INFO: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording:
2020-04-22 12:42:55.310 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type browser
2020-04-22 12:42:55.345 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 108 log entries for type driver
2020-04-22 12:42:55.459 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
2020-04-22 12:42:55.462 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
2020-04-22 12:42:55.515 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
2020-04-22 12:42:55.685 INFO: [71] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Chrome driver quit
2020-04-22 12:42:55.686 INFO: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Finalizing the recording
2020-04-22 12:43:05.719 SEVERE: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Timed out waiting for process logger task to complete
2020-04-22 12:43:05.720 INFO: [71] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Recording finalize script finished with exit value 2
2020-04-22 12:43:05.722 INFO: [71] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: BUSY -> IDLE
2020-04-22 12:43:05.723 INFO: [71] 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
2020-04-22 12:43:05.723 INFO: [71] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@4a76cb9a
2020-04-22 12:43:05.724 FINE: [71] org.jitsi.xmpp.mucclient.MucClientManager.log() Replacing presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@2527e599
2020-04-22 12:43:05.731 FINE: [30] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element busy-status from namespace http_jitsi.org/protocol/jibri
2020-04-22 12:43:05.740 FINE: [30] org.jitsi.xmpp.extensions.DefaultPacketExtensionProvider.parse() Could not add a provider for element health-status from namespace http_jitsi.org/protocol/health

An update about this for anyone that could read this post, there seems to be an issue linked to this problem https://github.com/jitsi/docker-jitsi-meet/issues/240

I installed jitsi on non-cloud kubernetes behind a NAT, everything works well except Jibri. Jibri is well installed but fails with every recording start. What can be done to solve this problem, an idea?
Thks

An update about this, I tried again as of May 27 2020 and did not encounter this error

New update. I had used this a few times for short amounts of time. The other day I tried a longer recording and something failed.

What I remember happening (notice that it was a few days ago and I could misremember) is receiving a message in the user interface telling me that the recording had stopped (or had been stopped, can’t remember).

The recording was created. I didn’t try to record anything for 3 days but today I tried again and I’m getting again the message “All recorders are currently busy”. I’ve investigated several possible solutions like restarting services but none of them works.

When I check the network tab in Chrome developer tools, I see that after pressing on start recording a request is made that gets back this response:

< body xmlns=‘http://jabber.org/protocol/httpbind’ sid=‘blabla’ xmlns:stream=‘http://etherx.jabber.org/streams’>< iq to=‘blabla@myfqdn.com/mysecretsession’ from=‘blabla@muc.myfqdn.com/focus’ xmlns=‘jabber:client’ id=‘blabla:sendIQ’ type=‘error’>< error type=‘wait’>< text xmlns=‘urn:ietf:params:xml:ns:xmpp-stanzas’ xml:lang=‘en’>all Jibris are busy</ text></ error></ iq></ body>

When I check the logs[1] I do not see anything logged after the day when the recording stopped on its own (is it because somb jibri related service is dead?)

[1] The logs I checked were log.0.txt, ffmpeg.0.txt and brower.0.txt all in ~/.jitsi-meet-cfg/jibri/logs/