Jitsi Jibri recording black screen

sobish · September 4, 2019, 7:35am

Hi everyone,
I have two servers:
one is running jitsi-meet, jicofo, prosody without any errors.
one is running jibri without any errors
both server are able to talk with each other
when moderator started recording, recording started and mp4 file is created but having only logo of jitsi and members empty tiles and nothing else.
no error found on jibri/log/browser/ffmepg
no error found on jitsi/jvb/jicofo/prosody
xorg is running without any errors
please anyone help me to solve this?

is there any paid support from jitsi?

regards

bbaldino · September 4, 2019, 4:33pm

to start, please include some jibri logs from when the issue occurs. a sample of the recorded video might also be interesting.

sobish · September 5, 2019, 6:30am

jibri log

2019-09-05 05:07:58.224 INFO: [1] org.jitsi.jibri.Main.main() Jibri run with args [–config, /etc/jitsi/jibri/config.json]
2019-09-05 05:07:58.233 INFO: [1] org.jitsi.jibri.Main.main() Using config file /etc/jitsi/jibri/config.json
2019-09-05 05:07:58.233 INFO: [1] org.jitsi.jibri.Main.main() Using port 3333 for internal HTTP API
2019-09-05 05:07:58.233 INFO: [1] org.jitsi.jibri.Main.main() Using port 2222 for the HTTP API
2019-09-05 05:07:59.120 INFO: [1] org.jitsi.jibri.Main.loadConfig() Parsed config:
JibriConfig(recordingDirectory=/opt/records, enabledStatsD=true, finalizeRecordingScriptPath=/opt/finalize_recording.sh, xmppEnvironments=[XmppEnvironmentConfig(name=prod environment, xmppServerHosts=, xmppDomain=, controlLogin=XmppCredentials(domain=, username=jibri_user), controlMuc=XmppMuc(roomName=jibri_brewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)])
2019-09-05 05:07:59.852 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.
2019-09-05 05:08:00.182 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
2019-09-05 05:08:00.185 INFO: [1] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@31be6b49
2019-09-05 05:08:00.200 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() Connecting to xmpp environment on with config XmppEnvironmentConfig(name=prod environment, xmppServerHosts=, xmppDomain=, controlLogin=XmppCredentials(), controlMuc=XmppMuc(roomName=jibri_brewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)
2019-09-05 05:08:00.201 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
2019-09-05 05:08:00.230 WARNING: [20] org.jitsi.xmpp.mucclient.MucClient.log() Disabling certificate verification!
2019-09-05 05:08:00.252 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.
2019-09-05 05:08:00.541 INFO: [20] org.jitsi.xmpp.mucclient.MucClient.log() [MucClient] connected
2019-09-05 05:08:00.613 INFO: [20] org.jitsi.xmpp.mucclient.MucClient.log() Joined MUC: jibri_brewery@
2019-09-05 05:08:12.924 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq from environment [MucClient]
2019-09-05 05:08:12.925 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request
2019-09-05 05:08:12.929 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending ‘pending’ response to start IQ
2019-09-05 05:08:12.929 INFO: [35] org.jitsi.jibri.api.xmpp.XmppApi.run() Starting service
2019-09-05 05:08:12.962 INFO: [35] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://tcoms02.cognitivehealthintl.com, callName=blackscreenrecording, urlParams=)
2019-09-05 05:08:12.963 INFO: [35] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(callName=blackscreenrecording, urlParams=)), sessionId=ozzothwgorbbbfjm, callLoginParams=XmppCredentials() finalize script path: /opt/finalize_recording.sh and recordings directory: /opt/records
2019-09-05 05:08:15.655 INFO: [35] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
2019-09-05 05:08:15.685 FINE: [35] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.() Detected os as OS: LINUX
2019-09-05 05:08:15.691 INFO: [35] org.jitsi.jibri.service.impl.FileRecordingJibriService.() Writing recording to /opt/records/ozzothwgorbbbfjm
2019-09-05 05:08:15.692 FINE: [35] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
2019-09-05 05:08:15.693 INFO: [35] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
2019-09-05 05:08:15.693 INFO: [35] 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
2019-09-05 05:08:15.694 INFO: [35] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@3b5f5ac1
2019-09-05 05:08:16.527 FINE: [44] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url blackscreenrecording#config.iAmRecorder=true&config.externalConnectUrl=null&config.startWithAudioMuted=true&config.startWithVideoMuted=true&interfaceConfig.APP_NAME=“Jibri”&config.analytics.disabled=true
2019-09-05 05:08:17.992 INFO: [44] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Waited 1084 milliseconds for call page to load
2019-09-05 05:08:18.004 INFO: [44] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Running
2019-09-05 05:08:18.005 INFO: [44] org.jitsi.jibri.service.impl.FileRecordingJibriService.invoke() Selenium joined the call, starting the capturer
2019-09-05 05:08:18.036 INFO: [44] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.launch() Starting ffmpeg with command ffmpeg -y -v info -f x11grab -draw_mouse 0 -r 30 -s 1280x720 -thread_queue_size 4096 -i :0.0+0,0 -f alsa -thread_queue_size 4096 -i plug:cloop -acodec aac -strict -2 -ar 44100 -c:v libx264 -preset veryfast -profile:v main -level 3.1 -pix_fmt yuv420p -r 30 -crf 25 -g 60 -tune zerolatency -f mp4 /opt/records/ozzothwgorbbbfjm/blackscreenrecording_2019-09-05-05-08-15.mp4 ([ffmpeg, -y, -v, info, -f, x11grab, -draw_mouse, 0, -r, 30, -s, 1280x720, -thread_queue_size, 4096, -i, :0.0+0,0, -f, alsa, -thread_queue_size, 4096, -i, plug:cloop, -acodec, aac, -strict, -2, -ar, 44100, -c:v, libx264, -preset, veryfast, -profile:v, main, -level, 3.1, -pix_fmt, yuv420p, -r, 30, -crf, 25, -g, 60, -tune, zerolatency, -f, mp4, /opt/records/ozzothwgorbbbfjm/blackscreenrecording_2019-09-05-05-08-15.mp4])
2019-09-05 05:08:19.554 INFO: [48] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Starting up to Running
2019-09-05 05:08:19.555 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Running
2019-09-05 05:08:19.555 INFO: [48] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service started up successfully, sending on iq
2019-09-05 05:08:33.034 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=0, upload=0}, download=0, upload=0, video={download=0, upload=0}}, all clients muted? false
2019-09-05 05:08:44.724 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq from environment [MucClient]
2019-09-05 05:08:44.725 FINE: [34] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
2019-09-05 05:08:44.725 INFO: [34] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2019-09-05 05:08:44.725 INFO: [34] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
2019-09-05 05:08:44.725 INFO: [34] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
2019-09-05 05:08:45.154 INFO: [34] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value 255
2019-09-05 05:08:45.154 INFO: [48] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Running to Finished
2019-09-05 05:08:45.155 INFO: [34] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
2019-09-05 05:08:45.155 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Running to Finished
2019-09-05 05:08:45.155 INFO: [48] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service finished, sending off iq
2019-09-05 05:08:45.172 INFO: [34] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording:
2019-09-05 05:08:45.226 INFO: [34] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 48 log entries for type browser
2019-09-05 05:08:45.284 INFO: [34] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 717 log entries for type driver
2019-09-05 05:08:45.364 INFO: [34] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
2019-09-05 05:08:45.364 INFO: [34] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
2019-09-05 05:08:45.444 INFO: [34] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
2019-09-05 05:08:45.526 INFO: [34] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Chrome driver quit
2019-09-05 05:08:45.526 INFO: [34] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Finalizing the recording
2019-09-05 05:08:45.528 INFO: [34] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Recording finalize script finished with exit value 0
2019-09-05 05:08:45.529 INFO: [34] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: BUSY -> IDLE
2019-09-05 05:08:45.529 INFO: [34] 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
2019-09-05 05:08:45.530 INFO: [34] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@6c32d94e
2019-09-05 05:08:45.530 FINE: [48] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:
2019-09-05 05:08:45.531 INFO: [48] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2019-09-05 05:28:37.878 INFO: [17] org.jitsi.jibri.api.http.internal.InternalHttpApi.gracefulShutdown() Jibri gracefully shutting down

ffmpeg log:

