Jibri/Jitsi - Recording failed to start

Hi all, (I can’t add the log excerpt either as a text or as a file as I don;t have rights. Can upload when I have right.)

I have jibri running in a instance on google cloud and jitisi running on a vm on our dedicated server. I am running jitsi-meet on Ubuntu 18.04 and usingi jitsi-video-bridge2. The jibri server is running on 16.04 with the required kernel.

As far as I can tell everything has been configured as per several documents on jibri set up. Jitsi itself is working fine. We just have a problem with “start recording”/jibri functionality.

When “start recording” is selected we get back the generic “Recording failed to start” message. In the java script console we get the following console error below. The relevant part I suspect is

“<iq type=“error” to="4e75e82d-04b9-4fd5-b6a7-e4fde2985edb@guest.jumpingbean.io/6150248b-e379-4a66-8010-e78da610f49b” from="office@conference.jumpingbean.io/focus" id=“11976eb7-b3b8-4749-8264-83648b2cbc63:sendIQ” xmlns=“jabber:client”><error type=“cancel”><item-not-found xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”/>""

Looking in the jicofo.log, prosody.log and jibri.log shows no errors. I have checked and teh XmppApi.start call appears to connect correctly. There is only info messages in jicofo logs.

I did a tcpdump and I can see packets reaching nginx but don’t see any packets passed to the remote jibri server.

I am not sure where else to look. Any help appreciated.

anybody any insights ? have the same issue.

@damencho is this an XMPP account thing maybe? I don’t know what all can cause item-not-found

Yep. Maybe prosody logs may reveal more … not sure.

i have the same issue too, please help @damencho

here are all my logs. Couldn’t post before due to restrictions luckily the draft has been saved by discourse.

Javascript Console

2020-04-21T09:16:55.409Z [modules/UI/videolayout/RemoteVideo.js] : c8ce73c1 thumbnail connection status: active Logger.js:154:22
2020-04-21T09:16:55.971Z [modules/UI/videolayout/RemoteVideo.js] : c8ce73c1 thumbnail connection status: active Logger.js:154:22
@atlaskit/modal-dialog: Deprecation warning - Use of the footer prop in ModalDialog is deprecated. Please compose your ModalDialog using the ‘components’ prop instead Content.js:122:37
2020-04-21T09:17:00.643Z [JitsiMeetJS.js] : UnhandledError: null Script: null Line: null Column: null StackTrace:
iq#11976eb7-b3b8-4749-8264-83648b2cbc63:sendIQ

assignedSlot: null

attributes: NamedNodeMap(5) [ type=“error”, to="4e75e82d-04b9-4fd5-b6a7-e4fde2985edb@guest.abcxyz.io/6150248b-e379-4a66-8010-e78da610f49b", from="office@conference.abcxyz.io/focus", … ]

baseURI: “https://abcxyz.io/http-bind?room=office

childElementCount: 1

childNodes: NodeList [ error ]

children: HTMLCollection { 0: error, length: 1 }

classList: DOMTokenList

className: “”

clientHeight: 0

clientLeft: 0

clientTop: 0

clientWidth: 0

firstChild:

firstElementChild:

id: “11976eb7-b3b8-4749-8264-83648b2cbc63:sendIQ”

innerHTML: “<error xmlns=“jabber:client” type=“cancel”><item-not-found xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”/>”

isConnected: true

lastChild:

lastElementChild:

localName: “iq”

namespaceURI: “jabber:client”

nextElementSibling: null

nextSibling: null

nodeName: “iq”

nodeType: 1

nodeValue: null

onfullscreenchange: null

onfullscreenerror: null

outerHTML: “<iq type=“error” to="4e75e82d-04b9-4fd5-b6a7-e4fde2985edb@guest.abcxyz.io/6150248b-e379-4a66-8010-e78da610f49b” from="office@conference.abcxyz.io/focus" id=“11976eb7-b3b8-4749-8264-83648b2cbc63:sendIQ” xmlns=“jabber:client”><error type=“cancel”><item-not-found xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”/>"

ownerDocument: XMLDocument { … }

parentElement:

parentNode:

part: DOMTokenList

prefix: null

previousElementSibling: null

previousSibling: null

scrollHeight: 0

scrollLeft: 0

scrollLeftMax: 0

scrollTop: 0

scrollTopMax: 0

scrollWidth: 0

shadowRoot: null

slot: “”

tagName: “iq”

textContent: “”

: ElementPrototype { getAttributeNames: getAttributeNames(), getAttribute: getAttribute(), getAttributeNS: getAttributeNS(), … }
Logger.js:154:22
s Logger.js:154
getGlobalOnErrorHandler JitsiMeetJS.js:612
onunhandledrejection middleware.js:111
uncaught exception: Object

Jibri logs

