jibri icon indicating copy to clipboard operation
jibri copied to clipboard

I am getting Recording failed to start after preparing the recording

Open dhanasekaranw2s opened this issue 3 years ago • 4 comments

Hi,

I am attached below my logs, please help me to get resolve this.

Jicofo log

Jicofo 2022-02-17 10:13:56.471 INFO: [33] JibriSession.processJibriIqFromJibri#435: Updating status from JIBRI: for [email protected] Jicofo 2022-02-17 10:13:56.471 INFO: [33] JibriSession.handleJibriStatusUpdate#623: Got Jibri status update: Jibri [email protected]/jibri has status pending and failure reason null, current Jibri jid is [email protected]/jibri Jicofo 2022-02-17 10:13:56.471 INFO: [33] [[email protected] meeting_id=bc816cba-badc-43cf-92c8-17c81093e74d] JibriRecorder.handleStartRequest#113: Started Jibri session Jicofo 2022-02-17 10:14:28.442 INFO: [33] JibriSession.processJibriIqFromJibri#435: Updating status from JIBRI: for [email protected] Jicofo 2022-02-17 10:14:28.442 INFO: [33] JibriSession.handleJibriStatusUpdate#623: Got Jibri status update: Jibri [email protected]/jibri has status off and failure reason error, current Jibri jid is [email protected]/jibri Jicofo 2022-02-17 10:14:28.442 INFO: [33] JibriSession.clearPendingTimeout#575: Jibri is no longer pending, cancelling pending timeout task Jicofo 2022-02-17 10:14:28.442 INFO: [33] JibriSession.handleJibriStatusUpdate#662: Jibri failed, trying to fall back to another Jibri Jicofo 2022-02-17 10:14:28.442 SEVERE: [33] JibriSession.startInternal#308: Unable to find an available Jibri, can't start Jicofo 2022-02-17 10:14:28.443 WARNING: [33] JibriSession.handleJibriStatusUpdate#673: Failed to fall back to another Jibri, this session has now failed: org.jitsi.jicofo.jibri.JibriSession$StartException$AllBusy: All jibri instances are busy org.jitsi.jicofo.jibri.JibriSession$StartException$AllBusy: All jibri instances are busy at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:312) at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:286) at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:599) at org.jitsi.jicofo.jibri.JibriSession.handleJibriStatusUpdate(JibriSession.java:666) at org.jitsi.jicofo.jibri.JibriSession.processJibriIqFromJibri(JibriSession.java:437) at org.jitsi.jicofo.jibri.JibriSession.processJibriIqRequestFromJibri(JibriSession.java:421) at org.jitsi.jicofo.jibri.BaseJibri.doHandleIQRequest(BaseJibri.kt:158) at org.jitsi.jicofo.jibri.BaseJibri.incomingIqQueue$lambda-0(BaseJibri.kt:56) at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:416) at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:136) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Jicofo 2022-02-17 10:14:28.444 INFO: [33] [[email protected] meeting_id=bc816cba-badc-43cf-92c8-17c81093e74d] JibriRecorder.publishJibriRecordingStatus#158: Got jibri status off and failure error Jicofo 2022-02-17 10:14:28.444 INFO: [33] [[email protected] meeting_id=bc816cba-badc-43cf-92c8-17c81093e74d] JibriRecorder.publishJibriRecordingStatus#183: Publishing new jibri-recording-status: in: [email protected] Jicofo 2022-02-17 10:14:28.445 INFO: [33] JibriSession.cleanupSession#390: Cleaning up current JibriSession Jicofo 2022-02-17 10:14:31.657 INFO: [22] [[email protected] meeting_id=bc816cba-badc-43cf-92c8-17c81093e74d] JitsiMeetConferenceImpl.onMemberLeft#795: Member left:4507ef8f Jicofo 2022-02-17 10:14:31.657 WARNING: [22] [[email protected] meeting_id=bc816cba-badc-43cf-92c8-17c81093e74d] JitsiMeetConferenceImpl.onMemberLeft#810: Participant not found for 4507ef8f. Terminated already or never started? Jicofo 2022-02-17 10:14:31.658 INFO: [22] [[email protected] meeting_id=bc816cba-badc-43cf-92c8-17c81093e74d] JitsiMeetConferenceImpl.stop#436: Stopped