2019-09-05 05:08:18.394 INFO: [49] ffmpeg.call() ffmpeg version 3.4.6-0ubuntu0.18.04.1 2019-09-05 05:08:18.394 INFO: [49] ffmpeg.call() built with gcc 7 (Ubuntu 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() configuration: --prefix=/usr 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libavutil 55. 78.100 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libavcodec 57.107.100 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libavformat 57. 83.100 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libavdevice 57. 10.100 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libavfilter 6.107.100 / 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libavresample 3. 7. 2019-09-05 05:08:18.496 INFO: [49] ffmpeg.call() libswscale 4. 8.100 / 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() libswresample 2. 9.100 / 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() libpostproc 54. 7.100 / 54. 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() [x11grab @ 0x55f15dca1f00] 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() Input #0, 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() Duration: N/A, start: 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() Stream #0:0: 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() Guessed Channel Layout 2019-09-05 05:08:18.497 INFO: [49] ffmpeg.call() Input #1, 2019-09-05 05:08:18.553 INFO: [49] ffmpeg.call() Duration: N/A, start: 2019-09-05 05:08:18.553 INFO: [49] ffmpeg.call() Stream #1:0: 2019-09-05 05:08:18.553 INFO: [49] ffmpeg.call() Stream mapping:
2019-09-05 05:08:18.553 INFO: [49] ffmpeg.call() Stream #0:0 2019-09-05 05:08:18.554 INFO: [49] ffmpeg.call() Stream #1:0 2019-09-05 05:08:18.554 INFO: [49] ffmpeg.call() Press [q] to stop, [?] 2019-09-05 05:08:18.554 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:18.554 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:18.554 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:19.554 INFO: [49] ffmpeg.call() Output #0, 2019-09-05 05:08:19.554 INFO: [49] ffmpeg.call() Metadata:
2019-09-05 05:08:19.554 INFO: [49] ffmpeg.call() encoder : Lavf57.83. 2019-09-05 05:08:19.554 INFO: [49] ffmpeg.call() Stream #0:0: 2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() Metadata:
2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() encoder : 2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() Side data:
2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() cpb: bitrate max/min/avg: 2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() Stream #0:1: 2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() Metadata:
2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() encoder : 2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() frame= 14 fps=0.0 q=21.0 size= 2019-09-05 05:08:19.555 INFO: [49] ffmpeg.call() frame= 29 fps= 29 q=21.0 size= 2019-09-05 05:08:20.556 INFO: [49] ffmpeg.call() frame= 45 fps= 30 q=21.0 size= 2019-09-05 05:08:20.556 INFO: [49] ffmpeg.call() frame= 59 fps= 29 q=21.0 size= 2019-09-05 05:08:21.556 INFO: [49] ffmpeg.call() frame= 74 fps= 29 q=21.0 size= 2019-09-05 05:08:21.556 INFO: [49] ffmpeg.call() frame= 89 fps= 29 q=21.0 size= 2019-09-05 05:08:22.557 INFO: [49] ffmpeg.call() frame= 105 fps= 30 q=21.0 size= 2019-09-05 05:08:22.557 INFO: [49] ffmpeg.call() frame= 120 fps= 30 q=21.0 size= 2019-09-05 05:08:23.557 INFO: [49] ffmpeg.call() frame= 135 fps= 30 q=21.0 size= 2019-09-05 05:08:23.557 INFO: [49] ffmpeg.call() frame= 150 fps= 30 q=21.0 size= 2019-09-05 05:08:24.558 INFO: [49] ffmpeg.call() frame= 165 fps= 30 q=21.0 size= 2019-09-05 05:08:24.558 INFO: [49] ffmpeg.call() frame= 180 fps= 30 q=21.0 size= 2019-09-05 05:08:25.558 INFO: [49] ffmpeg.call() frame= 195 fps= 30 q=21.0 size= 2019-09-05 05:08:25.559 INFO: [49] ffmpeg.call() frame= 211 fps= 30 q=21.0 size= 2019-09-05 05:08:26.559 INFO: [49] ffmpeg.call() frame= 226 fps= 30 q=21.0 size= 2019-09-05 05:08:27.559 INFO: [49] ffmpeg.call() frame= 241 fps= 30 q=18.0 size= 2019-09-05 05:08:27.560 INFO: [49] ffmpeg.call() frame= 256 fps= 30 q=21.0 size= 2019-09-05 05:08:28.560 INFO: [49] ffmpeg.call() frame= 270 fps= 30 q=21.0 size= 2019-09-05 05:08:28.560 INFO: [49] ffmpeg.call() frame= 286 fps= 30 q=21.0 size= 2019-09-05 05:08:29.560 INFO: [49] ffmpeg.call() frame= 301 fps= 30 q=18.0 size= 2019-09-05 05:08:29.561 INFO: [49] ffmpeg.call() frame= 316 fps= 30 q=21.0 size= 2019-09-05 05:08:30.561 INFO: [49] ffmpeg.call() frame= 332 fps= 30 q=21.0 size= 2019-09-05 05:08:30.561 INFO: [49] ffmpeg.call() frame= 347 fps= 30 q=21.0 size= 2019-09-05 05:08:31.561 INFO: [49] ffmpeg.call() frame= 362 fps= 30 q=23.0 size= 2019-09-05 05:08:31.561 INFO: [49] ffmpeg.call() frame= 377 fps= 30 q=21.0 size= 2019-09-05 05:08:32.562 INFO: [49] ffmpeg.call() frame= 392 fps= 30 q=21.0 size= 2019-09-05 05:08:32.562 INFO: [49] ffmpeg.call() frame= 407 fps= 30 q=23.0 size= 2019-09-05 05:08:33.562 INFO: [49] ffmpeg.call() frame= 422 fps= 30 q=23.0 size= 2019-09-05 05:08:33.562 INFO: [49] ffmpeg.call() frame= 438 fps= 30 q=21.0 size= 2019-09-05 05:08:34.563 INFO: [49] ffmpeg.call() frame= 453 fps= 30 q=21.0 size= 2019-09-05 05:08:34.563 INFO: [49] ffmpeg.call() frame= 468 fps= 30 q=21.0 size= 2019-09-05 05:08:35.563 INFO: [49] ffmpeg.call() frame= 483 fps= 30 q=22.0 size= 2019-09-05 05:08:35.563 INFO: [49] ffmpeg.call() frame= 498 fps= 30 q=21.0 size= 2019-09-05 05:08:36.565 INFO: [49] ffmpeg.call() frame= 514 fps= 30 q=21.0 size= 2019-09-05 05:08:36.565 INFO: [49] ffmpeg.call() frame= 529 fps= 30 q=21.0 size= 2019-09-05 05:08:37.565 INFO: [49] ffmpeg.call() frame= 544 fps= 30 q=21.0 size= 2019-09-05 05:08:37.565 INFO: [49] ffmpeg.call() frame= 559 fps= 30 q=21.0 size= 2019-09-05 05:08:38.566 INFO: [49] ffmpeg.call() frame= 573 fps= 30 q=21.0 size= 2019-09-05 05:08:38.566 INFO: [49] ffmpeg.call() frame= 589 fps= 30 q=21.0 size= 2019-09-05 05:08:39.566 INFO: [49] ffmpeg.call() frame= 604 fps= 30 q=21.0 size= 2019-09-05 05:08:39.566 INFO: [49] ffmpeg.call() frame= 619 fps= 30 q=21.0 size= 2019-09-05 05:08:40.567 INFO: [49] ffmpeg.call() frame= 634 fps= 30 q=21.0 size= 2019-09-05 05:08:40.567 INFO: [49] ffmpeg.call() frame= 650 fps= 30 q=21.0 size= 2019-09-05 05:08:41.567 INFO: [49] ffmpeg.call() frame= 665 fps= 30 q=21.0 size= 2019-09-05 05:08:41.567 INFO: [49] ffmpeg.call() frame= 680 fps= 30 q=21.0 size= 2019-09-05 05:08:42.567 INFO: [49] ffmpeg.call() frame= 695 fps= 30 q=21.0 size= 2019-09-05 05:08:42.568 INFO: [49] ffmpeg.call() frame= 710 fps= 30 q=21.0 size= 2019-09-05 05:08:43.568 INFO: [49] ffmpeg.call() frame= 725 fps= 30 q=21.0 size= 2019-09-05 05:08:43.568 INFO: [49] ffmpeg.call() frame= 740 fps= 30 q=21.0 size= 2019-09-05 05:08:44.568 INFO: [49] ffmpeg.call() frame= 755 fps= 30 q=21.0 size= 2019-09-05 05:08:44.569 INFO: [49] ffmpeg.call() frame= 771 fps= 30 q=21.0 size= 2019-09-05 05:08:44.756 INFO: [49] ffmpeg.call() frame= 785 fps= 30 q=21.0 size= 2019-09-05 05:08:44.756 INFO: [49] ffmpeg.call() frame= 786 fps= 30 q=21.0 Lsize= 2019-09-05 05:08:44.756 INFO: [49] ffmpeg.call() video:158kB audio:9kB subtitle:0kB 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] frame I:14 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] frame P:772 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] mb I 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] mb P 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] i16 v,h,dc,p: 90% 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:44.757 INFO: [49] ffmpeg.call() [libx264 @ 0x55f15dcd7020] 2019-09-05 05:08:45.153 INFO: [49] ffmpeg.call() [aac @ 0x55f15dcdb3c0] 2019-09-05 05:08:45.153 INFO: [49] ffmpeg.call() Exiting normally, received Copyright © 2000-2019 the FFmpeg developers
7.3.0-16ubuntu3)
--extra-version=0ubuntu0.18.04.1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --enable-gpl --disable-stripping --enable-avresample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librubberband --enable-librsvg --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzmq --enable-libzvbi --enable-omx --enable-openal --enable-opengl --enable-sdl2 --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libopencv --enable-libx264 --enable-shared
/ 55. 78.100
/ 57.107.100
/ 57. 83.100
/ 57. 10.100
6.107.100
0 / 3. 7. 0
4. 8.100
2. 9.100
7.100
Stream #0: not enough frames to estimate rate; consider increasing probesize
x11grab, from ‘:0.0+0,0’:
1567660098.451539, bitrate: N/A
Video: rawvideo (BGR[0] / 0x524742), bgr0, 1280x720, 30 fps, 1000k tbr, 1000k tbn, 1000k tbc
for Input Stream #1.0 : stereo
alsa, from ‘plug:cloop’:
1567660098.115420, bitrate: 1536 kb/s
Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
-> #0:0 (rawvideo (native) -> h264 (libx264))
-> #0:1 (pcm_s16le (native) -> aac (native))
for help
using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
profile Main, level 3.1
264 - core 152 r2854 e9a5903 - H.264/MPEG-4 AVC codec - Copyleft 2003-2017 - options: cabac=1 ref=1 deblock=1:0:0 analyse=0x1:0x111 me=hex subme=2 psy=1 psy_rd=1.00:0.00 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=0 threads=4 lookahead_threads=4 sliced_threads=1 slices=4 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=1 keyint=60 keyint_min=6 scenecut=40 intra_refresh=0 rc=crf mbtree=0 crf=25.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
mp4, to ‘/opt/records/ozzothwgorbbbfjm/blackscreenrecording_2019-09-05-05-08-15.mp4’:
100
Video: h264 (libx264) (avc1 / 0x31637661), yuv420p(progressive), 1280x720, q=-1–1, 30 fps, 15360 tbn, 30 tbc
Lavc57.107.100 libx264
0/0/0 buffer size: 0 vbv_delay: -1
Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 128 kb/s
Lavc57.107.100 aac
0kB time=00:00:00.44 bitrate= 0.9kbits/s speed=0.879x
0kB time=00:00:00.95 bitrate= 0.4kbits/s speed=0.944x
0kB time=00:00:01.46 bitrate= 0.3kbits/s speed=0.97x
0kB time=00:00:01.95 bitrate= 0.2kbits/s speed=0.967x
0kB time=00:00:02.46 bitrate= 0.2kbits/s speed=0.977x
0kB time=00:00:02.97 bitrate= 0.1kbits/s speed=0.984x
0kB time=00:00:03.46 bitrate= 0.1kbits/s speed=0.984x
0kB time=00:00:03.97 bitrate= 0.1kbits/s speed=0.986x
0kB time=00:00:04.48 bitrate= 0.1kbits/s speed=0.989x
0kB time=00:00:04.99 bitrate= 0.1kbits/s speed=0.992x
0kB time=00:00:05.48 bitrate= 0.1kbits/s speed=0.99x
0kB time=00:00:05.99 bitrate= 0.1kbits/s speed=0.992x
0kB time=00:00:06.48 bitrate= 0.1kbits/s speed=0.99x
0kB time=00:00:07.00 bitrate= 0.1kbits/s speed=0.992x
0kB time=00:00:07.50 bitrate= 0.1kbits/s speed=0.993x
0kB time=00:00:08.01 bitrate= 0.0kbits/s speed=0.994x
0kB time=00:00:08.50 bitrate= 0.0kbits/s speed=0.993x
0kB time=00:00:09.01 bitrate= 0.0kbits/s speed=0.994x
0kB time=00:00:09.52 bitrate= 0.0kbits/s speed=0.995x
0kB time=00:00:10.00 bitrate= 0.0kbits/s speed=0.993x
0kB time=00:00:10.52 bitrate= 0.0kbits/s speed=0.994x
0kB time=00:00:11.03 bitrate= 0.0kbits/s speed=0.995x
0kB time=00:00:11.54 bitrate= 0.0kbits/s speed=0.995x
0kB time=00:00:12.03 bitrate= 0.0kbits/s speed=0.995x
0kB time=00:00:12.54 bitrate= 0.0kbits/s speed=0.995x
0kB time=00:00:13.05 bitrate= 0.0kbits/s speed=0.996x
0kB time=00:00:13.53 bitrate= 0.0kbits/s speed=0.995x
0kB time=00:00:14.07 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:14.56 bitrate= 0.0kbits/s speed=0.996x
0kB time=00:00:15.07 bitrate= 0.0kbits/s speed=0.996x
0kB time=00:00:15.58 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:16.07 bitrate= 0.0kbits/s speed=0.996x
0kB time=00:00:16.58 bitrate= 0.0kbits/s speed=0.996x
0kB time=00:00:17.10 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:17.60 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:18.10 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:18.60 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:19.11 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:19.62 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:20.13 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:20.62 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:21.13 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:21.64 bitrate= 0.0kbits/s speed=0.998x
0kB time=00:00:22.13 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:22.64 bitrate= 0.0kbits/s speed=0.998x
0kB time=00:00:23.15 bitrate= 0.0kbits/s speed=0.998x
0kB time=00:00:23.66 bitrate= 0.0kbits/s speed=0.998x
0kB time=00:00:24.15 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:24.66 bitrate= 0.0kbits/s speed=0.998x
0kB time=00:00:25.14 bitrate= 0.0kbits/s speed=0.997x
0kB time=00:00:25.66 bitrate= 0.0kbits/s speed=0.998x
0kB time=00:00:26.17 bitrate= 0.0kbits/s speed=0.998x
201kB time=00:00:26.21 bitrate= 62.6kbits/s speed=0.999x
other streams:0kB global headers:0kB muxing overhead: 20.215351%
Avg QP: 4.13 size: 5550
Avg QP: 6.55 size: 108
I16…4: 95.7% 0.0% 4.3%
I16…4: 0.2% 0.0% 0.0% P16…4: 0.0% 0.0% 0.0% 0.0% 0.0% skip:99.8%
coded y,uvDC,uvAC intra: 2.9% 0.5% 0.4% inter: 0.0% 0.0% 0.0%
2% 9% 0%
i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 29% 20% 31% 3% 3% 3% 4% 3% 4%
i8c dc,h,v,p: 100% 0% 0% 0%
Weighted P-Frames: Y:0.4% UV:0.0%
kb/s:49.11
Qavg: 65132.121
signal 2.

recorded video:

thanks for your response

bbaldino · September 5, 2019, 5:31pm

Looks like Jibri isn’t receiving any media. I’d check if ICE is connecting successfully, maybe there isn’t proper network connectivity between the Jibri machine and the JVB?

sobish · September 6, 2019, 6:31am

i did an other session to log and here it is:
jvb-log:

JVB 2019-09-06 06:06:53.714 INFO: [160] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=b130deb0e90fead9 conf_name=blackscreenrecording,logging=true,conf_count=1,ch_count=0,v_streams=0
JVB 2019-09-06 06:06:53.719 INFO: [160] org.jitsi.videobridge.Conference.log() CAT=stat create_content,conf_id=b130deb0e90fead9,content=audio conf_count=1,ch_count=0,v_streams=0
JVB 2019-09-06 06:06:53.720 INFO: [160] org.ice4j.ice.Agent.log() Gathering candidates for component stream.RTP. Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:06:53.720 INFO: [160] org.jitsi.videobridge.Conference.log() CAT=stat create_ice_tm,conf_id=b130deb0e90fead9 ufrag=fvv691dk2itgon,bundle=57951044,initiator=true
JVB 2019-09-06 06:06:53.721 INFO: [160] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=b130deb0e90fead9,content=audio,ch_id=d1b3069933ebbf7d,endp_id=null,stream=1742424081
JVB 2019-09-06 06:06:53.721 INFO: [160] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=b130deb0e90fead9,content=audio,ch_id=d1b3069933ebbf7d,endp_id=null,stream=1742424081 transport=default,bundle=57951044,initiator=true,media_type=audio,relay_type=null
JVB 2019-09-06 06:06:53.744 INFO: [160] org.jitsi.videobridge.Conference.log() CAT=stat create_content,conf_id=b130deb0e90fead9,content=video conf_count=1,ch_count=1,v_streams=0
JVB 2019-09-06 06:06:53.745 INFO: [160] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=b130deb0e90fead9,content=video,ch_id=c547f6ace3f9218e,endp_id=null,stream=422948673
JVB 2019-09-06 06:06:53.746 INFO: [160] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=b130deb0e90fead9,content=video,ch_id=c547f6ace3f9218e,endp_id=null,stream=422948673 transport=default,bundle=57951044,initiator=true,media_type=video,relay_type=null
JVB 2019-09-06 06:06:53.747 INFO: [160] org.jitsi.videobridge.Conference.log() CAT=stat create_content,conf_id=b130deb0e90fead9,content=data conf_count=1,ch_count=2,v_streams=1
JVB 2019-09-06 06:06:53.957 INFO: [15] org.jitsi.videobridge.VideobridgeExpireThread.log() Running expire()
JVB 2019-09-06 06:06:54.102 INFO: [183] org.jitsi.videobridge.IceUdpTransportManager.log() Starting ICE agent without remote candidates.
JVB 2019-09-06 06:06:54.103 INFO: [183] org.ice4j.ice.Agent.log() Start ICE connectivity establishment. Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:06:54.103 INFO: [183] org.ice4j.ice.Agent.log() Init checklist for stream stream
JVB 2019-09-06 06:06:54.103 INFO: [183] org.ice4j.ice.Agent.log() ICE state changed from Waiting to Running. Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:06:54.103 INFO: [183] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=b130deb0e90fead9,content=data,ch_id=54deff78185d064e,endp_id=57951044 old_state=Waiting,new_state=Running
JVB 2019-09-06 06:06:54.103 INFO: [183] org.ice4j.ice.ConnectivityCheckClient.log() Start connectivity checks. Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:06:54.115 INFO: [185] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 172.31.43.85:50998/udp
JVB 2019-09-06 06:06:54.115 INFO: [185] org.ice4j.ice.Component.log() new Pair added: 172.31.17.6:10000/udp/host -> 172.31.43.85:50998/udp/host (stream.RTP). Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:06:54.116 INFO: [185] org.ice4j.ice.Component.log() new Pair added: 3.8.229.196:10000/udp/srflx -> 172.31.43.85:50998/udp/host (stream.RTP). Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:06:54.202 INFO: [335] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 172.31.17.6:10000/udp/host -> 172.31.43.85:50998/udp/host (stream.RTP)
JVB 2019-09-06 06:06:54.237 INFO: [187] org.ice4j.ice.Agent.log() Gathering candidates for component stream.RTP. Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:06:54.241 INFO: [187] org.jitsi.videobridge.Conference.log() CAT=stat create_ice_tm,conf_id=b130deb0e90fead9 ufrag=15r6g1dk2ith8s,bundle=4e224569,initiator=true
JVB 2019-09-06 06:06:54.241 INFO: [187] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=b130deb0e90fead9,content=audio,ch_id=4704d6414c86f441,endp_id=null,stream=1615225255
JVB 2019-09-06 06:06:54.241 INFO: [187] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=b130deb0e90fead9,content=audio,ch_id=4704d6414c86f441,endp_id=null,stream=1615225255 transport=default,bundle=4e224569,initiator=true,media_type=audio,relay_type=null
JVB 2019-09-06 06:06:54.242 INFO: [187] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=b130deb0e90fead9,content=video,ch_id=92c56ff34ae4eee5,endp_id=null,stream=1399953016
JVB 2019-09-06 06:06:54.243 INFO: [187] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=b130deb0e90fead9,content=video,ch_id=92c56ff34ae4eee5,endp_id=null,stream=1399953016 transport=default,bundle=4e224569,initiator=true,media_type=video,relay_type=null
JVB 2019-09-06 06:06:55.291 INFO: [16] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=cc27dddcf306b20 conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4
JVB 2019-09-06 06:06:55.319 INFO: [16] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 29ms. Sticky failure: false
JVB 2019-09-06 06:06:55.454 INFO: [213] org.jitsi.videobridge.cc.BitrateController.log() new track projection for subjective_quality=0,primary_ssrc=904745427,secondary_ssrcs={183474910=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=904745427,secondary_ssrcs={183474910=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=904745427,secondary_ssrcs={183474910=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=706213895,secondary_ssrcs={3660922434=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=706213895,secondary_ssrcs={3660922434=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=706213895,secondary_ssrcs={3660922434=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=3507740899,secondary_ssrcs={2277118745=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=3507740899,secondary_ssrcs={2277118745=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=3507740899,secondary_ssrcs={2277118745=rtx},temporal_id=2,spatial_id=-1
JVB 2019-09-06 06:06:55.456 WARNING: [213] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57951044 not ready yet.
JVB 2019-09-06 06:06:55.456 WARNING: [213] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:06:55.465 INFO: [213] org.ice4j.ice.Component.log() Add remote candidate for stream.RTP: 10.8.99.12:59343/udp/host
JVB 2019-09-06 06:06:55.465 INFO: [213] org.jitsi.videobridge.IceUdpTransportManager.log() We have remote candidates for all ICE components. Starting the ICE agent.
JVB 2019-09-06 06:06:55.465 INFO: [213] org.ice4j.ice.Agent.log() Start ICE connectivity establishment. Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:06:55.465 INFO: [213] org.ice4j.ice.Agent.log() Init checklist for stream stream
JVB 2019-09-06 06:06:55.466 INFO: [213] org.ice4j.ice.Agent.log() ICE state changed from Waiting to Running. Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:06:55.466 INFO: [213] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=b130deb0e90fead9,content=data,ch_id=7e4520a57f26b15a,endp_id=4e224569 old_state=Waiting,new_state=Running
JVB 2019-09-06 06:06:55.466 INFO: [213] org.ice4j.ice.ConnectivityCheckClient.log() Start connectivity checks. Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:06:55.466 INFO: [238] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.466 INFO: [238] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.466 INFO: [238] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.467 INFO: [238] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.467 INFO: [238] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:9/tcp
JVB 2019-09-06 06:06:55.467 INFO: [238] org.ice4j.ice.Component.log() new Pair added: 172.31.17.6:4443/tcp/host -> 10.8.99.12:9/tcp/host (stream.RTP). Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:06:55.467 INFO: [238] org.ice4j.ice.Component.log() new Pair added: 3.8.229.196:4443/tcp/srflx -> 10.8.99.12:9/tcp/host (stream.RTP). Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:06:55.468 INFO: [236] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.468 INFO: [236] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.468 INFO: [236] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.468 INFO: [236] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59343/udp
JVB 2019-09-06 06:06:55.487 INFO: [335] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 172.31.17.6:10000/udp/host -> 10.8.99.12:59343/udp/host (stream.RTP)
JVB 2019-09-06 06:06:55.507 INFO: [335] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 172.31.17.6:4443/tcp/host -> 10.8.99.12:9/tcp/host (stream.RTP)
JVB 2019-09-06 06:07:01.548 INFO: [81] org.ice4j.ice.Agent.log() Gathering candidates for component stream.RTP. Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:01.549 INFO: [81] org.jitsi.videobridge.Conference.log() CAT=stat create_ice_tm,conf_id=b130deb0e90fead9 ufrag=4jr621dk2itodc,bundle=9ab5dc6a,initiator=true
JVB 2019-09-06 06:07:01.549 INFO: [81] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=b130deb0e90fead9,content=audio,ch_id=e2e9f7d731e54160,endp_id=null,stream=340185051
JVB 2019-09-06 06:07:01.549 INFO: [81] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=b130deb0e90fead9,content=audio,ch_id=e2e9f7d731e54160,endp_id=null,stream=340185051 transport=default,bundle=9ab5dc6a,initiator=true,media_type=audio,relay_type=null
JVB 2019-09-06 06:07:01.550 INFO: [81] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=b130deb0e90fead9,content=video,ch_id=83c724e3f024da20,endp_id=null,stream=1363428151
JVB 2019-09-06 06:07:01.550 INFO: [81] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=b130deb0e90fead9,content=video,ch_id=83c724e3f024da20,endp_id=null,stream=1363428151 transport=default,bundle=9ab5dc6a,initiator=true,media_type=video,relay_type=null
JVB 2019-09-06 06:07:03.082 INFO: [104] org.jitsi.videobridge.cc.BitrateController.log() new track projection for subjective_quality=0,primary_ssrc=3281319453,secondary_ssrcs={2306062248=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=3281319453,secondary_ssrcs={2306062248=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=3281319453,secondary_ssrcs={2306062248=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=712201114,secondary_ssrcs={4130210331=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=712201114,secondary_ssrcs={4130210331=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=712201114,secondary_ssrcs={4130210331=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=3522972069,secondary_ssrcs={1682206006=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=3522972069,secondary_ssrcs={1682206006=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=3522972069,secondary_ssrcs={1682206006=rtx},temporal_id=2,spatial_id=-1
JVB 2019-09-06 06:07:03.090 WARNING: [104] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57951044 not ready yet.
JVB 2019-09-06 06:07:03.090 WARNING: [104] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:03.090 INFO: [104] org.jitsi.videobridge.cc.BitrateController.log() new track projection for subjective_quality=0,primary_ssrc=3281319453,secondary_ssrcs={2306062248=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=3281319453,secondary_ssrcs={2306062248=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=3281319453,secondary_ssrcs={2306062248=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=712201114,secondary_ssrcs={4130210331=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=712201114,secondary_ssrcs={4130210331=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=712201114,secondary_ssrcs={4130210331=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=3522972069,secondary_ssrcs={1682206006=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=3522972069,secondary_ssrcs={1682206006=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=3522972069,secondary_ssrcs={1682206006=rtx},temporal_id=2,spatial_id=-1
JVB 2019-09-06 06:07:03.091 WARNING: [104] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 4e224569 not ready yet.
JVB 2019-09-06 06:07:03.091 WARNING: [104] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:03.092 INFO: [104] org.ice4j.ice.Component.log() Add remote candidate for stream.RTP: 10.8.99.12:59354/udp/host
JVB 2019-09-06 06:07:03.092 INFO: [104] org.jitsi.videobridge.IceUdpTransportManager.log() We have remote candidates for all ICE components. Starting the ICE agent.
JVB 2019-09-06 06:07:03.092 INFO: [104] org.ice4j.ice.Agent.log() Start ICE connectivity establishment. Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:03.092 INFO: [104] org.ice4j.ice.Agent.log() Init checklist for stream stream
JVB 2019-09-06 06:07:03.092 INFO: [104] org.ice4j.ice.Agent.log() ICE state changed from Waiting to Running. Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:03.093 INFO: [104] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=b130deb0e90fead9,content=data,ch_id=29718f39da965401,endp_id=9ab5dc6a old_state=Waiting,new_state=Running
JVB 2019-09-06 06:07:03.093 INFO: [104] org.ice4j.ice.ConnectivityCheckClient.log() Start connectivity checks. Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:03.103 INFO: [104] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.103 INFO: [104] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.103 INFO: [104] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.103 INFO: [104] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.120 INFO: [106] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.120 INFO: [106] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.120 INFO: [106] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.120 INFO: [106] org.ice4j.ice.Component.log() Not adding duplicate remote candidate: 10.8.99.12:59354/udp
JVB 2019-09-06 06:07:03.120 INFO: [106] org.ice4j.ice.Component.log() Update remote candidate for stream.RTP: 10.8.99.12:9/tcp
JVB 2019-09-06 06:07:03.121 INFO: [106] org.ice4j.ice.Component.log() new Pair added: 172.31.17.6:4443/tcp/host -> 10.8.99.12:9/tcp/host (stream.RTP). Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:03.121 INFO: [106] org.ice4j.ice.Component.log() new Pair added: 3.8.229.196:4443/tcp/srflx -> 10.8.99.12:9/tcp/host (stream.RTP). Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:03.131 INFO: [335] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 172.31.17.6:10000/udp/host -> 10.8.99.12:59354/udp/host (stream.RTP)
JVB 2019-09-06 06:07:03.152 INFO: [335] org.ice4j.ice.ConnectivityCheckClient.log() Pair failed: 172.31.17.6:4443/tcp/host -> 10.8.99.12:9/tcp/host (stream.RTP)
JVB 2019-09-06 06:07:05.319 INFO: [16] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=f2fdb0b87c088dc8 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9
JVB 2019-09-06 06:07:05.340 INFO: [16] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 21ms. Sticky failure: false
JVB 2019-09-06 06:07:08.904 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57951044 not ready yet.
JVB 2019-09-06 06:07:08.904 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:08.904 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 4e224569 not ready yet.
JVB 2019-09-06 06:07:08.904 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:08.904 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 9ab5dc6a not ready yet.
JVB 2019-09-06 06:07:08.904 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:09.404 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57951044 not ready yet.
JVB 2019-09-06 06:07:09.404 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:09.404 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 4e224569 not ready yet.
JVB 2019-09-06 06:07:09.404 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:09.404 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 9ab5dc6a not ready yet.
JVB 2019-09-06 06:07:09.405 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:15.341 INFO: [16] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=e1d21b624f033d87 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9
JVB 2019-09-06 06:07:15.366 INFO: [16] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 26ms. Sticky failure: false
JVB 2019-09-06 06:07:16.906 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57951044 not ready yet.
JVB 2019-09-06 06:07:16.906 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:16.906 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 4e224569 not ready yet.
JVB 2019-09-06 06:07:16.906 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:16.906 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 9ab5dc6a not ready yet.
JVB 2019-09-06 06:07:16.906 WARNING: [13] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:24.172 INFO: [185] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=audio,ch_id=d1b3069933ebbf7d,endp_id=57951044,stream=1742424081
JVB 2019-09-06 06:07:24.173 INFO: [185] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=b130deb0e90fead9,content=audio,ch_id=d1b3069933ebbf7d,endp_id=57951044,stream=1742424081 bRecv=0,bSent=0,pRecv=0,pSent=0,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0
JVB 2019-09-06 06:07:24.174 INFO: [185] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=video,ch_id=c547f6ace3f9218e,endp_id=57951044,stream=422948673
JVB 2019-09-06 06:07:24.174 INFO: [185] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=b130deb0e90fead9,content=video,ch_id=c547f6ace3f9218e,endp_id=57951044,stream=422948673 bRecv=0,bSent=0,pRecv=0,pSent=0,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0
JVB 2019-09-06 06:07:24.175 INFO: [185] org.ice4j.ice.Agent.log() ICE state changed from Running to Terminated. Local ufrag fvv691dk2itgon
JVB 2019-09-06 06:07:24.175 WARNING: [334] org.jitsi.videobridge.IceUdpTransportManager.log() Cannot get transport type.
JVB 2019-09-06 06:07:24.175 INFO: [185] org.ice4j.socket.MergingDatagramSocket.log() Closing.
JVB 2019-09-06 06:07:24.176 INFO: [17] org.jitsi.videobridge.cc.BitrateController.log() new track projection for subjective_quality=0,primary_ssrc=904745427,secondary_ssrcs={183474910=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=904745427,secondary_ssrcs={183474910=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=904745427,secondary_ssrcs={183474910=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=706213895,secondary_ssrcs={3660922434=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=706213895,secondary_ssrcs={3660922434=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=706213895,secondary_ssrcs={3660922434=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=3507740899,secondary_ssrcs={2277118745=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=3507740899,secondary_ssrcs={2277118745=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=3507740899,secondary_ssrcs={2277118745=rtx},temporal_id=2,spatial_id=-1
JVB 2019-09-06 06:07:24.176 WARNING: [17] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 9ab5dc6a not ready yet.
JVB 2019-09-06 06:07:24.176 WARNING: [17] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:24.176 WARNING: [185] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 57951044 not ready yet.
JVB 2019-09-06 06:07:24.176 WARNING: [185] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:24.177 INFO: [185] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=data,ch_id=54deff78185d064e,endp_id=57951044
JVB 2019-09-06 06:07:25.367 INFO: [16] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=39e77ee59c04c9bd conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4
JVB 2019-09-06 06:07:25.386 INFO: [16] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 20ms. Sticky failure: false
JVB 2019-09-06 06:07:29.502 INFO: [187] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=audio,ch_id=e2e9f7d731e54160,endp_id=9ab5dc6a,stream=340185051
JVB 2019-09-06 06:07:29.502 INFO: [187] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=b130deb0e90fead9,content=audio,ch_id=e2e9f7d731e54160,endp_id=9ab5dc6a,stream=340185051 bRecv=0,bSent=0,pRecv=0,pSent=0,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0
JVB 2019-09-06 06:07:29.503 INFO: [187] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=video,ch_id=83c724e3f024da20,endp_id=9ab5dc6a,stream=1363428151
JVB 2019-09-06 06:07:29.503 INFO: [187] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=b130deb0e90fead9,content=video,ch_id=83c724e3f024da20,endp_id=9ab5dc6a,stream=1363428151 bRecv=0,bSent=0,pRecv=0,pSent=0,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0
JVB 2019-09-06 06:07:29.504 INFO: [187] org.ice4j.ice.Agent.log() ICE state changed from Running to Terminated. Local ufrag 4jr621dk2itodc
JVB 2019-09-06 06:07:29.504 WARNING: [357] org.jitsi.videobridge.IceUdpTransportManager.log() Cannot get transport type.
JVB 2019-09-06 06:07:29.504 INFO: [187] org.ice4j.socket.MergingDatagramSocket.log() Closing.
JVB 2019-09-06 06:07:29.504 WARNING: [187] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 4e224569 not ready yet.
JVB 2019-09-06 06:07:29.504 WARNING: [17] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 4e224569 not ready yet.
JVB 2019-09-06 06:07:29.505 WARNING: [187] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:29.505 WARNING: [17] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:29.505 WARNING: [187] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 9ab5dc6a not ready yet.
JVB 2019-09-06 06:07:29.505 WARNING: [187] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can’t send a message
JVB 2019-09-06 06:07:29.505 INFO: [187] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=data,ch_id=29718f39da965401,endp_id=9ab5dc6a
JVB 2019-09-06 06:07:30.953 INFO: [211] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=audio,ch_id=4704d6414c86f441,endp_id=4e224569,stream=1615225255
JVB 2019-09-06 06:07:30.953 INFO: [211] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=b130deb0e90fead9,content=audio,ch_id=4704d6414c86f441,endp_id=4e224569,stream=1615225255 bRecv=0,bSent=0,pRecv=0,pSent=0,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0
JVB 2019-09-06 06:07:30.954 INFO: [211] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=video,ch_id=92c56ff34ae4eee5,endp_id=4e224569,stream=1399953016
JVB 2019-09-06 06:07:30.954 INFO: [211] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=b130deb0e90fead9,content=video,ch_id=92c56ff34ae4eee5,endp_id=4e224569,stream=1399953016 bRecv=0,bSent=0,pRecv=0,pSent=0,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0
JVB 2019-09-06 06:07:30.955 INFO: [211] org.ice4j.ice.Agent.log() ICE state changed from Running to Terminated. Local ufrag 15r6g1dk2ith8s
JVB 2019-09-06 06:07:30.955 INFO: [211] org.ice4j.socket.MergingDatagramSocket.log() Closing.
JVB 2019-09-06 06:07:30.955 INFO: [211] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=b130deb0e90fead9,content=data,ch_id=7e4520a57f26b15a,endp_id=4e224569
JVB 2019-09-06 06:07:30.956 INFO: [336] org.jitsi.videobridge.IceUdpTransportManager.log() Failed to connect IceUdpTransportManager: net.java.sip.communicator.service.protocol.OperationFailedException: TransportManager closed
JVB 2019-09-06 06:07:35.387 INFO: [16] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=462643bbb1adb9dc conf_name=null,logging=false,conf_count=2,ch_count=0,v_streams=0
JVB 2019-09-06 06:07:35.405 INFO: [16] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 18ms. Sticky failure: false

jicofo-log:

Jicofo 2019-09-06 06:06:25.415 INFO: [36] org.jitsi.jicofo.xmpp.BaseBrewery.processInstanceStatusChanged().324 Added brewery instance: jibri_breweryat/jibri-nickname
Jicofo 2019-09-06 06:06:25.415 INFO: [36] org.jitsi.jicofo.recording.jibri.JibriDetector.onInstanceStatusChanged().136 Received Jibri jibri_breweryat/jibri-nickname status
Jicofo 2019-09-06 06:06:25.416 INFO: [36] org.jitsi.jicofo.recording.jibri.JibriDetector.notifyJibriStatus().174 Jibri: jibri_breweryat/jibri-nickname available: true
Jicofo 2019-09-06 06:06:38.615 INFO: [57] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:38.622 INFO: [57] org.jitsi.jicofo.FocusManager.log() Created new focus for blackscreenrecordingatconference.atauth… Conference count 1,options:
Jicofo 2019-09-06 06:06:38.623 INFO: [57] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Lip-sync enabled in blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:38.624 INFO: [57] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Joining the room: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:39.005 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImplat56213c5d member=ChatMember[blackscreenrecordingatconference./4e224569, jid: null]at537877500]
Jicofo 2019-09-06 06:06:39.007 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Granted owner to blackscreenrecordingatconference./4e224569
Jicofo 2019-09-06 06:06:39.007 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member blackscreenrecordingatconference./4e224569 joined.
Jicofo 2019-09-06 06:06:50.520 INFO: [90] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibri_breweryat/jibri-nickname for stream ID: null in room: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:50.529 INFO: [90] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibri_breweryat/jibri-nickname has status pending and failure reason null, current Jibri jid is jibri_breweryat/jibri-nickname
Jicofo 2019-09-06 06:06:50.529 INFO: [90] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibri_breweryat/jibri-nickname
Jicofo 2019-09-06 06:06:50.529 INFO: [90] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Started Jibri session
Jicofo 2019-09-06 06:06:51.446 INFO: [36] org.jitsi.jicofo.recording.jibri.JibriDetector.onInstanceStatusChanged().136 Received Jibri jibri_breweryat/jibri-nickname status
Jicofo 2019-09-06 06:06:51.447 INFO: [36] org.jitsi.jicofo.recording.jibri.JibriDetector.notifyJibriStatus().174 Jibri: jibri_breweryat/jibri-nickname available: false
Jicofo 2019-09-06 06:06:53.202 INFO: [73] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:53.314 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImplat56213c5d member=ChatMember[blackscreenrecordingatconference./57951044, jid: null]at841365743]
Jicofo 2019-09-06 06:06:53.314 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member blackscreenrecordingatconference./57951044 joined.
Jicofo 2019-09-06 06:06:53.327 INFO: [36] org.jitsi.impl.protocol.xmpp.colibri.OperationSetColibriConferenceImpl.log() Conference created: org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImplat461c8acd
Jicofo 2019-09-06 06:06:53.328 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= blackscreenrecordingatconference./57951044, bridge=jitsi-videobridge.
Jicofo 2019-09-06 06:06:53.332 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ff0c0c octo_enabled= false: [[null, null]]
Jicofo 2019-09-06 06:06:53.334 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= blackscreenrecordingatconference./4e224569, bridge=jitsi-videobridge.
Jicofo 2019-09-06 06:06:53.334 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ff0c0c octo_enabled= false: [[null, null, null]]
Jicofo 2019-09-06 06:06:53.699 INFO: [84] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jitsi-videobridge. to allocate channels for: Participant[endpointId=57951044]
Jicofo 2019-09-06 06:06:53.702 INFO: [58] org.jitsi.jicofo.Bridge.log() Adding 1 video streams on jitsi-videobridge. video streams: 0 diff: 1 (estimated: 1)
Jicofo 2019-09-06 06:06:54.089 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from 57951044 with accepted sources:Sources{ }at756700042
Jicofo 2019-09-06 06:06:54.099 WARNING: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No jingle session yet for 4e224569
Jicofo 2019-09-06 06:06:54.221 INFO: [88] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jitsi-videobridge. to allocate channels for: Participant[endpointId=4e224569]
Jicofo 2019-09-06 06:06:54.223 INFO: [58] org.jitsi.jicofo.Bridge.log() Adding 3 video streams on jitsi-videobridge. video streams: 0 diff: 4 (estimated: 4)
Jicofo 2019-09-06 06:06:54.753 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: for blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:54.753 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibri_breweryat/jibri-nickname has status on and failure reason null, current Jibri jid is jibri_breweryat/jibri-nickname
Jicofo 2019-09-06 06:06:54.753 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
Jicofo 2019-09-06 06:06:54.753 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri session started, notifying owner
Jicofo 2019-09-06 06:06:54.753 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Got jibri status on and failure null
Jicofo 2019-09-06 06:06:54.754 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Publishing new jibri-recording-status: in: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:06:55.408 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from 4e224569 with accepted sources:Sources{ video: [ssrc=904745427 ssrc=183474910 ssrc=706213895 ssrc=3507740899 ssrc=3660922434 ssrc=2277118745 ] audio: [ssrc=4041760526 ] }at163445759
Jicofo 2019-09-06 06:06:55.414 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC blackscreenrecordingatconference./57951044 SID: 53s289vc81kmb Sources{ video: [ssrc=904745427 ssrc=183474910 ssrc=706213895 ssrc=3507740899 ssrc=3660922434 ssrc=2277118745 ] audio: [ssrc=4041760526 ] }at945395219 source_Groups{ video:[ SourceGroup(FID)[ ssrc=904745427 ssrc=183474910 ]SourceGroup(FID)[ ssrc=706213895 ssrc=3660922434 ]SourceGroup(FID)[ ssrc=3507740899 ssrc=2277118745 ]SourceGroup(SIM)[ ssrc=904745427 ssrc=706213895 ssrc=3507740899 ] ] }at148184650
Jicofo 2019-09-06 06:07:00.161 INFO: [75] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:07:00.591 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImplat56213c5d member=ChatMember[blackscreenrecordingatconference./9ab5dc6a, jid: null]at987497169]
Jicofo 2019-09-06 06:07:00.591 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member blackscreenrecordingatconference./9ab5dc6a joined.
Jicofo 2019-09-06 06:07:00.591 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= blackscreenrecordingatconference./9ab5dc6a, bridge=jitsi-videobridge.
Jicofo 2019-09-06 06:07:00.591 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ff0c0c octo_enabled= false: [[null, null, null, null]]
Jicofo 2019-09-06 06:07:01.544 INFO: [93] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jitsi-videobridge. to allocate channels for: Participant[endpointId=9ab5dc6a]
Jicofo 2019-09-06 06:07:01.544 INFO: [58] org.jitsi.jicofo.Bridge.log() Adding 5 video streams on jitsi-videobridge. video streams: 0 diff: 9 (estimated: 9)
Jicofo 2019-09-06 06:07:03.072 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from 9ab5dc6a with accepted sources:Sources{ video: [ssrc=3281319453 ssrc=2306062248 ssrc=712201114 ssrc=3522972069 ssrc=4130210331 ssrc=1682206006 ] audio: [ssrc=1047212602 ] }at52197616
Jicofo 2019-09-06 06:07:03.074 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC blackscreenrecordingatconference./57951044 SID: 53s289vc81kmb Sources{ video: [ssrc=3281319453 ssrc=2306062248 ssrc=712201114 ssrc=3522972069 ssrc=4130210331 ssrc=1682206006 ] audio: [ssrc=1047212602 ] }at588976535 source_Groups{ video:[ SourceGroup(FID)[ ssrc=3281319453 ssrc=2306062248 ]SourceGroup(FID)[ ssrc=712201114 ssrc=4130210331 ]SourceGroup(FID)[ ssrc=3522972069 ssrc=1682206006 ]SourceGroup(SIM)[ ssrc=3281319453 ssrc=712201114 ssrc=3522972069 ] ] }at2030785967
Jicofo 2019-09-06 06:07:03.077 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendAddSourceIQ().478 Notify add SSRC blackscreenrecordingatconference./4e224569 SID: aem1qa2ujt4ub Sources{ video: [ssrc=3281319453 ssrc=2306062248 ssrc=712201114 ssrc=3522972069 ssrc=4130210331 ssrc=1682206006 ] audio: [ssrc=1047212602 ] }at588976535 source_Groups{ video:[ SourceGroup(FID)[ ssrc=3281319453 ssrc=2306062248 ]SourceGroup(FID)[ ssrc=712201114 ssrc=4130210331 ]SourceGroup(FID)[ ssrc=3522972069 ssrc=1682206006 ]SourceGroup(SIM)[ ssrc=3281319453 ssrc=712201114 ssrc=3522972069 ] ] }at2030785967
Jicofo 2019-09-06 06:07:23.594 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: for blackscreenrecordingatconference.
Jicofo 2019-09-06 06:07:23.594 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibri_breweryat/jibri-nickname has status off and failure reason error, current Jibri jid is jibri_breweryat/jibri-nickname
Jicofo 2019-09-06 06:07:23.594 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri failed, trying to fall back to another Jibri
Jicofo 2019-09-06 06:07:23.595 SEVERE: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unable to find an available Jibri, can’t start
Jicofo 2019-09-06 06:07:23.595 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Failed to fall back to another Jibri, this session has now failed
Jicofo 2019-09-06 06:07:23.595 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Got jibri status off and failure error
Jicofo 2019-09-06 06:07:23.595 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Publishing new jibri-recording-status: in: blackscreenrecordingatconference.
Jicofo 2019-09-06 06:07:23.595 INFO: [89] org.jitsi.jicofo.recording.jibri.JibriSession.log() Cleaning up current JibriSession
Jicofo 2019-09-06 06:07:24.166 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImplat56213c5d member=ChatMember[blackscreenrecordingatconference./57951044, jid: null]at841365743]
Jicofo 2019-09-06 06:07:24.166 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member blackscreenrecordingatconference./57951044 is leaving
Jicofo 2019-09-06 06:07:24.166 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Terminating: blackscreenrecordingatconference./57951044
Jicofo 2019-09-06 06:07:24.167 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.terminateSession().620 Terminate session: blackscreenrecordingatconference./57951044
Jicofo 2019-09-06 06:07:24.168 WARNING: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No sources or groups to be removed from: blackscreenrecordingatconference./57951044
Jicofo 2019-09-06 06:07:24.168 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ff0c0c octo_enabled= false: [[null, null, null]]
Jicofo 2019-09-06 06:07:24.168 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: blackscreenrecordingatconference./57951044 on: Bridge[jid=jitsi-videobridge., relayId=null, region=null]
Jicofo 2019-09-06 06:07:24.169 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, blackscreenrecordingatconference./57951044
Jicofo 2019-09-06 06:07:24.170 INFO: [58] org.jitsi.jicofo.Bridge.log() Removing 5 video streams on jitsi-videobridge. video streams: 0 diff: 4 (estimated: 4)
Jicofo 2019-09-06 06:07:24.303 INFO: [36] org.jitsi.jicofo.recording.jibri.JibriDetector.onInstanceStatusChanged().136 Received Jibri jibri_breweryat/jibri-nickname status
Jicofo 2019-09-06 06:07:24.303 INFO: [36] org.jitsi.jicofo.recording.jibri.JibriDetector.notifyJibriStatus().174 Jibri: jibri_breweryat/jibri-nickname available: true
Jicofo 2019-09-06 06:07:29.452 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImplat56213c5d member=ChatMember[blackscreenrecordingatconference./9ab5dc6a, jid: null]at987497169]
Jicofo 2019-09-06 06:07:29.453 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member blackscreenrecordingatconference./9ab5dc6a is leaving
Jicofo 2019-09-06 06:07:29.453 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Terminating: blackscreenrecordingatconference./9ab5dc6a
Jicofo 2019-09-06 06:07:29.453 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.terminateSession().620 Terminate session: blackscreenrecordingatconference./9ab5dc6a
Jicofo 2019-09-06 06:07:29.455 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removing blackscreenrecordingatconference./9ab5dc6a sources Sources{ video: [ssrc=3281319453 ssrc=2306062248 ssrc=712201114 ssrc=3522972069 ssrc=4130210331 ssrc=1682206006 ] audio: [ssrc=1047212602 ] }at648019342
Jicofo 2019-09-06 06:07:29.456 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.sendRemoveSourceIQ().581 Notify remove SSRC blackscreenrecordingatconference./4e224569 SID: aem1qa2ujt4ub Sources{ video: [ssrc=3281319453 ssrc=2306062248 ssrc=712201114 ssrc=3522972069 ssrc=4130210331 ssrc=1682206006 ] audio: [ssrc=1047212602 ] }at648019342 source_Groups{ video:[ SourceGroup(FID)[ ssrc=3281319453 ssrc=2306062248 ]SourceGroup(FID)[ ssrc=712201114 ssrc=4130210331 ]SourceGroup(FID)[ ssrc=3522972069 ssrc=1682206006 ]SourceGroup(SIM)[ ssrc=3281319453 ssrc=712201114 ssrc=3522972069 ] ] }at572848915
Jicofo 2019-09-06 06:07:29.456 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ff0c0c octo_enabled= false: [[null, null]]
Jicofo 2019-09-06 06:07:29.457 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: blackscreenrecordingatconference./9ab5dc6a on: Bridge[jid=jitsi-videobridge., relayId=null, region=null]
Jicofo 2019-09-06 06:07:29.458 INFO: [58] org.jitsi.jicofo.Bridge.log() Removing 3 video streams on jitsi-videobridge. video streams: 0 diff: 1 (estimated: 1)
Jicofo 2019-09-06 06:07:29.458 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, blackscreenrecordingatconference./9ab5dc6a
Jicofo 2019-09-06 06:07:30.944 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImplat56213c5d member=ChatMember[blackscreenrecordingatconference./4e224569, jid: 4e224569-6008-44ff-8f49-0fc8048398dcat/e310362a-f457-4d77-ada8-3b275cb0870c]at537877500]
Jicofo 2019-09-06 06:07:30.944 INFO: [36] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Owner has left the room !
Jicofo 2019-09-06 06:07:30.944 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member blackscreenrecordingatconference./4e224569 is leaving
Jicofo 2019-09-06 06:07:30.944 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Terminating: blackscreenrecordingatconference./4e224569
Jicofo 2019-09-06 06:07:30.944 INFO: [36] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.terminateSession().620 Terminate session: blackscreenrecordingatconference./4e224569
Jicofo 2019-09-06 06:07:30.945 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removing blackscreenrecordingatconference./4e224569 sources Sources{ video: [ssrc=904745427 ssrc=183474910 ssrc=706213895 ssrc=3507740899 ssrc=3660922434 ssrc=2277118745 ] audio: [ssrc=4041760526 ] }at466320963
Jicofo 2019-09-06 06:07:30.945 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ff0c0c octo_enabled= false: [[null]]
Jicofo 2019-09-06 06:07:30.945 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: blackscreenrecordingatconference./4e224569 on: Bridge[jid=jitsi-videobridge., relayId=null, region=null]
Jicofo 2019-09-06 06:07:30.946 INFO: [58] org.jitsi.jicofo.Bridge.log() Removing 1 video streams on jitsi-videobridge. video streams: 0 diff: 0 (estimated: 0)
Jicofo 2019-09-06 06:07:30.946 INFO: [36] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, blackscreenrecordingatconference./4e224569
Jicofo 2019-09-06 06:07:30.949 INFO: [36] org.jitsi.jicofo.FocusManager.log() Disposed conference for room: blackscreenrecordingatconference. conference count: 0

jibri-log:

2019-09-06 06:06:23.717 INFO: [1] org.jitsi.jibri.Main.main() Jibri run with args [–config, /etc/jitsi/jibri/config.json]
2019-09-06 06:06:23.722 INFO: [1] org.jitsi.jibri.Main.main() Using config file /etc/jitsi/jibri/config.json
2019-09-06 06:06:23.723 INFO: [1] org.jitsi.jibri.Main.main() Using port 3333 for internal HTTP API
2019-09-06 06:06:23.723 INFO: [1] org.jitsi.jibri.Main.main() Using port 2222 for the HTTP API
2019-09-06 06:06:24.345 INFO: [1] org.jitsi.jibri.Main.loadConfig() Parsed config:
JibriConfig(recordingDirectory=/opt/records, enabledStatsD=true, finalizeRecordingScriptPath=/opt/finalize_recording.sh, xmppEnvironments=[XmppEnvironmentConfig(name=prod environment, xmppServerHosts=, xmppDomain=, controlLogin=XmppCredentials(domain=auth., username=jibri_user, password=), controlMuc=XmppMuc(domain=internal.auth., roomName=jibri_brewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=, username=recorder_jibri, password=), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)])
2019-09-06 06:06:24.858 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.
2019-09-06 06:06:25.085 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
2019-09-06 06:06:25.087 INFO: [1] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@31be6b49
2019-09-06 06:06:25.093 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() Connecting to xmpp environment on with config XmppEnvironmentConfig(name=prod environment, xmppServerHosts=, xmppDomain=, controlLogin=XmppCredentials(domain=auth., username=jibri_user, password=), controlMuc=XmppMuc(domain=internal.auth., roomName=jibri_brewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=, username=recorder_jibri, password=), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)
2019-09-06 06:06:25.094 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
2019-09-06 06:06:25.111 WARNING: [20] org.jitsi.xmpp.mucclient.MucClient.log() Disabling certificate verification!
2019-09-06 06:06:25.156 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.
2019-09-06 06:06:25.343 INFO: [20] org.jitsi.xmpp.mucclient.MucClient.log() [MucClient id= hostname=] connected
2019-09-06 06:06:25.415 INFO: [20] org.jitsi.xmpp.mucclient.MucClient.log() Joined MUC: jibri_breweryatinternal.auth.
2019-09-06 06:06:50.528 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq from environment [MucClient id= hostname=]
2019-09-06 06:06:50.529 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request
2019-09-06 06:06:50.532 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending ‘pending’ response to start IQ
2019-09-06 06:06:50.532 INFO: [35] org.jitsi.jibri.api.xmpp.XmppApi.run() Starting service
2019-09-06 06:06:50.563 INFO: [35] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://, callName=blackscreenrecording, urlParams=)
2019-09-06 06:06:50.565 INFO: [35] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://, callName=blackscreenrecording, urlParams=)), sessionId=scgcvtecfwncpqjv, callLoginParams=XmppCredentials(domain=, username=recorder_jibri, password=)) finalize script path: /opt/finalize_recording.sh and recordings directory: /opt/records
2019-09-06 06:06:51.408 INFO: [35] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
2019-09-06 06:06:51.436 FINE: [35] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.() Detected os as OS: LINUX
2019-09-06 06:06:51.443 INFO: [35] org.jitsi.jibri.service.impl.FileRecordingJibriService.() Writing recording to /opt/records/scgcvtecfwncpqjv
2019-09-06 06:06:51.444 FINE: [35] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
2019-09-06 06:06:51.445 INFO: [35] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
2019-09-06 06:06:51.445 INFO: [35] 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
2019-09-06 06:06:51.446 INFO: [35] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@2a7682b
2019-09-06 06:06:52.188 FINE: [45] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url https:///blackscreenrecording#config.iAmRecorder=true&config.externalConnectUrl=null&config.startWithAudioMuted=true&config.startWithVideoMuted=true&interfaceConfig.APP_NAME=“Jibri”&config.analytics.disabled=true
2019-09-06 06:06:53.565 INFO: [45] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Waited 1032 milliseconds for call page to load
2019-09-06 06:06:53.575 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Running
2019-09-06 06:06:53.576 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.invoke() Selenium joined the call, starting the capturer
2019-09-06 06:06:53.599 INFO: [45] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.launch() Starting ffmpeg with command ffmpeg -y -v info -f x11grab -draw_mouse 0 -r 30 -s 1280x720 -thread_queue_size 4096 -i :0.0+0,0 -f alsa -thread_queue_size 4096 -i plug:cloop -acodec aac -strict -2 -ar 44100 -c:v libx264 -preset veryfast -profile:v main -level 3.1 -pix_fmt yuv420p -r 30 -crf 25 -g 60 -tune zerolatency -f mp4 /opt/records/scgcvtecfwncpqjv/blackscreenrecording_2019-09-06-06-06-51.mp4 ([ffmpeg, -y, -v, info, -f, x11grab, -draw_mouse, 0, -r, 30, -s, 1280x720, -thread_queue_size, 4096, -i, :0.0+0,0, -f, alsa, -thread_queue_size, 4096, -i, plug:cloop, -acodec, aac, -strict, -2, -ar, 44100, -c:v, libx264, -preset, veryfast, -profile:v, main, -level, 3.1, -pix_fmt, yuv420p, -r, 30, -crf, 25, -g, 60, -tune, zerolatency, -f, mp4, /opt/records/scgcvtecfwncpqjv/blackscreenrecording_2019-09-06-06-06-51.mp4])
2019-09-06 06:06:54.753 INFO: [49] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Starting up to Running
2019-09-06 06:06:54.754 INFO: [49] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Running
2019-09-06 06:06:54.755 INFO: [49] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service started up successfully, sending on iq
2019-09-06 06:07:08.625 INFO: [46] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=0, upload=0}, download=0, upload=0, video={download=0, upload=0}}, all clients muted? false
2019-09-06 06:07:23.594 INFO: [46] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=0, upload=0}, download=0, upload=0, video={download=0, upload=0}}, all clients muted? false
2019-09-06 06:07:23.595 INFO: [46] org.jitsi.jibri.selenium.JibriSelenium.invoke() Recurring call status checks generated event org.jitsi.jibri.selenium.SeleniumEvent$NoMediaReceived@30f0c905
2019-09-06 06:07:23.596 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Running to Error: SESSION No media received
2019-09-06 06:07:23.596 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Running to Error: SESSION No media received
2019-09-06 06:07:23.596 INFO: [45] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service had an error, sending error iq
2019-09-06 06:07:23.597 FINE: [45] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
2019-09-06 06:07:23.597 INFO: [45] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2019-09-06 06:07:23.598 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
2019-09-06 06:07:23.598 INFO: [45] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
2019-09-06 06:07:24.006 INFO: [49] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Running to Finished
2019-09-06 06:07:24.007 INFO: [45] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value 255
2019-09-06 06:07:24.007 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
2019-09-06 06:07:24.017 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording:
2019-09-06 06:07:24.070 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 48 log entries for type browser
2019-09-06 06:07:24.129 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 830 log entries for type driver
2019-09-06 06:07:24.159 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
2019-09-06 06:07:24.159 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
2019-09-06 06:07:24.227 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
2019-09-06 06:07:24.301 INFO: [45] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Chrome driver quit
2019-09-06 06:07:24.302 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Finalizing the recording
2019-09-06 06:07:24.304 INFO: [45] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Recording finalize script finished with exit value 0
2019-09-06 06:07:24.305 INFO: [45] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: BUSY -> IDLE
2019-09-06 06:07:24.305 INFO: [45] 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
2019-09-06 06:07:24.305 INFO: [45] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@5f1b4316

ffmpeg-log:

ffmpeg:
2019-09-06 06:06:53.663 INFO: [50] ffmpeg.call() ffmpeg version 3.4.6-0ubuntu0.18.04.1 Copyright © 2000-2019 the FFmpeg developers
2019-09-06 06:06:53.663 INFO: [50] ffmpeg.call() built with gcc 7 (Ubuntu 7.3.0-16ubuntu3)
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() configuration: --prefix=/usr --extra-version=0ubuntu0.18.04.1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --enable-gpl --disable-stripping --enable-avresample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librubberband --enable-librsvg --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzmq --enable-libzvbi --enable-omx --enable-openal --enable-opengl --enable-sdl2 --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libopencv --enable-libx264 --enable-shared
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libavutil 55. 78.100 / 55. 78.100
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libavcodec 57.107.100 / 57.107.100
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libavformat 57. 83.100 / 57. 83.100
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libavdevice 57. 10.100 / 57. 10.100
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libavfilter 6.107.100 / 6.107.100
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libavresample 3. 7. 0 / 3. 7. 0
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libswscale 4. 8.100 / 4. 8.100
2019-09-06 06:06:53.736 INFO: [50] ffmpeg.call() libswresample 2. 9.100 / 2. 9.100
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() libpostproc 54. 7.100 / 54. 7.100
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() [x11grab @ 0x55b541f37f00] Stream #0: not enough frames to estimate rate; consider increasing probesize
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() Input #0, x11grab, from ‘:0.0+0,0’:
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() Duration: N/A, start: 1567750013.693125, bitrate: N/A
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() Stream #0:0: Video: rawvideo (BGR[0] / 0x524742), bgr0, 1280x720, 30 fps, 1000k tbr, 1000k tbn, 1000k tbc
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() Guessed Channel Layout for Input Stream #1.0 : stereo
2019-09-06 06:06:53.737 INFO: [50] ffmpeg.call() Input #1, alsa, from ‘plug:cloop’:
2019-09-06 06:06:53.751 INFO: [50] ffmpeg.call() Duration: N/A, start: 1567750013.355406, bitrate: 1536 kb/s
2019-09-06 06:06:53.751 INFO: [50] ffmpeg.call() Stream #1:0: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() Stream mapping:
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() Stream #0:0 -> #0:0 (rawvideo (native) -> h264 (libx264))
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() Stream #1:0 -> #0:1 (pcm_s16le (native) -> aac (native))
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() Press [q] to stop, [?] for help
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] profile Main, level 3.1
2019-09-06 06:06:53.752 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] 264 - core 152 r2854 e9a5903 - H.264/MPEG-4 AVC codec - Copyleft 2003-2017 - options: cabac=1 ref=1 deblock=1:0:0 analyse=0x1:0x111 me=hex subme=2 psy=1 psy_rd=1.00:0.00 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=0 threads=4 lookahead_threads=4 sliced_threads=1 slices=4 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=1 keyint=60 keyint_min=6 scenecut=40 intra_refresh=0 rc=crf mbtree=0 crf=25.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
2019-09-06 06:06:54.752 INFO: [50] ffmpeg.call() Output #0, mp4, to ‘/opt/records/scgcvtecfwncpqjv/blackscreenrecording_2019-09-06-06-06-51.mp4’:
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() Metadata:
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() encoder : Lavf57.83.100
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() Stream #0:0: Video: h264 (libx264) (avc1 / 0x31637661), yuv420p(progressive), 1280x720, q=-1–1, 30 fps, 15360 tbn, 30 tbc
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() Metadata:
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() encoder : Lavc57.107.100 libx264
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() Side data:
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() cpb: bitrate max/min/avg: 0/0/0 buffer size: 0 vbv_delay: -1
2019-09-06 06:06:54.753 INFO: [50] ffmpeg.call() Stream #0:1: Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 128 kb/s
2019-09-06 06:06:54.754 INFO: [50] ffmpeg.call() Metadata:
2019-09-06 06:06:54.754 INFO: [50] ffmpeg.call() encoder : Lavc57.107.100 aac
2019-09-06 06:06:54.754 INFO: [50] ffmpeg.call() frame= 14 fps=0.0 q=21.0 size= 0kB time=00:00:00.44 bitrate= 0.9kbits/s speed=0.875x
2019-09-06 06:06:54.754 INFO: [50] ffmpeg.call() frame= 29 fps= 29 q=21.0 size= 0kB time=00:00:00.95 bitrate= 0.4kbits/s speed=0.946x
2019-09-06 06:06:55.754 INFO: [50] ffmpeg.call() frame= 44 fps= 29 q=21.0 size= 0kB time=00:00:01.44 bitrate= 0.3kbits/s speed=0.954x
2019-09-06 06:06:56.755 INFO: [50] ffmpeg.call() frame= 59 fps= 29 q=22.0 size= 0kB time=00:00:01.95 bitrate= 0.2kbits/s speed=0.966x
2019-09-06 06:06:56.755 INFO: [50] ffmpeg.call() frame= 75 fps= 30 q=21.0 size= 0kB time=00:00:02.46 bitrate= 0.2kbits/s speed=0.978x
2019-09-06 06:06:57.755 INFO: [50] ffmpeg.call() frame= 89 fps= 29 q=21.0 size= 0kB time=00:00:02.97 bitrate= 0.1kbits/s speed=0.983x
2019-09-06 06:06:57.755 INFO: [50] ffmpeg.call() frame= 105 fps= 30 q=21.0 size= 0kB time=00:00:03.48 bitrate= 0.1kbits/s speed=0.985x
2019-09-06 06:06:58.756 INFO: [50] ffmpeg.call() frame= 120 fps= 30 q=22.0 size= 0kB time=00:00:03.99 bitrate= 0.1kbits/s speed=0.989x
2019-09-06 06:06:58.756 INFO: [50] ffmpeg.call() frame= 135 fps= 30 q=21.0 size= 0kB time=00:00:04.48 bitrate= 0.1kbits/s speed=0.986x
2019-09-06 06:06:59.756 INFO: [50] ffmpeg.call() frame= 151 fps= 30 q=21.0 size= 0kB time=00:00:05.00 bitrate= 0.1kbits/s speed=0.991x
2019-09-06 06:06:59.756 INFO: [50] ffmpeg.call() frame= 165 fps= 30 q=21.0 size= 0kB time=00:00:05.48 bitrate= 0.1kbits/s speed=0.987x
2019-09-06 06:07:00.757 INFO: [50] ffmpeg.call() frame= 181 fps= 30 q=21.0 size= 0kB time=00:00:06.00 bitrate= 0.1kbits/s speed=0.991x
2019-09-06 06:07:00.757 INFO: [50] ffmpeg.call() frame= 196 fps= 30 q=21.0 size= 0kB time=00:00:06.50 bitrate= 0.1kbits/s speed=0.992x
2019-09-06 06:07:01.757 INFO: [50] ffmpeg.call() frame= 211 fps= 30 q=21.0 size= 0kB time=00:00:07.01 bitrate= 0.1kbits/s speed=0.993x
2019-09-06 06:07:01.757 INFO: [50] ffmpeg.call() frame= 226 fps= 30 q=21.0 size= 0kB time=00:00:07.52 bitrate= 0.1kbits/s speed=0.995x
2019-09-06 06:07:02.758 INFO: [50] ffmpeg.call() frame= 241 fps= 30 q=21.0 size= 0kB time=00:00:08.01 bitrate= 0.0kbits/s speed=0.992x
2019-09-06 06:07:02.758 INFO: [50] ffmpeg.call() frame= 256 fps= 30 q=21.0 size= 0kB time=00:00:08.52 bitrate= 0.0kbits/s speed=0.993x
2019-09-06 06:07:03.758 INFO: [50] ffmpeg.call() frame= 271 fps= 30 q=21.0 size= 0kB time=00:00:09.03 bitrate= 0.0kbits/s speed=0.994x
2019-09-06 06:07:03.758 INFO: [50] ffmpeg.call() frame= 286 fps= 30 q=21.0 size= 0kB time=00:00:09.54 bitrate= 0.0kbits/s speed=0.995x
2019-09-06 06:07:04.759 INFO: [50] ffmpeg.call() frame= 302 fps= 30 q=21.0 size= 0kB time=00:00:10.03 bitrate= 0.0kbits/s speed=0.993x
2019-09-06 06:07:04.759 INFO: [50] ffmpeg.call() frame= 317 fps= 30 q=21.0 size= 0kB time=00:00:10.54 bitrate= 0.0kbits/s speed=0.994x
2019-09-06 06:07:05.759 INFO: [50] ffmpeg.call() frame= 332 fps= 30 q=21.0 size= 0kB time=00:00:11.05 bitrate= 0.0kbits/s speed=0.995x
2019-09-06 06:07:05.759 INFO: [50] ffmpeg.call() frame= 347 fps= 30 q=21.0 size= 0kB time=00:00:11.54 bitrate= 0.0kbits/s speed=0.994x
2019-09-06 06:07:06.760 INFO: [50] ffmpeg.call() frame= 362 fps= 30 q=21.0 size= 0kB time=00:00:12.05 bitrate= 0.0kbits/s speed=0.995x
2019-09-06 06:07:06.760 INFO: [50] ffmpeg.call() frame= 377 fps= 30 q=21.0 size= 0kB time=00:00:12.56 bitrate= 0.0kbits/s speed=0.996x
2019-09-06 06:07:07.760 INFO: [50] ffmpeg.call() frame= 392 fps= 30 q=21.0 size= 0kB time=00:00:13.07 bitrate= 0.0kbits/s speed=0.996x
2019-09-06 06:07:07.760 INFO: [50] ffmpeg.call() frame= 408 fps= 30 q=21.0 size= 0kB time=00:00:13.58 bitrate= 0.0kbits/s speed=0.996x
2019-09-06 06:07:08.761 INFO: [50] ffmpeg.call() frame= 423 fps= 30 q=21.0 size= 0kB time=00:00:14.07 bitrate= 0.0kbits/s speed=0.995x
2019-09-06 06:07:08.761 INFO: [50] ffmpeg.call() frame= 438 fps= 30 q=21.0 size= 0kB time=00:00:14.58 bitrate= 0.0kbits/s speed=0.995x
2019-09-06 06:07:09.761 INFO: [50] ffmpeg.call() frame= 454 fps= 30 q=21.0 size= 0kB time=00:00:15.11 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:09.761 INFO: [50] ffmpeg.call() frame= 469 fps= 30 q=21.0 size= 0kB time=00:00:15.60 bitrate= 0.0kbits/s speed=0.996x
2019-09-06 06:07:10.762 INFO: [50] ffmpeg.call() frame= 484 fps= 30 q=21.0 size= 0kB time=00:00:16.11 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:10.762 INFO: [50] ffmpeg.call() frame= 499 fps= 30 q=21.0 size= 0kB time=00:00:16.60 bitrate= 0.0kbits/s speed=0.996x
2019-09-06 06:07:11.762 INFO: [50] ffmpeg.call() frame= 514 fps= 30 q=21.0 size= 0kB time=00:00:17.11 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:11.762 INFO: [50] ffmpeg.call() frame= 529 fps= 30 q=21.0 size= 0kB time=00:00:17.62 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:12.763 INFO: [50] ffmpeg.call() frame= 544 fps= 30 q=21.0 size= 0kB time=00:00:18.13 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:12.763 INFO: [50] ffmpeg.call() frame= 560 fps= 30 q=21.0 size= 0kB time=00:00:18.64 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:13.763 INFO: [50] ffmpeg.call() frame= 575 fps= 30 q=21.0 size= 0kB time=00:00:19.13 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:13.763 INFO: [50] ffmpeg.call() frame= 590 fps= 30 q=21.0 size= 0kB time=00:00:19.64 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:14.764 INFO: [50] ffmpeg.call() frame= 605 fps= 30 q=21.0 size= 0kB time=00:00:20.15 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:14.764 INFO: [50] ffmpeg.call() frame= 620 fps= 30 q=21.0 size= 0kB time=00:00:20.64 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:15.764 INFO: [50] ffmpeg.call() frame= 635 fps= 30 q=21.0 size= 0kB time=00:00:21.15 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:15.764 INFO: [50] ffmpeg.call() frame= 651 fps= 30 q=21.0 size= 0kB time=00:00:21.66 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:16.765 INFO: [50] ffmpeg.call() frame= 666 fps= 30 q=21.0 size= 0kB time=00:00:22.17 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:16.765 INFO: [50] ffmpeg.call() frame= 681 fps= 30 q=21.0 size= 0kB time=00:00:22.68 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:17.765 INFO: [50] ffmpeg.call() frame= 696 fps= 30 q=21.0 size= 0kB time=00:00:23.19 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:17.765 INFO: [50] ffmpeg.call() frame= 711 fps= 30 q=21.0 size= 0kB time=00:00:23.68 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:18.766 INFO: [50] ffmpeg.call() frame= 726 fps= 30 q=21.0 size= 0kB time=00:00:24.19 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:18.766 INFO: [50] ffmpeg.call() frame= 741 fps= 30 q=21.0 size= 0kB time=00:00:24.70 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:19.766 INFO: [50] ffmpeg.call() frame= 757 fps= 30 q=21.0 size= 0kB time=00:00:25.21 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:19.766 INFO: [50] ffmpeg.call() frame= 772 fps= 30 q=21.0 size= 0kB time=00:00:25.70 bitrate= 0.0kbits/s speed=0.997x
2019-09-06 06:07:20.767 INFO: [50] ffmpeg.call() frame= 787 fps= 30 q=21.0 size= 0kB time=00:00:26.21 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:20.767 INFO: [50] ffmpeg.call() frame= 802 fps= 30 q=21.0 size= 0kB time=00:00:26.72 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:21.767 INFO: [50] ffmpeg.call() frame= 817 fps= 30 q=21.0 size= 0kB time=00:00:27.24 bitrate= 0.0kbits/s speed=0.999x
2019-09-06 06:07:21.767 INFO: [50] ffmpeg.call() frame= 833 fps= 30 q=21.0 size= 0kB time=00:00:27.73 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:22.768 INFO: [50] ffmpeg.call() frame= 847 fps= 30 q=21.0 size= 0kB time=00:00:28.23 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:22.768 INFO: [50] ffmpeg.call() frame= 863 fps= 30 q=21.0 size= 0kB time=00:00:28.74 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() frame= 878 fps= 30 q=21.0 size= 0kB time=00:00:29.25 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() frame= 893 fps= 30 q=21.0 size= 0kB time=00:00:29.74 bitrate= 0.0kbits/s speed=0.998x
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() frame= 895 fps= 30 q=21.0 Lsize= 207kB time=00:00:29.86 bitrate= 56.8kbits/s speed=0.999x
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() video:146kB audio:22kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 22.677687%
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] frame I:15 Avg QP: 3.69 size: 3624
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] frame P:880 Avg QP: 6.40 size: 108
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] mb I I16…4: 97.7% 0.0% 2.3%
2019-09-06 06:07:23.632 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] mb P I16…4: 0.1% 0.0% 0.0% P16…4: 0.0% 0.0% 0.0% 0.0% 0.0% skip:99.8%
2019-09-06 06:07:23.633 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] coded y,uvDC,uvAC intra: 1.6% 1.5% 1.3% inter: 0.0% 0.0% 0.0%
2019-09-06 06:07:23.633 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] i16 v,h,dc,p: 90% 1% 9% 0%
2019-09-06 06:07:23.633 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 32% 17% 32% 3% 2% 3% 3% 4% 4%
2019-09-06 06:07:23.633 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] i8c dc,h,v,p: 99% 1% 1% 0%
2019-09-06 06:07:24.006 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] Weighted P-Frames: Y:0.1% UV:0.0%
2019-09-06 06:07:24.006 INFO: [50] ffmpeg.call() [libx264 @ 0x55b541f6d020] kb/s:40.02
2019-09-06 06:07:24.006 INFO: [50] ffmpeg.call() [aac @ 0x55b541f713c0] Qavg: 63742.801
2019-09-06 06:07:24.006 INFO: [50] ffmpeg.call() Exiting normally, received signal 2.

recorded video is same
thanks

bbaldino · September 6, 2019, 4:39pm

I think ICE is failing. What’s the IP of your Jibri machine?

sobish · September 11, 2019, 5:07am

35.176.223.237
it is connected through domain name

bbaldino · September 11, 2019, 5:30am

I don’t see that IP anywhere in the bridge logs above. Maybe it was a different address (an internal ip or something?) or the wrong jibri. but from the bridge logs i think it may be an ice failure. do you have stun/turn setup?

sobish · September 11, 2019, 7:44am

my servers are hosted at aws
jibri config:

{
// NOTE: this is a SAMPLE config file, it will need to be configured with
// values from your environment
// Where recording files should be temporarily stored
“recording_directory”:"/usr/jibri/records",
// The path to the script which will be run on completed recordings
“finalize_recording_script_path”: “/usr/jibri/finalize_recording.sh”,
“xmpp_environments”: [
{
// A friendly name for this environment which can be used
// for logging, stats, etc.
“name”: “prod environment”,
// The hosts of the XMPP servers to connect to as part of
// this environment
“xmpp_server_hosts”: [
“my-jitsi-meet-domain-address”
],
// The xmpp domain we’ll connect to on the XMPP server
“xmpp_domain”: “my-jitsi-meet-domain-address”,
// Jibri will login to the xmpp server as a privileged user
“control_login”: {
// The domain to use for logging in
“domain”: “auth.my-jitsi-meet-domain-address”,
// The credentials for logging in
“username”: “jibri_user”,
“password”: “”
},
// Using the control_login information above, Jibri will join
// a control muc as a means of announcing its availability
// to provide services for a given environment
“control_muc”: {
“domain”: “internal.auth.my-jitsi-meet-domain-address”,
“room_name”: “jibri_brewery”,
“nickname”: “jibri-nickname”
},
// All participants in a call join a muc so they can exchange
// information. Jibri can be instructed to join a special muc
// with credentials to give it special abilities (e.g. not being
// displayed to other users like a normal participant)
“call_login”: {
“domain”: “my-jibri-domain-address”,
“username”: “recorder_jibri”,
“password”: “”
},
// When jibri gets a request to start a service for a room, the room
// jid will look like:
// roomName@optional.prefixes.subdomain.xmpp_domain
// We’ll build the url for the call by transforming that into:
// https://xmpp_domain/subdomain/roomName
// So if there are any prefixes in the jid (like jitsi meet, which
// has its participants join a muc at conference.xmpp_domain) then
// list that prefix here so it can be stripped out to generate
// the call url correctly
“room_jid_domain_string_to_strip_from_start”: “conference.”,
// The amount of time, in minutes, a service is allowed to continue.
// Once a service has been running for this long, it will be
// stopped (cleanly). A value of 0 means an indefinite amount
// of time is allowed
“usage_timeout”: “0”
}
]
}

sobish · September 12, 2019, 6:00am

is there any paid service to resolve this issue?
thanks

bbaldino · September 12, 2019, 4:52pm

See my question above. Do you have STUN/TURN configured on your jitsi-meet instance? If not then it’s possible clients could fail to connect, which would cause the ICE failures I mentioned above.

sobish · September 13, 2019, 5:00am

do I need to setup the stun/turn servers? will it not use the google stunServer mention in config of jitsi-meet?
jitsi-meet running with default settings.

bbaldino · September 13, 2019, 3:53pm

It’ll use google’s stun by default, i think? but not turn. stun isn’t always enough.

sobish · September 16, 2019, 5:38am

how to enable turn server? can you guide in details? thanks

damencho · September 16, 2019, 9:10am

@sobish check Turn Server and the links there have examples and what is needed.

sobish · September 19, 2019, 1:10pm

finally I have my own coturn server running.
can you people guide me where to use its IP in exiting jitsi/jibri system?
thanks

damencho · September 19, 2019, 2:57pm

Have you read the posts ^? They describe how to configure mod_turncredentials.

Sergio_Ruiz · April 22, 2020, 3:41pm

HI,

I’m not problem with udp protocol, but when I reproduce video recorder with jibri this is black . the audio sound correctly.

Log ffmepg.0.txt:
2020-04-22 12:21:26.922 INFORMACIÓN: [59] ffmpeg.call() ffmpeg version 2.8.15-0ubuntu0.16.04.1 Copyright © 2000-2018 the FFmpeg developers
2020-04-22 12:21:26.922 INFORMACIÓN: [59] ffmpeg.call() built with gcc 5.4.0 (Ubuntu 5.4.0-6ubuntu1~16.04.10) 20160609
2020-04-22 12:21:26.964 INFORMACIÓN: [59] ffmpeg.call() configuration: --prefix=/usr --extra-version=0ubuntu0.16.04.1 --build-suffix=-ffmpeg --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --cc=cc --cxx=g++ --enable-gpl --enable-shared --disable-stripping --disable-decoder=libopenjpeg --disable-decoder=libschroedinger --enable-avresample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libmodplug --enable-libmp3lame --enable-libopenjpeg --enable-libopus --enable-libpulse --enable-librtmp --enable-libschroedinger --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxvid --enable-libzvbi --enable-openal --enable-opengl --enable-x11grab --enable-libdc1394 --enable-libiec61883 --enable-libzmq --enable-frei0r --enable-libx264 --enable-libopencv
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libavutil 54. 31.100 / 54. 31.100
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libavcodec 56. 60.100 / 56. 60.100
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libavformat 56. 40.101 / 56. 40.101
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libavdevice 56. 4.100 / 56. 4.100
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libavfilter 5. 40.101 / 5. 40.101
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libavresample 2. 1. 0 / 2. 1. 0
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libswscale 3. 1.101 / 3. 1.101
2020-04-22 12:21:26.965 INFORMACIÓN: [59] ffmpeg.call() libswresample 1. 2.101 / 1. 2.101
2020-04-22 12:21:26.966 INFORMACIÓN: [59] ffmpeg.call() libpostproc 53. 3.100 / 53. 3.100
2020-04-22 12:21:26.966 INFORMACIÓN: [59] ffmpeg.call() Input #0, x11grab, from ‘:0.0+0,0’:
2020-04-22 12:21:26.966 INFORMACIÓN: [59] ffmpeg.call() Duration: N/A, start: 1587550886.954363, bitrate: N/A
2020-04-22 12:21:26.966 INFORMACIÓN: [59] ffmpeg.call() Stream #0:0: Video: rawvideo (BGR[0] / 0x524742), bgr0, 1280x720, 30 fps, 30 tbr, 1000k tbn, 30 tbc
2020-04-22 12:21:26.966 INFORMACIÓN: [59] ffmpeg.call() Guessed Channel Layout for Input Stream #1.0 : stereo
2020-04-22 12:21:26.966 INFORMACIÓN: [59] ffmpeg.call() Input #1, alsa, from ‘plug:cloop’:
2020-04-22 12:21:26.969 INFORMACIÓN: [59] ffmpeg.call() Duration: N/A, start: 1587550886.582429, bitrate: 1536 kb/s
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() Stream #1:0: Audio: pcm_s16le, 48000 Hz, 2 channels, s16, 1536 kb/s
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 AVX2 LZCNT BMI2
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] profile Main, level 3.1
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] 264 - core 148 r2643 5c65704 - H.264/MPEG-4 AVC codec - Copyleft 2003-2015 l - options: cabac=1 ref=1 deblock=1:0:0 analyse=0x1:0x111 me=hex subme=2 psy=1 psy_rd=1.00:0.00 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=0 threads=4 lookahead_threads=4 sliced_threads=1 slices=4 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=1 keyint=60 keyint_min=6 scenecut=40 intra_refresh=0 rc=crf mbtree=0 crf=25.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() Output #0, mp4, to ‘/srv/recordings/derytiblrnpdaayx/aula37_2020-04-22-12-21-24.mp4’:
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() Metadata:
2020-04-22 12:21:26.979 INFORMACIÓN: [59] ffmpeg.call() encoder : Lavf56.40.101
2020-04-22 12:21:27.980 INFORMACIÓN: [59] ffmpeg.call() Stream #0:0: Video: h264 (libx264) ([33][0][0][0] / 0x0021), yuv420p, 1280x720, q=-1–1, 30 fps, 15360 tbn, 30 tbc
2020-04-22 12:21:27.980 INFORMACIÓN: [59] ffmpeg.call() Metadata:
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() encoder : Lavc56.60.100 libx264
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() Stream #0:1: Audio: aac ([64][0][0][0] / 0x0040), 44100 Hz, stereo, fltp, 128 kb/s
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() Metadata:
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() encoder : Lavc56.60.100 aac
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() Stream mapping:
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() Stream #0:0 -> #0:0 (rawvideo (native) -> h264 (libx264))
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() Stream #1:0 -> #0:1 (pcm_s16le (native) -> aac (native))
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() Press [q] to stop, [?] for help
2020-04-22 12:21:27.981 INFORMACIÓN: [59] ffmpeg.call() frame= 14 fps=0.0 q=21.0 size= 11kB time=00:00:00.46 bitrate= 184.0kbits/s
2020-04-22 12:21:28.982 INFORMACIÓN: [59] ffmpeg.call() frame= 29 fps= 29 q=21.0 size= 14kB time=00:00:00.97 bitrate= 120.4kbits/s
2020-04-22 12:21:28.982 INFORMACIÓN: [59] ffmpeg.call() frame= 45 fps= 30 q=21.0 size= 24kB time=00:00:01.50 bitrate= 130.6kbits/s
2020-04-22 12:21:29.982 INFORMACIÓN: [59] ffmpeg.call() frame= 60 fps= 30 q=21.0 size= 34kB time=00:00:02.00 bitrate= 140.1kbits/s

…

2020-04-22 12:23:12.672 INFORMACIÓN: [59] ffmpeg.call() frame= 3166 fps= 30 q=21.0 size= 1971kB time=00:01:45.53 bitrate= 153.0kbits/s
2020-04-22 12:23:12.672 INFORMACIÓN: [59] ffmpeg.call() frame= 3169 fps= 30 q=21.0 Lsize= 2095kB time=00:01:45.65 bitrate= 162.5kbits/s
2020-04-22 12:23:12.672 INFORMACIÓN: [59] ffmpeg.call() video:289kB audio:1675kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 6.699902%
2020-04-22 12:23:12.672 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] frame I:53 Avg QP: 3.08 size: 393
2020-04-22 12:23:12.672 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] frame P:3116 Avg QP: 6.03 size: 88
2020-04-22 12:23:12.672 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] mb I I16…4: 99.9% 0.0% 0.1%
2020-04-22 12:23:12.675 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] mb P I16…4: 0.0% 0.0% 0.0% P16…4: 0.0% 0.0% 0.0% 0.0% 0.0% skip:100.0%
2020-04-22 12:23:12.675 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] coded y,uvDC,uvAC intra: 0.0% 0.0% 0.0% inter: 0.0% 0.0% 0.0%
2020-04-22 12:23:12.675 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] i16 v,h,dc,p: 91% 0% 9% 0%
2020-04-22 12:23:12.676 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 0% 0% 100% 0% 0% 0% 0% 0% 0%
2020-04-22 12:23:12.676 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] i8c dc,h,v,p: 100% 0% 0% 0%
2020-04-22 12:23:12.676 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] Weighted P-Frames: Y:0.0% UV:0.0%
2020-04-22 12:23:12.676 INFORMACIÓN: [59] ffmpeg.call() [libx264 @ 0x233e900] kb/s:22.38
2020-04-22 12:23:12.676 INFORMACIÓN: [59] ffmpeg.call() Exiting normally, received signal 2.

file log.0.txt
2020-04-22 12:21:25.341 DETALLADO: [47] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url aula37#config.iAmRecorder=true&config.externalConnectUrl=null&config.startWithAudioMuted=true&config.startWithVideoMuted=true&interfaceConfig.APP_NAME=“Jibri”&config.analytics.disabled=true&config.p2p.enabled=false
2020-04-22 12:21:26.848 INFORMACIÓN: [47] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Waited 1059 milliseconds for call page to load
2020-04-22 12:21:26.858 INFORMACIÓN: [47] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Running
2020-04-22 12:21:26.859 INFORMACIÓN: [47] org.jitsi.jibri.service.impl.FileRecordingJibriService.invoke() Selenium joined the call, starting the capturer
2020-04-22 12:21:26.885 INFORMACIÓN: [47] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.launch() Starting ffmpeg with command ffmpeg -y -v info -f x11grab -draw_mouse 0 -r 30 -s 1280x720 -thread_queue_size 4096 -i :0.0+0,0 -f alsa -thread_queue_size 4096 -i plug:cloop -acodec aac -strict -2 -ar 44100 -c:v libx264 -preset veryfast -profile:v main -level 3.1 -pix_fmt yuv420p -r 30 -crf 25 -g 60 -tune zerolatency -f mp4 /srv/recordings/derytiblrnpdaayx/aula37_2020-04-22-12-21-24.mp4 ([ffmpeg, -y, -v, info, -f, x11grab, -draw_mouse, 0, -r, 30, -s, 1280x720, -thread_queue_size, 4096, -i, :0.0+0,0, -f, alsa, -thread_queue_size, 4096, -i, plug:cloop, -acodec, aac, -strict, -2, -ar, 44100, -c:v, libx264, -preset, veryfast, -profile:v, main, -level, 3.1, -pix_fmt, yuv420p, -r, 30, -crf, 25, -g, 60, -tune, zerolatency, -f, mp4, /srv/recordings/derytiblrnpdaayx/aula37_2020-04-22-12-21-24.mp4])
2020-04-22 12:21:27.980 INFORMACIÓN: [58] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Starting up to Running
2020-04-22 12:21:27.982 INFORMACIÓN: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Running
2020-04-22 12:21:27.982 INFORMACIÓN: [58] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service started up successfully, sending on iq
2020-04-22 12:21:41.930 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {}, all clients muted? false
2020-04-22 12:21:56.884 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=35, upload=22}, download=2587, upload=22, video={download=2552, upload=0}}, all clients muted? false
2020-04-22 12:22:11.875 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=42, upload=22}, download=2576, upload=22, video={download=2534, upload=0}}, all clients muted? false
2020-04-22 12:22:26.879 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=42, upload=22}, download=2650, upload=22, video={download=2608, upload=0}}, all clients muted? false
2020-04-22 12:22:41.877 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=36, upload=22}, download=2678, upload=22, video={download=2642, upload=0}}, all clients muted? false
2020-04-22 12:22:56.881 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=34, upload=22}, download=2581, upload=22, video={download=2547, upload=0}}, all clients muted? false
2020-04-22 12:23:11.877 INFORMACIÓN: [45] org.jitsi.jibri.selenium.JibriSelenium.run() Jibri client receive bitrates: {audio={download=42, upload=22}, download=2603, upload=22, video={download=2561, upload=0}}, all clients muted? false
2020-04-22 12:23:12.627 INFORMACIÓN: [63] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq from environment [MucClient id=video.test.notariado.org hostname=video]
2020-04-22 12:23:12.627 DETALLADO: [63] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
2020-04-22 12:23:12.627 INFORMACIÓN: [63] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2020-04-22 12:23:12.627 INFORMACIÓN: [63] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
2020-04-22 12:23:12.627 INFORMACIÓN: [63] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
2020-04-22 12:23:12.672 INFORMACIÓN: [58] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Running to Finished
2020-04-22 12:23:12.672 INFORMACIÓN: [58] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Running to Finished
2020-04-22 12:23:12.672 INFORMACIÓN: [58] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service finished, sending off iq
2020-04-22 12:23:12.679 INFORMACIÓN: [63] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value 255
2020-04-22 12:23:12.679 INFORMACIÓN: [63] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
2020-04-22 12:23:12.700 INFORMACIÓN: [63] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording:
2020-04-22 12:23:12.722 INFORMACIÓN: [63] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 24 log entries for type browser
2020-04-22 12:23:12.820 INFORMACIÓN: [63] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 1068 log entries for type driver
2020-04-22 12:23:12.919 INFORMACIÓN: [63] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
2020-04-22 12:23:12.919 INFORMACIÓN: [63] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
2020-04-22 12:23:13.093 INFORMACIÓN: [63] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
2020-04-22 12:23:20.169 INFORMACIÓN: [63] org.openqa.selenium.os.OsProcess.destroy() Unable to drain process streams. Ignoring but the exception being swallowed follows.
org.apache.commons.exec.ExecuteException: The stop timeout of 2000 ms was exceeded (Exit value: -559038737)
at org.apache.commons.exec.PumpStreamHandler.stopThread(PumpStreamHandler.java:295)
at org.apache.commons.exec.PumpStreamHandler.stop(PumpStreamHandler.java:180)
at org.openqa.selenium.os.OsProcess.destroy(OsProcess.java:135)
at org.openqa.selenium.os.CommandLine.destroy(CommandLine.java:153)