2020-04-21 09:27:48.548 INFO: [1] org.jitsi.jibri.Main.main() Jibri run with args [–config, /etc/jitsi/jibri/config.json]
2020-04-21 09:27:48.554 INFO: [1] org.jitsi.jibri.Main.main() Using config file /etc/jitsi/jibri/config.json
2020-04-21 09:27:48.554 INFO: [1] org.jitsi.jibri.Main.main() Using port 3333 for internal HTTP API
2020-04-21 09:27:48.554 INFO: [1] org.jitsi.jibri.Main.main() Using port 2222 for the HTTP API
2020-04-21 09:27:49.266 INFO: [1] org.jitsi.jibri.Main.loadConfig() Parsed config:
JibriConfig(recordingDirectory=/recordings, singleUseMode=false, enabledStatsD=true, finalizeRecordingScriptPath=/recordings/finalize_recording.sh, xmppEnvironments=[XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[abcxyz.io], xmppDomain=abcxyz.io, controlLogin=XmppCredentials(domain=auth.abcxyz.io, username=jibri, password=r=[x5KS+:5@9NMfr), controlMuc=XmppMuc(domain=internal.auth.abcxyz.io, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.abcxyz.io, username=recorder, password=$a%j4tUA=F@pQJe9), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)])
2020-04-21 09:27:49.973 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.internal.InternalHttpApi registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider org.jitsi.jibri.api.http.internal.InternalHttpApi will be ignored.
2020-04-21 09:27:50.304 INFO: [1] 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-21 09:27:50.307 INFO: [1] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@771158fb
2020-04-21 09:27:50.315 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() Connecting to xmpp environment on abcxyz.io with config XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[abcxyz.io], xmppDomain=abcxyz.io, controlLogin=XmppCredentials(domain=auth.abcxyz.io, username=jibri, password=r=[x5KS+:5@9NMfr), controlMuc=XmppMuc(domain=internal.auth.abcxyz.io, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.abcxyz.io, username=recorder, password=$a%j4tUA=F@pQJe9), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)
2020-04-21 09:27:50.316 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2020-04-21 09:27:50.347 WARNING: [19] org.jitsi.xmpp.mucclient.MucClient.log() Disabling certificate verification!
2020-04-21 09:27:50.423 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.HttpApi registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider org.jitsi.jibri.api.http.HttpApi will be ignored.
2020-04-21 09:27:52.196 INFO: [19] org.jitsi.xmpp.mucclient.MucClient.log() [MucClient id=abcxyz.io hostname=abcxyz.io] connected
2020-04-21 09:27:53.594 INFO: [19] org.jitsi.xmpp.mucclient.MucClient.log() Joined MUC: jibribrewery@internal.auth.abcxyz.io
(END)

jicofo log