Jibri log

2022-02-17 10:14:24.376 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:24.883 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:25.390 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:25.896 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:26.403 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:26.910 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:27.417 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:27.924 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:28.430 FINE: [54] CallPage$visit$$inlined$measureTimedValue$lambda$1.apply#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined') 2022-02-17 10:14:28.435 SEVERE: [54] CallPage.visit#65: Timed out waiting for call page to load 2022-02-17 10:14:28.437 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.onSeleniumStateChange#215: Transitioning from state Starting up to Error: FailedToJoinCall SESSION Failed to join the call 2022-02-17 10:14:28.438 INFO: [54] [session_id=mledrcfqjzvsqchc] StatefulJibriService.onServiceStateChange#39: File recording service transitioning from state Starting up to Error: FailedToJoinCall SESSION Failed to join the call 2022-02-17 10:14:28.439 INFO: [54] XmppApi$createServiceStatusHandler$1.invoke#243: Current service had an error Error: FailedToJoinCall SESSION Failed to join the call, sending error iq 2022-02-17 10:14:28.439 FINE: [54] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: stop:recording 2022-02-17 10:14:28.440 INFO: [54] JibriManager.stopService#260: Stopping the current service 2022-02-17 10:14:28.440 INFO: [54] [session_id=mledrcfqjzvsqchc] FileRecordingJibriService.stop#181: Stopping capturer 2022-02-17 10:14:28.440 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSubprocess.stop#75: Stopping ffmpeg process 2022-02-17 10:14:28.440 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSubprocess.stop#89: ffmpeg exited with value null 2022-02-17 10:14:28.440 INFO: [54] [session_id=mledrcfqjzvsqchc] FileRecordingJibriService.stop#183: Quitting selenium 2022-02-17 10:14:28.441 INFO: [54] [session_id=mledrcfqjzvsqchc] FileRecordingJibriService.stop#190: No media was recorded, deleting directory and skipping metadata file & finalize 2022-02-17 10:14:28.441 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#336: Leaving call and quitting browser 2022-02-17 10:14:28.441 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#339: Recurring call status checks cancelled 2022-02-17 10:14:28.456 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#345: Got 21 log entries for type browser 2022-02-17 10:14:28.503 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#345: Got 1047 log entries for type driver 2022-02-17 10:14:28.630 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#345: Got 0 log entries for type client 2022-02-17 10:14:28.630 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#354: Leaving web call 2022-02-17 10:14:28.660 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#361: Quitting chrome driver 2022-02-17 10:14:28.730 INFO: [54] [session_id=mledrcfqjzvsqchc] JibriSelenium.leaveCallAndQuitBrowser#363: Chrome driver quit 2022-02-17 10:14:28.731 INFO: [54] JibriStatusManager$$special$$inlined$observable$1.afterChange#72: Busy status has changed: BUSY -> IDLE 2022-02-17 10:14:28.731 FINE: [54] WebhookClient$updateStatus$1.invokeSuspend#107: Updating 0 subscribers of status 2022-02-17 10:14:28.732 INFO: [54] XmppApi.updatePresence#144: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections 2022-02-17 10:14:34.345 FINE: [17] WebhookClient$updateStatus$1.invokeSuspend#107: Updating 0 subscribers of status

dhanasekaranw2s avatar Feb 17 '22 10:02 dhanasekaranw2s

@bbaldino @damencho

dhanasekaranw2s avatar Feb 17 '22 10:02 dhanasekaranw2s

You'd have more luck in community.jitsi.org for something like this. 2022-02-17 10:14:28.435 SEVERE: [54] CallPage.visit#65: Timed out waiting for call page to load is in the logs, I'd search the community for that; there are a couple different things that can cause it. If it never works, you probably have an auth config problem. If it sometimes works, it could be that this is happening on first jibri boot, which can be a problem (chrome starts up slow the first time).

bbaldino avatar Feb 17 '22 17:02 bbaldino

Thanks for your response @bbaldino