Only error is when stop recordinf:
2020-04-22 12:23:20.169 INFORMACIÓN: [63] org.openqa.selenium.os.OsProcess.destroy() Unable to drain process streams. Ignoring but the exception being swallowed follows.
org.apache.commons.exec.ExecuteException: The stop timeout of 2000 ms was exceeded (Exit value: -559038737)
at org.apache.commons.exec.PumpStreamHandler.stopThread(PumpStreamHandler.java:295)

that Jibri server has process chrome running:
jibri 17336 0.0 0.6 427548 53696 ? S 12:21 0:00 _ /opt/google/chrome/chrome --type=zygote --no-sandbox --enable-logging --headless --log-level=0 --headless --enable-crash-reporter
jibri 17377 3.8 8.4 15964732 691184 ? Sl 12:21 11:10 | _ /opt/google/chrome/chrome --type=renderer --no-sandbox --allow-pre-commit-input --autoplay-policy=no-user-gesture-required --enable-automation --enable-logging --log-level=0 --remote-debugging-port=0 --test-type=webdriver --use-fake-ui-for-media-stream --use-gl=swiftshader-webgl --field-trial-handle=279166958013913078,7345149451722425539,131072 --disable-gpu-compositing --enable-blink-features=ShadowDOMV0 --lang=es-ES --headless --enable-crash-reporter --lang=es-ES --num-raster-threads=2 --enable-main-frame-b
jibri 17350 0.0 1.0 493512 82244 ? Sl 12:21 0:09 _ /opt/google/chrome/chrome --type=gpu-process --field-trial-handle=279166958013913078,7345149451722425539,131072 --no-sandbox --enable-logging --headless --log-level=0 --headless --enable-crash-reporter --gpu-preferences=MAAAAAAAAAAgAAAAAAAAAAAAAAAAAAAAAABgAAAAAAAQAAAAAAAAAAAAAAAAAAAACAAAAAAAAAA= --use-gl=swiftshader-webgl --override-use-software-gl-for-tests --enable-logging --log-level=0 --shared-files
jibri 17351 0.0 0.8 494808 69644 ? Sl 12:21 0:02 _ /opt/google/chrome/chrome --type=utility --field-trial-handle=279166958013913078,7345149451722425539,131072 --lang=es-ES --service-sandbox-type=network --no-sandbox --enable-logging --ignore-certificate-errors --log-level=0 --use-gl=swiftshader-webgl --alsa-output-device=plug:amix --ignore-certificate-errors --headless --enable-crash-reporter --enable-logging --log-level=0 --shared-files
jibri 17390 0.5 0.7 526088 62468 ? SLl 12:21 1:42 _ /opt/google/chrome/chrome --type=utility --field-trial-handle=279166958013913078,7345149451722425539,131072 --lang=es-ES --service-sandbox-type=audio --no-sandbox --enable-logging --ignore-certificate-errors --log-level=0 --use-gl=swiftshader-webgl --alsa-output-device=plug:amix --ignore-certificate-errors --headless --enable-crash-reporter --enable-logging --log-level=0 --shared-files

Why video is black? Why don’t stop chrome binary?

Sergio_Ruiz · April 23, 2020, 10:04am

Problem fixed.

I had changed google-chrome binary to run with 4 parameters:
/usr/bin/google-chrome-orig --ignore-certificate-errors --disable-dev-shm-usage --no-sandbox --disable-web-security --headless $@

–no-sandbox --> when I removed it problem stop chrome binary resolved
–disable-web-security --> when I removed it problem black recorder video resolved

Finish file google-chrome:
/usr/bin/google-chrome-orig --ignore-certificate-errors --disable-dev-shm-usage $@

Regards.

cbstatic · April 23, 2020, 10:22am

I’m having a similar problem. Where did you add these options? Just restarting the service with these parameters? or is there a config file?