Jicofo 2020-04-21 09:28:44.148 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.006S. Sticky failure: false
Jicofo 2020-04-21 09:28:45.363 INFO: [222] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: office@conference.abcxyz.io
Jicofo 2020-04-21 09:28:45.363 INFO: [222] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: d5c37521-7b14-44d9-a582-39428a168049@guest.abcxyz.io/c7acf2f3-c003-491e-b0be-73e5da41c9c3 with session: AuthSession[ID=mark@abcxyz.io, JID=d5c37521-7b14-44d9-a582-39428a168049@guest.abcxyz.io/c7acf2f3-c003-491e-b0be-73e5da41c9c3, SID=87a9baa8-6ea6-49b2-9b1c-6f986853d51e, MUID=672237141111cc6efa7833dcb41ba80a, LIFE_TM_SEC=846, R=office@conference.abcxyz.io]@1981055486
Jicofo 2020-04-21 09:28:45.363 INFO: [222] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid d5c37521-7b14-44d9-a582-39428a168049@guest.abcxyz.io/c7acf2f3-c003-491e-b0be-73e5da41c9c3 authenticated as: mark@abcxyz.io
Jicofo 2020-04-21 09:28:45.776 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@310064f7 member=ChatMember[office@conference.abcxyz.io/d5c37521, jid: null]@1324046181]
Jicofo 2020-04-21 09:28:45.780 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member office@conference.abcxyz.io/d5c37521 joined.
Jicofo 2020-04-21 09:28:45.781 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= office@conference.abcxyz.io/d5c37521, bridge=jvbbrewery@internal.auth.abcxyz.io/4050f981-2e33-4fbf-b4ad-a1bb8ec65fa3
Jicofo 2020-04-21 09:28:45.781 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ffa2b0 octo_enabled= false: [[null, null, null, null]]
Jicofo 2020-04-21 09:28:45.781 INFO: [99] org.jitsi.jicofo.discovery.DiscoveryUtil.discoverParticipantFeatures().148 Doing feature discovery for office@conference.abcxyz.io/d5c37521
Jicofo 2020-04-21 09:28:47.314 INFO: [99] org.jitsi.jicofo.discovery.DiscoveryUtil.discoverParticipantFeatures().169 Successfully discovered features for office@conference.abcxyz.io/d5c37521
Jicofo 2020-04-21 09:28:47.315 INFO: [99] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.abcxyz.io/4050f981-2e33-4fbf-b4ad-a1bb8ec65fa3 to allocate channels for: Participant[office@conference.abcxyz.io/d5c37521]@629287328
Jicofo 2020-04-21 09:28:47.344 INFO: [99] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: office@conference.abcxyz.io/d5c37521
Jicofo 2020-04-21 09:28:47.821 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from office@conference.abcxyz.io/d5c37521 with accepted sources:Sources{ video: [ssrc=195085583 ] audio: [ssrc=1381042 ] }@617196876
Jicofo 2020-04-21 09:28:47.823 INFO: [28] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC office@conference.abcxyz.io/c8ce73c1 SID: 5tpre7g9l90eo Sources{ video: [ssrc=195085583 ] audio: [ssrc=1381042 ] }@176863514 source_Groups{ }@2013358871
Jicofo 2020-04-21 09:28:47.824 INFO: [28] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC office@conference.abcxyz.io/4e75e82d SID: 1kf2j2pq7gs0e Sources{ video: [ssrc=195085583 ] audio: [ssrc=1381042 ] }@176863514 source_Groups{ }@2013358871
Jicofo 2020-04-21 09:28:54.152 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.01S. Sticky failure: false
Jicofo 2020-04-21 09:29:04.150 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.008S. Sticky failure: false
Jicofo 2020-04-21 09:29:14.151 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.009S. Sticky failure: false
Jicofo 2020-04-21 09:29:24.153 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.011S. Sticky failure: false
Jicofo 2020-04-21 09:29:34.150 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.008S. Sticky failure: false
Jicofo 2020-04-21 09:29:44.151 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.009S. Sticky failure: false
Jicofo 2020-04-21 09:29:54.150 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.007S. Sticky failure: false
Jicofo 2020-04-21 09:30:04.151 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.008S. Sticky failure: false
Jicofo 2020-04-21 09:30:14.152 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.01S. Sticky failure: false
Jicofo 2020-04-21 09:30:24.152 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.01S. Sticky failure: false
Jicofo 2020-04-21 09:30:34.151 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.009S. Sticky failure: false
Jicofo 2020-04-21 09:30:44.150 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.008S. Sticky failure: false
Jicofo 2020-04-21 09:30:54.150 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.007S. Sticky failure: false
Jicofo 2020-04-21 09:31:04.149 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.006S. Sticky failure: false
Jicofo 2020-04-21 09:31:14.150 INFO: [33] org.jitsi.jicofo.health.Health.log() Performed a successful health check in PT0.007S. Sticky failure: false
(END)

prosody.log