I installed Jitsi and Jibri on same instance. Server Details Instance Size : t2.xlarge RAM : 16 GB OS: Ubuntu 18.04 vCPU : 4

I tried in community as well. please find my configurations below, If I do anything wrong please correct me.

Jibri config jibri { // A unique identifier for this Jibri // TODO: eventually this will be required with no default id = "" // Whether or not Jibri should return to idle state after handling // (successfully or unsuccessfully) a request. A value of 'true' // here means that a Jibri will NOT return back to the IDLE state // and will need to be restarted in order to be used again. single-use-mode = false api { http { external-api-port = 2222 internal-api-port = 3333 } xmpp { // See example_xmpp_envs.conf for an example of what is expected here environments = [ { name = "prod environment" xmpp-server-hosts = ["jitsi.mydomain.com"] xmpp-domain = "jitsi.mydomain.com"

            control-muc {
                domain = "internal.auth.jitsi.mydomain.com"
                room-name = "JibriBrewery"
                nickname = "jibri"
            }

            control-login {
                domain = "auth.jitsi.mydomain.com"
                username = "jibri"
                password = "jibri1234"
            }

            call-login {
                domain = "recorder.jitsi.mydomain.com"
                username = "recorder"
                password = "recorder1234"
            }

            strip-from-room-domain = "conference."
            usage-timeout = 0
            trust-all-xmpp-certs = true
        }]
}

} recording { recordings-directory = "/recordings" # TODO: make this an optional param and remove the default finalize-script = "/finalize_recording.sh" } streaming { // A list of regex patterns for allowed RTMP URLs. The RTMP URL used // when starting a stream must match at least one of the patterns in // this list. rtmp-allow-list = [ // By default, all services are allowed ".*" ] } chrome { // The flags which will be passed to chromium when launching flags = [ "--use-fake-ui-for-media-stream", "--start-maximized", "--kiosk", "--enabled", "--disable-infobars", "--autoplay-policy=no-user-gesture-required", "--headless", "--no-sandbox", "--log-file=/var/log/jitsi/jibri/chromedriver.log" "--ignore-certificate-errors", "--disable-setuid-sandbox", "--disable-web-security", "--disable-dev-shm-usage" ] } stats { enable-stats-d = true } webhook { // A list of subscribers interested in receiving webhook events subscribers = [] } jwt-info { // The path to a .pem file which will be used to sign JWT tokens used in webhook // requests. If not set, no JWT will be added to webhook requests. # signing-key-path = "/path/to/key.pem"

// The kid to use as part of the JWT
# kid = "key-id"

// The issuer of the JWT
# issuer = "issuer"

// The audience of the JWT
# audience = "audience"

// The TTL of each generated JWT.  Can't be less than 10 minutes.
# ttl = 1 hour

} call-status-checks { // If all clients have their audio and video muted and if Jibri does not // detect any data stream (audio or video) comming in, it will stop // recording after NO_MEDIA_TIMEOUT expires. no-media-timeout = 30 seconds

// If all clients have their audio and video muted, Jibri consideres this
// as an empty call and stops the recording after ALL_MUTED_TIMEOUT expires.
all-muted-timeout = 10 minutes

// When detecting if a call is empty, Jibri takes into consideration for how
// long the call has been empty already. If it has been empty for more than
// DEFAULT_CALL_EMPTY_TIMEOUT, it will consider it empty and stop the recording.
default-call-empty-timeout = 30 seconds

} }

browser log , { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:14.041Z" "[JitsiMeetJS.js]" "\u003CObject.getGlobalOnErrorHandler>: " "UnhandledError: Strophe: BOSH-Connection...", "source": "console-api", "timestamp": 1.645163834042e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:14.041Z" "[modules/xmpp/strophe.util.js]" "\u003CObject.Br.ot.Strophe.log>: " "Strophe: BOSH-Connection failed:...", "source": "console-api", "timestamp": 1.645163834042e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/app.bundle.min.js?v=5818 137:840652 "2022-02-18T05:57:14.044Z" "[connection.js]" "\u003Cr.o>: " "CONNECTION FAILED:" "connection.otherError"", "source": "console-api", "timestamp": 1.645163834044e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/app.bundle.min.js?v=5818 137:840652 "2022-02-18T05:57:14.052Z" "[features/base/connection]" "connection.otherError"", "source": "console-api", "timestamp": 1.645163834053e+12 }, { "level": "WARNING", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:14.119Z" "[modules/RTC/RTCUtils.js]" "Failed to get access to local media. NotFoundError: Requested device not ...", "source": "console-api", "timestamp": 1.645163834119e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/app.bundle.min.js?v=5818 137:840652 "2022-02-18T05:57:14.120Z" "[features/base/tracks]" "Failed to create local tracks" Array(1) DOMException: Requested device not f...", "source": "console-api", "timestamp": 1.64516383412e+12 }, { "level": "WARNING", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.078Z" "[modules/xmpp/strophe.util.js]" "\u003CObject.Br.ot.Strophe.log>: " "Strophe: Disconnect was called b...", "source": "console-api", "timestamp": 1.645163847319e+12 }, { "level": "WARNING", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.079Z" "[modules/xmpp/strophe.util.js]" "\u003CObject.Br.ot.Strophe.log>: " "Strophe: Disconnect was called b...", "source": "console-api", "timestamp": 1.645163847319e+12 }, { "level": "WARNING", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.303Z" "[JitsiMeetJS.js]" "\u003CObject.init>: " "Analytics disabled, disposing."", "source": "console-api", "timestamp": 1.645163847324e+12 }, { "level": "WARNING", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.304Z" "[modules/statistics/AnalyticsAdapter.js]" "\u003CObject.dispose>: " "Disposing of analytics adapter."", "source": "console-api", "timestamp": 1.645163847324e+12 }, { "level": "WARNING", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.307Z" "[modules/statistics/AnalyticsAdapter.js]" "\u003CObject.dispose>: " "Disposing of analytics adapter."", "source": "console-api", "timestamp": 1.645163847325e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.506Z" "[JitsiMeetJS.js]" "\u003CObject.getGlobalOnErrorHandler>: " "UnhandledError: Strophe: BOSH-Connection...", "source": "console-api", "timestamp": 1.645163847509e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/lib-jitsi-meet.min.js?v=5818 1:3281 "2022-02-18T05:57:27.506Z" "[modules/xmpp/strophe.util.js]" "\u003CObject.Br.ot.Strophe.log>: " "Strophe: BOSH-Connection failed:...", "source": "console-api", "timestamp": 1.645163847509e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/app.bundle.min.js?v=5818 137:840652 "2022-02-18T05:57:27.507Z" "[connection.js]" "\u003Cr.o>: " "CONNECTION FAILED:" "connection.otherError"", "source": "console-api", "timestamp": 1.64516384751e+12 }, { "level": "SEVERE", "message": "https://jitsi.mydomain.com/libs/app.bundle.min.js?v=5818 137:840652 "2022-02-18T05:57:27.512Z" "[features/base/connection]" "connection.otherError"", "source": "console-api", "timestamp": 1.645163847513e+12 }, "..." ]

2022-02-18 05:57:44.357 INFO: [56] JibriSelenium.leaveCallAndQuitBrowser#348: [2022-02-18T05:57:44+0000] [INFO] [ac87537906dbe65ac2e0db3cf3d66ff4] COMMAND GetLog { "type": "driver" }

2022-02-18 05:57:44.357 INFO: [56] JibriSelenium.leaveCallAndQuitBrowser#348: [2022-02-18T05:57:44+0000] [FINE] DevTools WebSocket Command: Runtime.evaluate (id=242) 09196120ADD77AD976F0BE90FAC6B25B { "awaitPromise": false, "expression": "1", "returnByValue": true }

2022-02-18 05:57:44.357 INFO: [56] JibriSelenium.leaveCallAndQuitBrowser#348: [2022-02-18T05:57:44+0000] [FINE] DevTools WebSocket Response: Runtime.evaluate (id=242) 09196120ADD77AD976F0BE90FAC6B25B { "result": { "description": "1", "type": "number", "value": 1 } }

dhanasekaranw2s avatar Feb 18 '22 06:02 dhanasekaranw2s