Apr 21 08:27:08 general info Hello and welcome to Prosody version 0.10.0
Apr 21 08:27:08 general info Prosody is using the select backend for connection handling
Apr 21 08:27:08 portmanager info Activated service ‘s2s’ on [::]:5269, []:5269
Apr 21 08:27:08 portmanager info Activated service ‘c2s’ on [::]:5222, [
]:5222
Apr 21 08:27:08 portmanager info Activated service ‘legacy_ssl’ on no ports
Apr 21 08:27:08 mod_posix info Prosody is about to detach from the console, disabling further console output
Apr 21 08:27:08 mod_posix info Successfully daemonized to PID 2982
Apr 21 08:27:08 portmanager info Activated service ‘http’ on [::]:5280, :5280
Apr 21 08:27:08 portmanager error Error binding encrypted port for https: No key present in SSL/TLS configuration for https port 5281
Apr 21 08:27:08 portmanager error Error binding encrypted port for https: No key present in SSL/TLS configuration for https port 5281
Apr 21 08:27:08 portmanager info Activated service ‘https’ on no ports
Apr 21 08:27:08 portmanager info Activated service ‘component’ on [127.0.0.1]:5347, [::1]:5347
Apr 21 08:27:09 jcp5622550c6100 info Incoming Jabber component connection
Apr 21 08:27:09 focus.abcxyz.io:component info External component successfully authenticated
Apr 21 08:27:12 c2s5622550cf6b0 info Client connected
Apr 21 08:27:13 c2s5622550cf6b0 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
Apr 21 08:27:13 c2s5622550cf6b0 info Authenticated as jibri@auth.abcxyz.io
Apr 21 08:27:15 c2s56225510b430 info Client connected
Apr 21 08:27:15 c2s56225510b430 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
Apr 21 08:27:15 c2s56225510b430 info Authenticated as jvb@auth.abcxyz.io
Apr 21 08:27:16 c2s56225518ea00 info Client connected
Apr 21 08:27:16 c2s56225518ea00 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
Apr 21 08:27:16 c2s56225518ea00 info Authenticated as focus@auth.abcxyz.io
Apr 21 08:30:26 mod_bosh info New BOSH session, assigned it sid ‘5f091a3f-bc69-4d2a-a4b1-fbabf990cc5c’
Apr 21 08:30:26 bosh5f091a3f-bc69-4d2a-a4b1-fbabf990cc5c info Authenticated as df62c3ec-87e0-4513-be90-56d775e36c80@guest.abcxyz.io
Apr 21 08:32:26 bosh5f091a3f-bc69-4d2a-a4b1-fbabf990cc5c info BOSH client disconnected
Apr 21 08:32:32 mod_bosh info New BOSH session, assigned it sid ‘1be7256f-fdf5-41bd-8fb0-e2bcffcdbb3f’
Apr 21 08:32:32 bosh1be7256f-fdf5-41bd-8fb0-e2bcffcdbb3f info Authenticated as e63b2741-48e0-4331-9b3c-1bd3eedd4b5a@guest.abcxyz.io
Apr 21 08:32:41 bosh1be7256f-fdf5-41bd-8fb0-e2bcffcdbb3f info BOSH client disconnected
Apr 21 08:32:43 mod_bosh info New BOSH session, assigned it sid ‘6c27314b-087e-4c04-863e-f9c9172b8b8f’
Apr 21 08:32:43 bosh6c27314b-087e-4c04-863e-f9c9172b8b8f info Authenticated as 01d279fb-dabb-4c6f-af20-fbc2248dc731@guest.abcxyz.io
Apr 21 08:43:07 bosh6c27314b-087e-4c04-863e-f9c9172b8b8f info BOSH client disconnected
Apr 21 08:43:09 mod_bosh info New BOSH session, assigned it sid ‘d0049100-f75b-46a8-adfb-b6c88a9afb7d’
Apr 21 08:43:09 boshd0049100-f75b-46a8-adfb-b6c88a9afb7d info Authenticated as 342c1102-03e9-4c05-8bab-e60a48137256@guest.abcxyz.io
Apr 21 09:00:22 c2s5622552ba810 info Client connected
Apr 21 09:00:22 c2s5622552ba810 info Client disconnected: connection closed
Apr 21 09:09:52 mod_bosh info New BOSH session, assigned it sid ‘4e079369-73de-4e23-91a4-9f208338e2bb’
Apr 21 09:09:52 bosh4e079369-73de-4e23-91a4-9f208338e2bb info Authenticated as c8ce73c1-16ef-469f-b743-eaaf6034c054@guest.abcxyz.io
Apr 21 09:14:36 mod_bosh info New BOSH session, assigned it sid ‘de454aa9-8c2d-4ddb-bad2-fc7cd2660974’
Apr 21 09:14:37 boshde454aa9-8c2d-4ddb-bad2-fc7cd2660974 info Authenticated as 4e75e82d-04b9-4fd5-b6a7-e4fde2985edb@guest.abcxyz.io
Apr 21 09:27:48 c2s5622550cf6b0 info Client disconnected: closed
Apr 21 09:27:50 c2s562254dce4e0 info Client connected
Apr 21 09:27:52 c2s562254dce4e0 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
Apr 21 09:27:52 c2s562254dce4e0 info Authenticated as jibri@auth.abcxyz.io
Apr 21 09:28:43 mod_bosh info New BOSH session, assigned it sid ‘b8697da3-6371-4623-87fa-968c7d39f0fc’
Apr 21 09:28:43 boshb8697da3-6371-4623-87fa-968c7d39f0fc info Authenticated as d5c37521-7b14-44d9-a582-39428a168049@guest.abcxyz.io
Apr 21 09:30:19 c2s5622552e5e20 info Client connected
Apr 21 09:30:19 c2s5622552e5e20 info Client disconnected: connection closed

I solved this by reinstalling jitsi. I was trying to add the functionality to a jitsi instance that had been upgraded several times from OS upgrades to jitsi upgrades so maybe there is something that was hanging around from an older version causing issues. Followed the same steps with the reinstalled jitsi and it all works.

I’m having a similar issue. Couldn’t find anything in logs. Only browser console has errors. There is a brief “Recording failed to start” - popup, which disappears in a few seconds.

I have same issue. I checked all logs, but could not find any errors in any of them. Please help, we want to enable recording.

Hi Guys!
I’m facing the same issue
Did you have any Luck ?

Tks!

Hi there,
Facing same issue, with no error in Jibri, Jicofo, JVB, and Prosody logs.
Just getting “item-not-found” error in browser console when starting recording, and recording fails to start.
Any solution?

In my case someone else fixed the setup. One problem was missing snd-aloop kernel module.