Jibri problem on AWS

Hi,

I have already an jitsi server with JWT successfully running on AWS.
After that I tried to setup a jibri server as described in https://github.com/jitsi/jibri

I used ubuntu 16.04 as recommended. It seams, that the jibri is able to connect to the jitsi server, but I still get the message “Failed to start a Jibri session, no Jibris available”.

In the jibri.log I see the following messages:

2020-06-03 12:20:53.371 INFO: [1] org.jitsi.jibri.Main.main() Jibri run with args [–config, /etc/jitsi/jibri/config.json]
2020-06-03 12:20:53.379 INFO: [1] org.jitsi.jibri.Main.main() Using config file /etc/jitsi/jibri/config.json
2020-06-03 12:20:53.379 INFO: [1] org.jitsi.jibri.Main.main() Using port 3333 for internal HTTP API
2020-06-03 12:20:53.380 INFO: [1] org.jitsi.jibri.Main.main() Using port 2222 for the HTTP API
2020-06-03 12:20:54.721 INFO: [1] org.jitsi.jibri.Main.loadConfig() Parsed config:
JibriConfig(recordingDirectory=/srv/recordings, singleUseMode=false, enabledStatsD=true, finalizeRecordingScriptPath=/path/to/finalize_recording.sh, xmppEnvironments=[XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[jitsi.test.at], xmppDomain=jitsi.test.at, controlLogin=XmppCredentials(domain=auth.jitsi.test.at, username=jibri, password=PWD), controlMuc=XmppMuc(domain=internal.auth.jitsi.test.at, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.jitsi.test.at, username=recorder, password=PWD), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)])
2020-06-03 12:20:55.879 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.internal.InternalHttpApi registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider org.jitsi.jibri.api.http.internal.InternalHttpApi will be ignored.
2020-06-03 12:20:56.487 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.updatePresence() Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2020-06-03 12:20:56.490 INFO: [1] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@771158fb
2020-06-03 12:20:56.506 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() Connecting to xmpp environment on jitsi.test.at with config XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[jitsi.test.at], xmppDomain=jitsi.test.at, controlLogin=XmppCredentials(domain=auth.jitsi.test.at, username=jibri, password=PWD), controlMuc=XmppMuc(domain=internal.auth.jitsi.test.at, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.jitsi.test.at, username=recorder, password=PWD), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)
2020-06-03 12:20:56.507 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2020-06-03 12:20:56.576 WARNING: [19] org.jitsi.xmpp.mucclient.MucClient.log() Disabling certificate verification!
2020-06-03 12:20:56.674 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.HttpApi registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider org.jitsi.jibri.api.http.HttpApi will be ignored.
2020-06-03 12:20:57.217 INFO: [19] org.jitsi.xmpp.mucclient.MucClient.log() [MucClient id=jitsi.test.at hostname=jitsi.test.at] connected
2020-06-03 12:20:57.387 INFO: [19] org.jitsi.xmpp.mucclient.MucClient.log() Joined MUC: jibribrewery@internal.auth.jitsi.test.at

at the prosody.log

Jun 03 12:20:56 c2s55cc4dcba230 info Client connected
Jun 03 12:20:57 c2s55cc4dcba230 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
Jun 03 12:20:57 c2s55cc4dcba230 info Authenticated as jibri@auth.jitsi.test.at

It seams, that the jibri is able to establish a connection to the jitsi server.

At the Jicofo log file I see the following

Jicofo 2020-06-03 12:47:00.022 SEVERE: [83] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unable to find an available Jibri, can't start
Jicofo 2020-06-03 12:47:00.023 INFO: [83] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Failed to start a Jibri session, no Jibris available

The status of the jibri service shows:

Jun 03 16:27:21 ip-172-31-41-10 systemd[1]: jibri.service: Main process exited, code=exited, status=143/n/a

Jun 03 16:27:21 ip-172-31-41-10 systemd[1]: Stopped Jibri Process.

Jun 03 16:27:21 ip-172-31-41-10 systemd[1]: jibri.service: Unit entered failed state.

Jun 03 16:27:21 ip-172-31-41-10 systemd[1]: jibri.service: Failed with result ‘exit-code’.

Jun 03 16:27:21 ip-172-31-41-10 systemd[1]: Started Jibri Process.

Jun 03 16:27:22 ip-172-31-41-10 launch.sh[2356]: SLF4J: Failed to load class “org.slf4j.impl.StaticLoggerBinder”.

Jun 03 16:27:22 ip-172-31-41-10 launch.sh[2356]: SLF4J: Defaulting to no-operation (NOP) logger implementation

Jun 03 16:27:22 ip-172-31-41-10 launch.sh[2356]: SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

What’s the problem?

I don’t see anything in those logs that’s a problem. 143 is sigterm, so it was killed.

If I start the service with “service jibri start” it seems to work

● jibri.service - Jibri Process
Loaded: loaded (/etc/systemd/system/jibri.service; disabled; vendor preset: enabled)
Active: active (running) since Wed 2020-06-03 16:59:31 UTC; 6s ago
Process: 2007 ExecStop=/opt/jitsi/jibri/graceful_shutdown.sh (code=exited, status=0/SUCCESS)
Main PID: 2047 (java)
Tasks: 38
Memory: 149.4M
CPU: 3.601s
CGroup: /system.slice/jibri.service
└─2047 java -Djava.util.logging.config.file=/etc/jitsi/jibri/logging.properties -jar /opt/jitsi/jibri/jibri.jar --config /etc/jitsi/jibri/config.json

Jun 03 16:59:31 ip-172-31-12-216 systemd[1]: Started Jibri Process.
Jun 03 16:59:32 ip-172-31-12-216 launch.sh[2047]: SLF4J: Failed to load class “org.slf4j.impl.StaticLoggerBinder”.
Jun 03 16:59:32 ip-172-31-12-216 launch.sh[2047]: SLF4J: Defaulting to no-operation (NOP) logger implementation
Jun 03 16:59:32 ip-172-31-12-216 launch.sh[2047]: SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

But If I use “service jibri restart” I receive the above errors.

Hmm, I don’t think that logger warning is actually a problem so not sure what it would be.

Is there a possibility to see if a jibri instance is connected?

My Jicofo config file has
JICOFO_HOST=localhost
included, do I have to use the dns name?

No, I don’t think so. Jicofo will log something when it ‘discovers’ new Jibris, but if your Jibri isn’t even running you’ll need to solve that first.

I think the jibri is running (if I start the service with service jibri start, not wit restart)

I see after “service jibri start” in the prosody.log file the following entries

Jun 03 17:11:54 conference.jitsi.test.at:muc_domain_mapper warn Session filters applied
Jun 03 17:11:54 c2s55a5e4490b40 info Client connected
Jun 03 17:11:55 c2s55a5e4490b40 info Stream encrypted (TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384)
Jun 03 17:11:55 c2s55a5e4490b40 info Authenticated as jibri@auth.jitsi.test.at

after “service jibri stop” I see the following:

Jun 03 17:13:22 c2s55a5e4490b40 info Client disconnected: closed

it seams, that the process is running, or I am wrong?
with ps I see:

jibri 1545 1 5 17:27 ? 00:00:04 java -Djava.util.logging.config.file=/etc/jitsi/jibri/logging.properties -jar /opt/jitsi/jibri/jibri.jar --config /etc/jitsi/jibri/config.json

I use openjdk version “1.8.0_252”

I had an spelling error in my /etc/jitsi/jicofo/sip-communicator.properties file at my org.jitsi.jicofo.jibri.BREWERY domain.

Now I came closer to the solution, but I still have the following errors in the log files:

jibri log

2020-06-03 18:01:35.260 INFO: [122] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.jitsi.test.at/Qg4c5vq2' from='jibribrewery@internal.auth.jitsi.test.at/focus' id='amlicmlAYXV0aC5qaXRzaS5pZWN0LmF0L1FnNGM1dnEyAGlzTTRyLTM3OACgn5z5uDhZm1JVl4FmnN4x' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='test@conference.jitsi.test.at' session_id='apqspkgfrknxbsks' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=jitsi.test.at hostname=jitsi.test.at]
2020-06-03 18:01:35.261 INFO: [122] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request
2020-06-03 18:01:35.261 INFO: [122] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending 'pending' response to start IQ
2020-06-03 18:01:35.263 INFO: [123] org.jitsi.jibri.api.xmpp.XmppApi.run() Starting service
2020-06-03 18:01:35.273 INFO: [123] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://jitsi.test.at, callName=test, urlParams=[])
2020-06-03 18:01:35.274 INFO: [123] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://jitsi.test.at, callName=test, urlParams=[])), sessionId=apqspkgfrknxbsks, callLoginParams=XmppCredentials(domain=recorder.jitsi.test.at, username=recorder, password=PWD)) finalize script path: /path/to/finalize_recording.sh and recordings directory: /srv/recordings
2020-06-03 18:01:35.870 INFO: [123] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
2020-06-03 18:01:35.878 INFO: [123] org.jitsi.jibri.selenium.JibriSelenium.<init>() Starting empty call check with a timeout of PT30S
2020-06-03 18:01:35.879 FINE: [123] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.<init>() Detected os as OS: LINUX
2020-06-03 18:01:35.879 INFO: [123] org.jitsi.jibri.service.impl.FileRecordingJibriService.<init>() Writing recording to /srv/recordings/apqspkgfrknxbsks
2020-06-03 18:01:35.880 FINE: [123] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
2020-06-03 18:01:35.880 INFO: [123] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
2020-06-03 18:01:35.881 INFO: [123] org.jitsi.jibri.api.xmpp.XmppApi.updatePresence() Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2020-06-03 18:01:35.882 INFO: [123] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@7ab78c46
2020-06-03 18:01:37.299 FINE: [132] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url https://jitsi.test.at/test#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-06-03 18:01:39.844 INFO: [122] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.jitsi.test.at/Qg4c5vq2' from='jibribrewery@internal.auth.jitsi.test.at/focus' id='amlicmlAYXV0aC5qaXRzaS5pZWN0LmF0L1FnNGM1dnEyAGlzTTRyLTM5MwCgn5z5uDhZm1JVl4FmnN4x' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='stop'/></iq> from environment [MucClient id=jitsi.test.at hostname=jitsi.test.at]
2020-06-03 18:01:39.844 FINE: [122] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
2020-06-03 18:01:39.844 INFO: [122] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2020-06-03 18:01:39.845 INFO: [122] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
2020-06-03 18:01:39.845 INFO: [122] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
2020-06-03 18:01:39.845 INFO: [122] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value null
2020-06-03 18:01:39.845 INFO: [122] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
2020-06-03 18:01:39.861 INFO: [122] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording: []
2020-06-03 18:01:39.885 INFO: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 18 log entries for type browser
2020-06-03 18:01:39.938 INFO: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 530 log entries for type driver
2020-06-03 18:01:40.044 INFO: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
2020-06-03 18:01:40.044 INFO: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
2020-06-03 18:01:40.060 SEVERE: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Error trying to leave the call: org.openqa.selenium.JavascriptException: javascript error: The conference is has been already left
  (Session info: chrome=83.0.4103.61)
  (Driver info: chromedriver=83.0.4103.39 (ccbf011cb2d2b19b506d844400483861342c20cd-refs/branch-heads/4103@{#416}),platform=Linux 4.4.0-179-generic x86_64) (WARNING: The server did not provide any stacktrace information)
Command duration or timeout: 0 milliseconds
Build info: version: 'unknown', revision: 'unknown', time: 'unknown'
System info: host: 'ip-172-31-41-10', ip: '172.31.41.10', os.name: 'Linux', os.arch: 'amd64', os.version: '4.4.0-179-generic', java.version: '1.8.0_252'
Driver info: org.openqa.selenium.chrome.ChromeDriver
Capabilities {acceptInsecureCerts: false, acceptSslCerts: false, applicationCacheEnabled: false, browserConnectionEnabled: false, browserName: chrome, chrome: {chromedriverVersion: 83.0.4103.39 (ccbf011cb2d2b..., userDataDir: /tmp/.com.google.Chrome.kuRkcB}, cssSelectorsEnabled: true, databaseEnabled: false, goog:chromeOptions: {debuggerAddress: localhost:38440}, handlesAlerts: true, hasTouchScreen: false, javascriptEnabled: true, locationContextEnabled: true, mobileEmulationEnabled: false, nativeEvents: true, networkConnectionEnabled: false, pageLoadStrategy: normal, platform: LINUX, platformName: LINUX, proxy: Proxy(), rotatable: false, setWindowRect: true, strictFileInteractability: false, takesHeapSnapshot: true, takesScreenshot: true, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unexpectedAlertBehaviour: ignore, unhandledPromptBehavior: ignore, version: 83.0.4103.61, webStorageEnabled: true, webauthn:virtualAuthenticators: true}
Session ID: d889cf2e51b28446d5496cdd5d955d86 with stack: 
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
java.lang.reflect.Constructor.newInstance(Constructor.java:423)
org.openqa.selenium.remote.ErrorHandler.createThrowable(ErrorHandler.java:214)
org.openqa.selenium.remote.ErrorHandler.throwIfResponseFailed(ErrorHandler.java:166)
org.openqa.selenium.remote.http.JsonHttpResponseCodec.reconstructValue(JsonHttpResponseCodec.java:40)
org.openqa.selenium.remote.http.AbstractHttpResponseCodec.decode(AbstractHttpResponseCodec.java:80)
org.openqa.selenium.remote.http.AbstractHttpResponseCodec.decode(AbstractHttpResponseCodec.java:44)
org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:158)
org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:83)
org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:543)
org.openqa.selenium.remote.RemoteWebDriver.executeScript(RemoteWebDriver.java:480)
org.jitsi.jibri.selenium.pageobjects.CallPage.leave(CallPage.kt:218)
org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser(JibriSelenium.kt:290)
org.jitsi.jibri.service.impl.FileRecordingJibriService.stop(FileRecordingJibriService.kt:188)
org.jitsi.jibri.JibriManager.stopService(JibriManager.kt:254)
org.jitsi.jibri.api.xmpp.XmppApi.handleStopJibriIq(XmppApi.kt:256)
org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq(XmppApi.kt:163)
org.jitsi.jibri.api.xmpp.XmppApi.handleIq(XmppApi.kt:147)
org.jitsi.xmpp.mucclient.MucClient.handleIq(MucClient.java:446)
org.jitsi.xmpp.mucclient.MucClient.access$500(MucClient.java:47)
org.jitsi.xmpp.mucclient.MucClient$2.handleIQRequest(MucClient.java:412)
org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

2020-06-03 18:01:40.061 INFO: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
2020-06-03 18:01:40.132 INFO: [122] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Chrome driver quit
2020-06-03 18:01:40.132 INFO: [122] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Finalizing the recording
2020-06-03 18:01:40.133 SEVERE: [122] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Failed to run finalize script: java.io.IOException: Cannot run program "/path/to/finalize_recording.sh": error=2, No such file or directory with stack: 
java.lang.ProcessBuilder.start(ProcessBuilder.java:1048)
org.jitsi.jibri.util.ProcessWrapper.start(ProcessWrapper.kt:87)
org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize(FileRecordingJibriService.kt:205)
org.jitsi.jibri.service.impl.FileRecordingJibriService.stop(FileRecordingJibriService.kt:190)
org.jitsi.jibri.JibriManager.stopService(JibriManager.kt:254)
org.jitsi.jibri.api.xmpp.XmppApi.handleStopJibriIq(XmppApi.kt:256)
org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq(XmppApi.kt:163)
org.jitsi.jibri.api.xmpp.XmppApi.handleIq(XmppApi.kt:147)
org.jitsi.xmpp.mucclient.MucClient.handleIq(MucClient.java:446)
org.jitsi.xmpp.mucclient.MucClient.access$500(MucClient.java:47)
org.jitsi.xmpp.mucclient.MucClient$2.handleIQRequest(MucClient.java:412)
org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

2020-06-03 18:01:40.134 INFO: [122] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: BUSY -> IDLE
2020-06-03 18:01:40.134 INFO: [122] org.jitsi.jibri.api.xmpp.XmppApi.updatePresence() Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2020-06-03 18:01:40.134 INFO: [122] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@169ef08e
2020-06-03 18:01:40.327 SEVERE: [132] org.jitsi.jibri.selenium.JibriSelenium.run() An error occurred while joining the call: org.openqa.selenium.NoSuchSessionException: Session ID is null. Using WebDriver after calling quit()?
Build info: version: 'unknown', revision: 'unknown', time: 'unknown'
System info: host: 'ip-172-31-41-10', ip: '172.31.41.10', os.name: 'Linux', os.arch: 'amd64', os.version: '4.4.0-179-generic', java.version: '1.8.0_252'
Driver info: driver.version: RemoteWebDriver with stack: 
org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:125)
org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:83)
org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:543)
org.openqa.selenium.remote.RemoteWebDriver.executeScript(RemoteWebDriver.java:480)
org.jitsi.jibri.selenium.pageobjects.CallPage$visit$1.apply(CallPage.kt:48)
org.jitsi.jibri.selenium.pageobjects.CallPage$visit$1.apply(CallPage.kt:33)
org.openqa.selenium.support.ui.FluentWait.until(FluentWait.java:248)
org.jitsi.jibri.selenium.pageobjects.CallPage.visit(CallPage.kt:47)
org.jitsi.jibri.selenium.JibriSelenium$joinCall$1.run(JibriSelenium.kt:256)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
java.util.concurrent.FutureTask.run(FutureTask.java:266)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

2020-06-03 18:01:40.328 INFO: [132] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Error: SESSION Failed to join call
2020-06-03 18:01:40.328 INFO: [132] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Error: SESSION Failed to join call
2020-06-03 18:01:40.328 INFO: [132] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service had an error, sending error iq <iq to='jibribrewery@internal.auth.jitsi.test.at/focus' id='FOfW9-199' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error'/></iq>
2020-06-03 18:01:40.328 INFO: [132] org.jitsi.jibri.JibriManager.stopService() No service active, ignoring stop

Jicofo.log

Jicofo 2020-06-03 18:01:35.232 INFO: [92] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname
Jicofo 2020-06-03 18:01:35.233 INFO: [92] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname for stream ID: null in room: test@conference.jitsi.test.at
Jicofo 2020-06-03 18:01:35.238 INFO: [92] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.jitsi.test.at/focus17178713625' from='jibribrewery@internal.auth.jitsi.test.at/jibri-nickname' id='isM4r-378' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='pending'/></iq> for test@conference.jitsi.test.at
Jicofo 2020-06-03 18:01:35.238 INFO: [92] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname has status pending and failure reason null, current Jibri jid is jibribrewery@internal.auth.jitsi.test.at/jibri-nickname
Jicofo 2020-06-03 18:01:35.239 INFO: [92] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Started Jibri session
Jicofo 2020-06-03 18:01:39.166 INFO: [71] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test@conference.jitsi.test.at
Jicofo 2020-06-03 18:01:39.307 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@3460ccf6 member=ChatMember[test@conference.jitsi.test.at/73d28595, jid: null]@1582132825]
Jicofo 2020-06-03 18:01:39.308 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Owner already in the room: 4f185132
Jicofo 2020-06-03 18:01:39.308 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.jitsi.test.at/73d28595 joined.
Jicofo 2020-06-03 18:01:39.309 WARNING: [28] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Failed to select initial bridge for participantRegion=null
Jicofo 2020-06-03 18:01:39.309 SEVERE: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available.
Jicofo 2020-06-03 18:01:39.310 WARNING: [28] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Failed to select initial bridge for participantRegion=null
Jicofo 2020-06-03 18:01:39.310 SEVERE: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Can not invite participant -- no bridge available.
Jicofo 2020-06-03 18:01:39.696 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@3460ccf6 member=ChatMember[test@conference.jitsi.test.at/73d28595, jid: null]@1582132825]
Jicofo 2020-06-03 18:01:39.696 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.jitsi.test.at/73d28595 is leaving
Jicofo 2020-06-03 18:01:39.696 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, test@conference.jitsi.test.at/73d28595
Jicofo 2020-06-03 18:01:39.817 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@3460ccf6 member=ChatMember[test@conference.jitsi.test.at/4f185132, jid: 4f185132-45ea-4e5c-8481-0e4d7ec68ea5@jitsi.test.at/lYMcniLH]@1079839087]
Jicofo 2020-06-03 18:01:39.817 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Owner has left the room !
Jicofo 2020-06-03 18:01:39.817 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.jitsi.test.at/4f185132 is leaving
Jicofo 2020-06-03 18:01:39.817 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, test@conference.jitsi.test.at/4f185132
Jicofo 2020-06-03 18:01:39.818 INFO: [28] org.jitsi.jicofo.recording.jibri.JibriSession.log() Trying to stop: <iq to='jibribrewery@internal.auth.jitsi.test.at/jibri-nickname' id='isM4r-393' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='stop'/></iq>
Jicofo 2020-06-03 18:01:39.821 INFO: [28] org.jitsi.jicofo.FocusManager.log() Disposed conference for room: test@conference.jitsi.test.at conference count: 0
Jicofo 2020-06-03 18:01:40.116 INFO: [95] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: <iq to='focus@auth.jitsi.test.at/focus17178713625' from='jibribrewery@internal.auth.jitsi.test.at/jibri-nickname' id='isM4r-393' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off'/></iq> for test@conference.jitsi.test.at
Jicofo 2020-06-03 18:01:40.116 INFO: [95] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname has status off and failure reason null, current Jibri jid is jibribrewery@internal.auth.jitsi.test.at/jibri-nickname
Jicofo 2020-06-03 18:01:40.116 INFO: [95] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
Jicofo 2020-06-03 18:01:40.117 INFO: [95] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri session ended cleanly, notifying owner and cleaning up session
Jicofo 2020-06-03 18:01:40.117 SEVERE: [95] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() onSessionStateChanged for unknown session: org.jitsi.jicofo.recording.jibri.JibriSession@20195b2d
Jicofo 2020-06-03 18:01:40.117 INFO: [95] org.jitsi.jicofo.recording.jibri.JibriSession.log() Cleaning up current JibriSession
Jicofo 2020-06-03 18:02:00.246 INFO: [47] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test@conference.jitsi.test.at
Jicofo 2020-06-03 18:02:00.248 INFO: [47] org.jitsi.jicofo.FocusManager.log() Created new focus for test@conference.jitsi.test.at@auth.jitsi.test.at. Conference count 1,options: channelLastN=1 enableLipSync=false openSctp=true disableRtx=false 
Jicofo 2020-06-03 18:02:00.248 INFO: [47] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Joining the room: test@conference.jitsi.test.at
Jicofo 2020-06-03 18:02:00.371 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@6079c68e member=ChatMember[test@conference.jitsi.test.at/250844e8, jid: null]@1442009982]
Jicofo 2020-06-03 18:02:00.374 SEVERE: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Failed to grant owner status to 250844e8-03bb-4415-88d1-b47523414bb0@jitsi.test.at/LwIzT3FA
java.lang.RuntimeException: Failed to grant owner: <iq to='focus@auth.jitsi.test.at/focus17178713625' from='test@conference.jitsi.test.at' id='isM4r-427' type='error'><error type='modify'><not-acceptable xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.grantOwnership(ChatRoomImpl.java:808)
	at org.jitsi.jicofo.ChatRoomRoleAndPresence.grantOwner(ChatRoomRoleAndPresence.java:332)
	at org.jitsi.jicofo.ChatRoomRoleAndPresence.electNewOwner(ChatRoomRoleAndPresence.java:247)
	at org.jitsi.jicofo.ChatRoomRoleAndPresence.memberPresenceChanged(ChatRoomRoleAndPresence.java:159)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.lambda$notifyMemberJoined$1(ChatRoomImpl.java:917)
	at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.notifyMemberJoined(ChatRoomImpl.java:917)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.processOtherPresence(ChatRoomImpl.java:1212)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.processPresence(ChatRoomImpl.java:1261)
	at org.jivesoftware.smackx.muc.MultiUserChat$3.processStanza(MultiUserChat.java:251)
	at org.jivesoftware.smack.AbstractXMPPConnection$6.run(AbstractXMPPConnection.java:1263)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Jicofo 2020-06-03 18:02:00.375 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.jitsi.test.at/250844e8 joined.

This failure is due to no videobridge being available.

Hi,

I have a really strange problem. I installed jibri on an AWS instance and stored the image.
If I start the image direct from the AWS console and start the service by executing (sudo service jibri start) everything works fine. I am able to record a conference.

But if I reboot the system with “sudo reboot” and start the jibri again (“sudo service jibri”) the recording doesn’t work.

At the different log files I see several errors, maybe they are all related.
It seams, that the prosody does not allow the authentication after reboot.
does jitsi not totally unregister the jibri instance? Does jitsi get in trouble if this jibri instance has the same IP address after reboot?

In the browser log there exists an error as well:
Failed to get access to local media. NotFoundError: Requested device not found [object Object]

Here are the log files
jibri.log

2020-06-04 12:43:33.813 INFO: [1] org.jitsi.jibri.Main.main() Jibri run with args [--config, /etc/jitsi/jibri/config.json]
2020-06-04 12:43:33.822 INFO: [1] org.jitsi.jibri.Main.main() Using config file /etc/jitsi/jibri/config.json
2020-06-04 12:43:33.822 INFO: [1] org.jitsi.jibri.Main.main() Using port 3333 for internal HTTP API
2020-06-04 12:43:33.823 INFO: [1] org.jitsi.jibri.Main.main() Using port 2222 for the HTTP API
2020-06-04 12:43:34.891 INFO: [1] org.jitsi.jibri.Main.loadConfig() Parsed config:
JibriConfig(recordingDirectory=/srv/recordings, singleUseMode=false, enabledStatsD=true, finalizeRecordingScriptPath=/path/to/finalize_recording.sh, xmppEnvironments=[XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[jitsi.test.at], xmppDomain=jitsi.test.at, controlLogin=XmppCredentials(domain=auth.jitsi.test.at, username=jibri, password=PWD), controlMuc=XmppMuc(domain=internal.auth.jitsi.test.at, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.jitsi.test.at, username=recorder, password=PWD), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)])
2020-06-04 12:43:35.851 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.internal.InternalHttpApi registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider org.jitsi.jibri.api.http.internal.InternalHttpApi will be ignored.
2020-06-04 12:43:36.268 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.updatePresence() Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2020-06-04 12:43:36.270 INFO: [1] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@771158fb
2020-06-04 12:43:36.281 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() Connecting to xmpp environment on jitsi.test.at with config XmppEnvironmentConfig(name=prod environment, xmppServerHosts=[jitsi.test.at], xmppDomain=jitsi.test.at, controlLogin=XmppCredentials(domain=auth.jitsi.test.at, username=jibri, password=PWD), controlMuc=XmppMuc(domain=internal.auth.jitsi.test.at, roomName=JibriBrewery, nickname=jibri-nickname), sipControlMuc=null, callLogin=XmppCredentials(domain=recorder.jitsi.test.at, username=recorder, password=PWD), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true)
2020-06-04 12:43:36.283 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2020-06-04 12:43:36.344 WARNING: [19] org.jitsi.xmpp.mucclient.MucClient.log() Disabling certificate verification!
2020-06-04 12:43:36.351 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.HttpApi registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider org.jitsi.jibri.api.http.HttpApi will be ignored.
2020-06-04 12:43:36.761 INFO: [19] org.jitsi.xmpp.mucclient.MucClient.log() [MucClient id=jitsi.test.at hostname=jitsi.test.at] connected
2020-06-04 12:43:36.891 INFO: [19] org.jitsi.xmpp.mucclient.MucClient.log() Joined MUC: jibribrewery@internal.auth.jitsi.test.at
2020-06-04 12:43:56.645 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleJibriIq() Received JibriIq <iq to='jibri@auth.jitsi.test.at/Otzv7kTk' from='jibribrewery@internal.auth.jitsi.test.at/focus' id='amlicmlAYXV0aC5qaXRzaS5pZWN0LmF0L090enY3a1RrAFp1bFBzLTIwNDQAEM7KuLTcAb4flXuc4L8gbg==' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='jitsi@conference.jitsi.test.at' session_id='gqwljmmlapacgabk' app_data='{"file_recording_metadata":{"share":true}}'/></iq> from environment [MucClient id=jitsi.test.at hostname=jitsi.test.at]
2020-06-04 12:43:56.645 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Received start request
2020-06-04 12:43:56.663 INFO: [34] org.jitsi.jibri.api.xmpp.XmppApi.handleStartJibriIq() Sending 'pending' response to start IQ
2020-06-04 12:43:56.664 INFO: [35] org.jitsi.jibri.api.xmpp.XmppApi.run() Starting service
2020-06-04 12:43:56.759 INFO: [35] org.jitsi.jibri.api.xmpp.XmppApi.handleStartService() Parsed call url info: CallUrlInfo(baseUrl=https://jitsi.test.at, callName=jitsi, urlParams=[])
2020-06-04 12:43:56.761 INFO: [35] org.jitsi.jibri.JibriManager.startFileRecording() Starting a file recording with params: FileRecordingRequestParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://jitsi.test.at, callName=jitsi, urlParams=[])), sessionId=gqwljmmlapacgabk, callLoginParams=XmppCredentials(domain=recorder.jitsi.test.at, username=recorder, password=PWD)) finalize script path: /path/to/finalize_recording.sh and recordings directory: /srv/recordings
2020-06-04 12:43:59.030 INFO: [35] org.openqa.selenium.remote.ProtocolHandshake.createSession() Detected dialect: OSS
2020-06-04 12:43:59.052 INFO: [35] org.jitsi.jibri.selenium.JibriSelenium.<init>() Starting empty call check with a timeout of PT30S
2020-06-04 12:43:59.069 FINE: [35] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.<init>() Detected os as OS: LINUX
2020-06-04 12:43:59.077 INFO: [35] org.jitsi.jibri.service.impl.FileRecordingJibriService.<init>() Writing recording to /srv/recordings/gqwljmmlapacgabk
2020-06-04 12:43:59.079 FINE: [35] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: start:recording
2020-06-04 12:43:59.080 INFO: [35] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: IDLE -> BUSY
2020-06-04 12:43:59.081 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
2020-06-04 12:43:59.081 INFO: [35] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.jibri.JibriStatusPacketExt@3bf55ada
2020-06-04 12:44:01.230 FINE: [44] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Visiting url https://jitsi.test.at/jitsi#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-06-04 12:44:03.197 INFO: [44] org.jitsi.jibri.selenium.pageobjects.CallPage.visit() Waited 1136 milliseconds for call page to load
2020-06-04 12:44:03.243 INFO: [44] org.jitsi.jibri.selenium.JibriSelenium.onSeleniumStateChange() Transitioning from state Starting up to Running
2020-06-04 12:44:03.244 INFO: [44] org.jitsi.jibri.service.impl.FileRecordingJibriService.invoke() Selenium joined the call, starting the capturer
2020-06-04 12:44:03.311 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 /srv/recordings/gqwljmmlapacgabk/jitsi_2020-06-04-12-43-59.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/gqwljmmlapacgabk/jitsi_2020-06-04-12-43-59.mp4])
2020-06-04 12:44:08.323 FINE: [45] org.jitsi.jibri.util.ProcessStatePublisher.ffmpeg.invoke() Process ffmpeg hasn't written in 2 seconds, publishing periodic update
2020-06-04 12:44:08.324 INFO: [48] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegProcessUpdate() Ffmpeg quit abruptly.  Last output line: plug:cloop: Input/output error
2020-06-04 12:44:08.324 INFO: [48] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Starting up to Error: SESSION Ffmpeg failed to start
2020-06-04 12:44:08.327 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.onServiceStateChange() File recording service transitioning from state Starting up to Error: SESSION Ffmpeg failed to start
2020-06-04 12:44:08.327 INFO: [48] org.jitsi.jibri.api.xmpp.XmppApi.invoke() Current service had an error, sending error iq <iq to='jibribrewery@internal.auth.jitsi.test.at/focus' id='EU6O2-23' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' failure_reason='error'/></iq>
2020-06-04 12:44:08.328 FINE: [48] org.jitsi.jibri.statsd.JibriStatsDClient.incrementCounter() Incrementing statsd counter: stop:recording
2020-06-04 12:44:08.331 INFO: [48] org.jitsi.jibri.JibriManager.stopService() Stopping the current service
2020-06-04 12:44:08.332 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Stopping capturer
2020-06-04 12:44:08.332 INFO: [48] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() Stopping ffmpeg process
2020-06-04 12:44:08.347 INFO: [48] org.jitsi.jibri.util.JibriSubprocess.ffmpeg.stop() ffmpeg exited with value 1
2020-06-04 12:44:08.347 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Quitting selenium
2020-06-04 12:44:08.382 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Participants in this recording: [{group=a123-123-456-789, user={avatar=https:/gravatar.com/avatar/abc123, id=abcd:a1b2c3-d4e5f6-0abc1-23de-abcdef01fedcba, name=Moderator}}]
2020-06-04 12:44:08.601 INFO: [48] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 31 log entries for type browser
2020-06-04 12:44:08.809 INFO: [48] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 737 log entries for type driver
2020-06-04 12:44:09.212 INFO: [48] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Got 0 log entries for type client
2020-06-04 12:44:09.213 INFO: [48] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Leaving web call
2020-06-04 12:44:09.453 INFO: [48] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Quitting chrome driver
2020-06-04 12:44:09.533 INFO: [48] org.jitsi.jibri.selenium.JibriSelenium.leaveCallAndQuitBrowser() Chrome driver quit
2020-06-04 12:44:09.533 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.stop() Finalizing the recording
2020-06-04 12:44:09.543 INFO: [48] org.jitsi.jibri.service.impl.FileRecordingJibriService.finalize() Recording finalize script finished with exit value 0
2020-06-04 12:44:09.544 INFO: [48] org.jitsi.jibri.status.JibriStatusManager.log() Busy status has changed: BUSY -> IDLE
2020-06-04 12:44:09.544 INFO: [48] 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

browser.log

2020-06-04 12:44:08.577 INFO: [48] browser.leaveCallAndQuitBrowser() Logs for call https://jitsi.test.at/test#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-06-04 12:44:08.602 INFO: [48] browser.leaveCallAndQuitBrowser() ========= TYPE=browser ===========
2020-06-04 12:44:08.602 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:00+0000] [WARNING] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:00.070Z” “[modules/UI/videolayout/VideoLayout.js]” "\u003CObject.changeUserAvatar>: " “Missed avatar update - no small video yet for undefined”
2020-06-04 12:44:08.603 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:00+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:00.092Z” “[modules/statistics/AnalyticsAdapter.js]” "\u003CObject.dispose>: " “Disposing of analytics adapter.”
2020-06-04 12:44:08.604 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:00+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:00.092Z” “[features/analytics]” Error: No analytics handlers created!
at https://jitsi.test.at/libs/app.bundle.min.js?v=4171:1:41650
2020-06-04 12:44:08.605 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:00+0000] [WARNING] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:00.672Z” “[modules/UI/videolayout/VideoLayout.js]” "\u003CObject.changeUserAvatar>: " “Missed avatar update - no small video yet for undefined”
2020-06-04 12:44:08.605 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:00+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:00.683Z” “[modules/statistics/AnalyticsAdapter.js]” "\u003CObject.dispose>: " “Disposing of analytics adapter.”
2020-06-04 12:44:08.606 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:00+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:00.684Z” “[features/analytics]” Error: No analytics handlers created!
at https://jitsi.test.at/libs/app.bundle.min.js?v=4171:1:41650
2020-06-04 12:44:08.606 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:01.062Z” “[modules/RTC/RTCUtils.js]” "Failed to get access to local media. NotFoundError: Requested device not found [object Object] "
2020-06-04 12:44:08.606 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:01.064Z” “[features/base/tracks]” “Failed to create local tracks” Array(2) s
2020-06-04 12:44:08.607 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:01.129Z” “[modules/RTC/RTCUtils.js]” "Failed to get access to local media. NotFoundError: Requested device not found [object Object] "
2020-06-04 12:44:08.607 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:01.129Z” “[features/base/tracks]” “Failed to create local tracks” Array(1) s
2020-06-04 12:44:08.608 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:01.141Z” “[modules/RTC/RTCUtils.js]” "Failed to get access to local media. NotFoundError: Requested device not found [object Object] "
2020-06-04 12:44:08.609 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:01.144Z” “[features/base/tracks]” “Failed to create local tracks” Array(1) s
2020-06-04 12:44:08.609 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:01.152Z” “[connection.js]” "\u003Ca.o>: " “CONNECTION FAILED:” “connection.passwordRequired”
2020-06-04 12:44:08.610 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [WARNING] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:01.828Z” “[modules/UI/videolayout/VideoLayout.js]” "\u003CObject.changeUserAvatar>: " “Missed avatar update - no small video yet for undefined”
2020-06-04 12:44:08.610 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:01.836Z” “[JitsiMeetJS.js]” "\u003CObject.init>: " “Analytics disabled, disposing.”
2020-06-04 12:44:08.610 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:01+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:01.838Z” “[modules/statistics/AnalyticsAdapter.js]” "\u003CObject.dispose>: " “Disposing of analytics adapter.”
2020-06-04 12:44:08.612 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:02+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:02.122Z” “[modules/RTC/RTCUtils.js]” "Failed to get access to local media. NotFoundError: Requested device not found [object Object] "
2020-06-04 12:44:08.612 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:02+0000] [SEVERE] https://jitsi.test.at/libs/app.bundle.min.js?v=4171 71:36911 “2020-06-04T12:44:02.123Z” “[features/base/tracks]” “Failed to create local tracks” Array(1) s
2020-06-04 12:44:08.613 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:02.694Z” “[modules/xmpp/XmppConnection.js]” "\u003Cd._maybeEnableStreamResume>: " “Stream resume enabled, but WebSockets are not enabled”
2020-06-04 12:44:08.614 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:02.759Z” “[modules/xmpp/strophe.jingle.js]” “getting turn credentials failed” iq#b65a133e-5025-4d38-8b49-869109e7695d:sendIQ
2020-06-04 12:44:08.614 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:02.760Z” “[modules/xmpp/strophe.jingle.js]” “is mod_turncredentials or similar installed?”
2020-06-04 12:44:08.615 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:02.936Z” “[modules/recording/RecordingManager.js]” "\u003Ct.a._handleFocusPresence>: " “Ignoring recording presence update” “Received a new session with status off.”
2020-06-04 12:44:08.615 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:02.943Z” “[modules/recording/RecordingManager.js]” "\u003Ct.a._handleJibriPresence>: " “Ignoring potential jibri presence due to no session id.”
2020-06-04 12:44:08.616 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [SEVERE] https://www.gravatar.com/avatar/694ea0904ceaf766c6738166ed89bafb?d=404&size=200 - Failed to load resource: the server responded with a status of 404 ()
2020-06-04 12:44:08.616 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.075Z” “[modules/recording/RecordingManager.js]” "\u003Ct.a._handleFocusPresence>: " “Ignoring recording presence update” “Received a new session with status off.”
2020-06-04 12:44:08.627 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.079Z” “[modules/recording/RecordingManager.js]” "\u003Ct.a._handleFocusPresence>: " “Ignoring recording presence update” “Received a new session with status off.”
2020-06-04 12:44:08.630 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:03+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.082Z” “[modules/recording/RecordingManager.js]” "\u003Ct.a._handleFocusPresence>: " “Ignoring recording presence update” “Received a new session with status off.”
2020-06-04 12:44:08.631 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:08+0000] [SEVERE] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.434Z” “[JitsiMeetJS.js]” "\u003CObject.getGlobalOnErrorHandler>: " “UnhandledError: null” “Script: null” “Line: null” “Column: null” "StackTrace: " Error: P2P mode disabled in the configuration
at se._rejectIncomingCall (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:10:178684)
at se._onIncomingCallP2P (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:10:176499)
at se.onIncomingCall (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:10:176618)
at a.emit (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:1:129506)
at g.onJingle (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:10:273901)
at I.Handler.run (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:1:21746)
at https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:1:30184
at Object.forEachChild (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:1:13408)
at I.Connection._dataRecv (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:1:30033)
at D.Bosh._onRequestStateChange (https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171:1:50018)
2020-06-04 12:44:08.631 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:08+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.438Z” “[modules/xmpp/strophe.jingle.js]” "\u003Cg.onJingle>: " “invalid session id” iq#cmVjb3JkZXJAcmVjb3JkZXIuaml0c2kuaWVjdC5hdC82R3JHZzlkMAAyNDY3YWQyMC0wMTk2LTQ0YWQtYWY1YS04ZTYxYmExMTdlZTE6c2VuZElRALcU+nqVuudTBYhoEQ7odWA=
2020-06-04 12:44:08.633 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:08+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.439Z” “[modules/xmpp/strophe.jingle.js]” "\u003Cg.onJingle>: " “invalid session id” iq#cmVjb3JkZXJAcmVjb3JkZXIuaml0c2kuaWVjdC5hdC82R3JHZzlkMAA2OGM4M2I1Ny1jMmVmLTQ0ZWUtYmQ5Yy04YzAzMjQwODMzYjY6c2VuZElRALcU+nqVuudTBYhoEQ7odWA=
2020-06-04 12:44:08.634 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:44:08+0000] [WARNING] https://jitsi.test.at/libs/lib-jitsi-meet.min.js?v=4171 9:26401 “2020-06-04T12:44:03.440Z” “[modules/xmpp/strophe.jingle.js]” "\u003Cg.onJingle>: " “invalid session id” iq#cmVjb3JkZXJAcmVjb3JkZXIuaml0c2kuaWVjdC5hdC82R3JHZzlkMAA3ZDY1MjBiMS03YTFmLTQxNjktYWI0OC02NmViYmZlZWVjOGQ6c2VuZElRALcU+nqVuudTBYhoEQ7odWA=
2020-06-04 12:44:08.809 INFO: [48] browser.leaveCallAndQuitBrowser() ========= TYPE=driver ===========
2020-06-04 12:44:08.813 INFO: [48] browser.leaveCallAndQuitBrowser() [2020-06-04T12:43:57+0000] [INFO] Populating Preferences file: {
“alternate_error_pages”: {

ffmpeg.log

2020-06-04 12:44:03.634 INFO: [49] ffmpeg.call() ffmpeg version 2.8.15-0ubuntu0.16.04.1 Copyright © 2000-2018 the FFmpeg developers
2020-06-04 12:44:03.635 INFO: [49] ffmpeg.call() built with gcc 5.4.0 (Ubuntu 5.4.0-6ubuntu1~16.04.10) 20160609
2020-06-04 12:44:03.708 INFO: [49] 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-06-04 12:44:03.708 INFO: [49] ffmpeg.call() libavutil 54. 31.100 / 54. 31.100
2020-06-04 12:44:03.708 INFO: [49] ffmpeg.call() libavcodec 56. 60.100 / 56. 60.100
2020-06-04 12:44:03.708 INFO: [49] ffmpeg.call() libavformat 56. 40.101 / 56. 40.101
2020-06-04 12:44:03.709 INFO: [49] ffmpeg.call() libavdevice 56. 4.100 / 56. 4.100
2020-06-04 12:44:03.709 INFO: [49] ffmpeg.call() libavfilter 5. 40.101 / 5. 40.101
2020-06-04 12:44:03.709 INFO: [49] ffmpeg.call() libavresample 2. 1. 0 / 2. 1. 0
2020-06-04 12:44:03.709 INFO: [49] ffmpeg.call() libswscale 3. 1.101 / 3. 1.101
2020-06-04 12:44:03.709 INFO: [49] ffmpeg.call() libswresample 1. 2.101 / 1. 2.101
2020-06-04 12:44:03.710 INFO: [49] ffmpeg.call() libpostproc 53. 3.100 / 53. 3.100
2020-06-04 12:44:03.710 INFO: [49] ffmpeg.call() Input #0, x11grab, from ‘:0.0+0,0’:
2020-06-04 12:44:03.710 INFO: [49] ffmpeg.call() Duration: N/A, start: 1591274643.676453, bitrate: N/A
2020-06-04 12:44:03.710 INFO: [49] ffmpeg.call() Stream #0:0: Video: rawvideo (BGR[0] / 0x524742), bgr0, 1280x720, 30 fps, 30 tbr, 1000k tbn, 30 tbc
2020-06-04 12:44:03.710 INFO: [49] ffmpeg.call() ALSA lib pcm_direct.c:1562:(_snd_pcm_direct_get_slave_ipc_offset) Invalid value for card
2020-06-04 12:44:03.710 INFO: [49] ffmpeg.call() [alsa @ 0x1b53220] cannot open audio device plug:cloop (No such device)
2020-06-04 12:44:03.711 INFO: [49] ffmpeg.call() plug:cloop: Input/output error

Jicofo.log

Jicofo 2020-06-04 12:43:56.664 INFO: [317] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Started Jibri session
Jicofo 2020-06-04 12:43:59.082 INFO: [28] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname status
Jicofo 2020-06-04 12:43:59.082 INFO: [28] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal.auth.jitsi.test.at/jibri-nickname available: false
Jicofo 2020-06-04 12:44:00.808 WARNING: [154] org.jitsi.jicofo.bridge.JvbDoctor.log() XMPP disconnected - skipping health check for: jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635
Jicofo 2020-06-04 12:44:02.745 INFO: [88] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test@conference.jitsi.test.at
Jicofo 2020-06-04 12:44:02.863 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@13f0b70f member=ChatMember[test@conference.jitsi.test.at/d74f8a15, jid: null]@2130454342]
Jicofo 2020-06-04 12:44:02.863 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.jitsi.test.at/d74f8a15 joined.
Jicofo 2020-06-04 12:44:02.863 INFO: [28] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Selected initial bridge Bridge[jid=jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635, relayId=null, region=null, stress=0.00] with packetRate=0 for participantRegion=null
Jicofo 2020-06-04 12:44:02.864 INFO: [28] org.jitsi.impl.protocol.xmpp.colibri.OperationSetColibriConferenceImpl.log() Conference created: org.jitsi.impl.protocol.xmpp.colibri.ColibriConferenceImpl@5dd0c8aa
Jicofo 2020-06-04 12:44:02.864 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= test@conference.jitsi.test.at/d74f8a15, bridge=jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635
Jicofo 2020-06-04 12:44:02.864 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ffd55e octo_enabled= false: [[null, null]]
Jicofo 2020-06-04 12:44:02.865 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= test@conference.jitsi.test.at/4726ab68, bridge=jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635
Jicofo 2020-06-04 12:44:02.866 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ffd55e octo_enabled= false: [[null, null, null]]
Jicofo 2020-06-04 12:44:02.866 INFO: [320] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:02.866 INFO: [320] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for test@conference.jitsi.test.at/d74f8a15 in 0
Jicofo 2020-06-04 12:44:02.866 INFO: [320] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635 to allocate channels for: Participant[test@conference.jitsi.test.at/d74f8a15]@935257672
Jicofo 2020-06-04 12:44:02.885 INFO: [321] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:02.885 INFO: [321] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for test@conference.jitsi.test.at/4726ab68 in 1
Jicofo 2020-06-04 12:44:02.885 INFO: [321] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635 to allocate channels for: Participant[test@conference.jitsi.test.at/4726ab68]@805222328
Jicofo 2020-06-04 12:44:02.899 INFO: [320] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:02.924 INFO: [321] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:03.394 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:03.395 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from test@conference.jitsi.test.at/4726ab68 with accepted sources:Sources{ video: [ssrc=1338384581 ssrc=2234718070 ssrc=2485829007 ssrc=1481104936 ssrc=1481640745 ssrc=2419111712 ] audio: [ssrc=1924484525 ] }@1369495181
Jicofo 2020-06-04 12:44:03.396 WARNING: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No jingle session yet for test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:03.432 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:03.433 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from test@conference.jitsi.test.at/d74f8a15 with accepted sources:Sources{ }@183423371
Jicofo 2020-06-04 12:44:03.433 INFO: [28] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() Notify add SSRC test@conference.jitsi.test.at/4726ab68 SID: 6h1a79vnm5gjd Sources{ }@1486429998 source_Groups{ }@1578539960
Jicofo 2020-06-04 12:44:03.434 INFO: [28] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() Notify add SSRC test@conference.jitsi.test.at/d74f8a15 SID: f044vm5oehvq6 Sources{ audio: [ssrc=1924484525 ] video: [ssrc=1338384581 ssrc=2234718070 ssrc=2485829007 ssrc=1481104936 ssrc=1481640745 ssrc=2419111712 ] }@156580425 source_Groups{ video:[ SourceGroup(FID)[ ssrc=1338384581 ssrc=2234718070 ]SourceGroup(FID)[ ssrc=2485829007 ssrc=1481640745 ]SourceGroup(FID)[ ssrc=1481104936 ssrc=2419111712 ]SourceGroup(SIM)[ ssrc=1338384581 ssrc=2485829007 ssrc=1481104936 ] ] }@1976291425
Jicofo 2020-06-04 12:44:08.328 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriSession.log() Updating status from JIBRI: for test@conference.jitsi.test.at
Jicofo 2020-06-04 12:44:08.328 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriSession.log() Got Jibri status update: Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname has status off and failure reason error, current Jibri jid is jibribrewery@internal.auth.jitsi.test.at/jibri-nickname
Jicofo 2020-06-04 12:44:08.328 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri is no longer pending, cancelling pending timeout task
Jicofo 2020-06-04 12:44:08.328 WARNING: [326] org.jitsi.jicofo.recording.jibri.JibriSession.log() failureReason was non-null but shouldRetry wasn’t set, will NOT retry
Jicofo 2020-06-04 12:44:08.328 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriSession.log() Jibri failed and signaled that we should not retry the same request
Jicofo 2020-06-04 12:44:08.328 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Got jibri status off and failure error
Jicofo 2020-06-04 12:44:08.328 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriRecorder.log() Publishing new jibri-recording-status: in: test@conference.jitsi.test.at
Jicofo 2020-06-04 12:44:08.329 INFO: [326] org.jitsi.jicofo.recording.jibri.JibriSession.log() Cleaning up current JibriSession
Jicofo 2020-06-04 12:44:09.239 INFO: [28] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@13f0b70f member=ChatMember[test@conference.jitsi.test.at/d74f8a15, jid: null]@2130454342]
Jicofo 2020-06-04 12:44:09.240 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@conference.jitsi.test.at/d74f8a15 is leaving
Jicofo 2020-06-04 12:44:09.240 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Terminating: test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:09.240 INFO: [28] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() Terminate session: test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:09.240 WARNING: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No sources or groups to be removed from: test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:09.240 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ffd55e octo_enabled= false: [[null, null]]
Jicofo 2020-06-04 12:44:09.240 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: test@conference.jitsi.test.at/d74f8a15 on: Bridge[jid=jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635, relayId=null, region=null, stress=0.02]
Jicofo 2020-06-04 12:44:09.245 INFO: [28] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, test@conference.jitsi.test.at/d74f8a15
Jicofo 2020-06-04 12:44:09.547 INFO: [28] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Received Jibri jibribrewery@internal.auth.jitsi.test.at/jibri-nickname status
Jicofo 2020-06-04 12:44:09.547 INFO: [28] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal.auth.jitsi.test.at/jibri-nickname available: true
Jicofo 2020-06-04 12:44:10.808 WARNING: [154] org.jitsi.jicofo.bridge.JvbDoctor.log() XMPP disconnected - skipping health check for: jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635
Jicofo 2020-06-04 12:44:15.656 INFO: [28] org.jitsi.jicofo.xmpp.BaseBrewery.log() Removed brewery instance: jibribrewery@internal.auth.jitsi.test.at/jibri-nickname
Jicofo 2020-06-04 12:44:15.656 INFO: [28] org.jitsi.jicofo.recording.jibri.JibriDetector.log() Jibri: jibribrewery@internal.auth.jitsi.test.at/jibri-nickname went offline
Jicofo 2020-06-04 12:44:20.808 WARNING: [154] org.jitsi.jicofo.bridge.JvbDoctor.log() XMPP disconnected - skipping health check for: jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635
Jicofo 2020-06-04 12:44:29.246 INFO: [241] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Timing out single participant: test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:29.246 INFO: [241] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Terminating: test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:29.246 INFO: [241] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() Terminate session: test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:29.247 INFO: [241] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removing test@conference.jitsi.test.at/4726ab68 sources Sources{ video: [ssrc=1338384581 ssrc=2234718070 ssrc=2485829007 ssrc=1481104936 ssrc=1481640745 ssrc=2419111712 ] audio: [ssrc=1924484525 ] }@168962167
Jicofo 2020-06-04 12:44:29.247 INFO: [241] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=ffd55e octo_enabled= false: [[null]]
Jicofo 2020-06-04 12:44:29.247 INFO: [241] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Expiring channels for: test@conference.jitsi.test.at/4726ab68 on: Bridge[jid=jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635, relayId=null, region=null, stress=0.01]
Jicofo 2020-06-04 12:44:29.247 INFO: [241] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Removed participant: true, test@conference.jitsi.test.at/4726ab68
Jicofo 2020-06-04 12:44:30.808 WARNING: [242] org.jitsi.jicofo.bridge.JvbDoctor.log() XMPP disconnected - skipping health check for: jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635
Jicofo 2020-06-04 12:44:40.808 WARNING: [242] org.jitsi.jicofo.bridge.JvbDoctor.log() XMPP disconnected - skipping health check for: jvbbrewery@internal.auth.jitsi.test.at/8ec02131-98c6-413b-9ae7-7ebd35c48635

jvb.log

2020-06-04 12:44:02.879 INFO: [161] Videobridge.createConference#290: create_conf, id=6e0a97ce5b036079 gid=ffd55e logging=true
2020-06-04 12:44:02.885 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e conf_name=test ufrag=4bq711e9vlo7e4] Agent.gatherCandidates#662: Gathering candidates for component stream-d74f8a15.RTP.
2020-06-04 12:44:02.885 INFO: [35] [confId=6e0a97ce5b036079 gid=ffd55e conf_name=test] Conference.dominantSpeakerChanged#461: ds_change ds_id=d74f8a15
2020-06-04 12:44:02.890 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e conf_name=test] Endpoint.lambda$setTransportInfo$8#1110: Ignoring empty DtlsFingerprint extension:
2020-06-04 12:44:02.891 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e conf_name=test] Endpoint.describe#1293: Transport description:
E1:82:F3:27:6F:75:55:87:50:3E:0E:8F:F4:BC:31:9C:73:2F:23:A2:C0:DD:E9:FD:C7:41:11:4C:68:93:77:67
2020-06-04 12:44:02.904 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e conf_name=test ufrag=8m14r1e9vlo7eo] Agent.gatherCandidates#662: Gathering candidates for component stream-4726ab68.RTP.
2020-06-04 12:44:02.918 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e conf_name=test] Endpoint.lambda$setTransportInfo$8#1110: Ignoring empty DtlsFingerprint extension:
2020-06-04 12:44:02.919 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e conf_name=test] Endpoint.describe#1293: Transport description:
E1:82:F3:27:6F:75:55:87:50:3E:0E:8F:F4:BC:31:9C:73:2F:23:A2:C0:DD:E9:FD:C7:41:11:4C:68:93:77:67
2020-06-04 12:44:03.407 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DtlsTransport.setSetupAttribute#120: The remote side is acting as DTLS server, we’ll act as client
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.initCheckLists#996: Init checklist for stream stream-4726ab68
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.setState#963: ICE state changed from Waiting to Running.
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-06-04 12:44:03.409 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.triggerCheck#1773: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
LocalCandidate=candidate:1 1 udp 2130706431 172.31.44.158 10000 typ host
RemoteCandidate=candidate:10000 1 udp 1853824767 194.208.156.193 36057 typ prflx
2020-06-04 12:44:03.410 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-06-04 12:44:03.410 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint.describe#1293: Transport description:
E1:82:F3:27:6F:75:55:87:50:3E:0E:8F:F4:BC:31:9C:73:2F:23:A2:C0:DD:E9:FD:C7:41:11:4C:68:93:77:67
2020-06-04 12:44:03.415 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC componentId=1 conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-4726ab68.RTP: 192.168.178.103:62434/udp
2020-06-04 12:44:03.415 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC componentId=1 conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Component.updateRemoteCandidates#481: new Pair added: 172.31.44.158:10000/udp/host -> 192.168.178.103:62434/udp/host (stream-4726ab68.RTP).
2020-06-04 12:44:03.415 INFO: [161] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint.describe#1293: Transport description:
E1:82:F3:27:6F:75:55:87:50:3E:0E:8F:F4:BC:31:9C:73:2F:23:A2:C0:DD:E9:FD:C7:41:11:4C:68:93:77:67
2020-06-04 12:44:03.440 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] DtlsTransport.setSetupAttribute#120: The remote side is acting as DTLS server, we’ll act as client
2020-06-04 12:44:03.441 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-06-04 12:44:03.441 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-06-04 12:44:03.441 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.initCheckLists#996: Init checklist for stream stream-d74f8a15
2020-06-04 12:44:03.441 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.setState#963: ICE state changed from Waiting to Running.
2020-06-04 12:44:03.441 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-06-04 12:44:03.441 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-06-04 12:44:03.442 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.triggerCheck#1773: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7926369428998979583):
LocalCandidate=candidate:1 1 udp 2130706431 172.31.44.158 10000 typ host
RemoteCandidate=candidate:10000 1 udp 1845501695 172.31.10.175 53878 typ prflx
2020-06-04 12:44:03.445 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.triggerCheck#1773: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7926369428998979583):
LocalCandidate=candidate:1 1 udp 2130706431 172.31.44.158 10000 typ host
RemoteCandidate=candidate:10003 1 udp 1845501695 18.157.184.94 53878 typ prflx
2020-06-04 12:44:03.445 INFO: [161] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-06-04 12:44:03.446 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint.describe#1293: Transport description:
E1:82:F3:27:6F:75:55:87:50:3E:0E:8F:F4:BC:31:9C:73:2F:23:A2:C0:DD:E9:FD:C7:41:11:4C:68:93:77:67
2020-06-04 12:44:03.467 INFO: [161] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint.describe#1293: Transport description:
E1:82:F3:27:6F:75:55:87:50:3E:0E:8F:F4:BC:31:9C:73:2F:23:A2:C0:DD:E9:FD:C7:41:11:4C:68:93:77:67
2020-06-04 12:44:03.476 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.44.158:10000/udp/host -> 172.31.10.175:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.477 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri componentId=1 conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 172.31.10.175:53878/udp
2020-06-04 12:44:03.477 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 172.31.44.158:10000/udp/host -> 172.31.10.175:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.477 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 172.31.44.158:10000/udp/host -> 172.31.10.175:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.477 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.nominate#1846: verify if nominated pair answer again
2020-06-04 12:44:03.477 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:false.
2020-06-04 12:44:03.481 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.44.158:10000/udp/host -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.482 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC componentId=1 conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 194.208.156.193:36057/udp
2020-06-04 12:44:03.482 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.483 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.483 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.nominate#1846: verify if nominated pair answer again
2020-06-04 12:44:03.483 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:false.
2020-06-04 12:44:03.483 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.44.158:10000/udp/host -> 18.157.184.94:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.484 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri componentId=1 conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 18.157.184.94:53878/udp
2020-06-04 12:44:03.484 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 18.157.126.134:10000/udp/srflx -> 18.157.184.94:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.484 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:false.
2020-06-04 12:44:03.485 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.44.158:10000/udp/host -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.486 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.487 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:false.
2020-06-04 12:44:03.487 INFO: [265] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 172.31.44.158:10000/udp/host -> 192.168.178.103:62434/udp/host (stream-4726ab68.RTP)
2020-06-04 12:44:03.502 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 172.31.44.158:10000/udp/host -> 172.31.10.175:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.505 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:true.
2020-06-04 12:44:03.506 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] ConnectivityCheckClient.processSuccessResponse#720: Nomination confirmed for pair: 172.31.44.158:10000/udp/host -> 172.31.10.175:53878/udp/prflx (stream-d74f8a15.RTP).
2020-06-04 12:44:03.506 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-d74f8a15.RTP: 172.31.44.158:10000/udp/host -> 172.31.10.175:53878/udp/prflx (stream-d74f8a15.RTP)
2020-06-04 12:44:03.507 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.checkListStatesUpdated#1937: CheckList of stream stream-d74f8a15 is COMPLETED
2020-06-04 12:44:03.507 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.setState#963: ICE state changed from Running to Completed.
2020-06-04 12:44:03.507 INFO: [255] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-06-04 12:44:03.507 INFO: [255] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint$3.connected#399: ICE connected
2020-06-04 12:44:03.508 INFO: [244] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] DtlsTransport.startDtlsHandshake#98: Starting DTLS handshake
2020-06-04 12:44:03.509 INFO: [255] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.logCandTypes#2045: Harvester used for selected pair for stream-d74f8a15.RTP: host
2020-06-04 12:44:03.512 INFO: [244] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-06-04 12:44:03.532 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.532 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.537 INFO: [244] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint$6.handshakeComplete#443: DTLS handshake complete
2020-06-04 12:44:03.546 INFO: [267] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint.lambda$acceptSctpConnection$6#942: Attempting to establish SCTP socket connection
2020-06-04 12:44:03.550 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:true.
2020-06-04 12:44:03.550 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] ConnectivityCheckClient.processSuccessResponse#720: Nomination confirmed for pair: 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP).
2020-06-04 12:44:03.550 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-4726ab68.RTP: 18.157.126.134:10000/udp/srflx -> 194.208.156.193:36057/udp/prflx (stream-4726ab68.RTP)
2020-06-04 12:44:03.553 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.checkListStatesUpdated#1937: CheckList of stream stream-4726ab68 is COMPLETED
2020-06-04 12:44:03.553 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.setState#963: ICE state changed from Running to Completed.
2020-06-04 12:44:03.553 INFO: [266] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-06-04 12:44:03.554 INFO: [266] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint$3.connected#399: ICE connected
2020-06-04 12:44:03.557 INFO: [266] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.logCandTypes#2045: Harvester used for selected pair for stream-4726ab68.RTP: srflx
2020-06-04 12:44:03.557 INFO: [268] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DtlsTransport.startDtlsHandshake#98: Starting DTLS handshake
2020-06-04 12:44:03.579 INFO: [268] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-06-04 12:44:03.605 INFO: [268] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint$6.handshakeComplete#443: DTLS handshake complete
2020-06-04 12:44:03.614 INFO: [269] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint.lambda$acceptSctpConnection$6#942: Attempting to establish SCTP socket connection
2020-06-04 12:44:03.635 INFO: [268] [confId=6e0a97ce5b036079 gid=ffd55e conf_name=test] Conference.dominantSpeakerChanged#461: ds_change ds_id=4726ab68
2020-06-04 12:44:06.306 INFO: [18] Videobridge.createConference#290: create_conf, id=ba41eadc535d74b0 gid=null logging=false
2020-06-04 12:44:06.383 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.077S. Sticky failure: false
2020-06-04 12:44:06.509 INFO: [261] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri conf_name=test ufrag=4bq711e9vlo7e4 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-06-04 12:44:06.509 INFO: [261] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
2020-06-04 12:44:06.557 INFO: [261] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test ufrag=8m14r1e9vlo7eo epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-06-04 12:44:06.557 INFO: [261] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
Got sctp association state update: 1
sctp is now up. was ready? false
2020-06-04 12:44:06.673 INFO: [267] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint$7.onReady#882: SCTP connection is ready, creating the Data channel stack
2020-06-04 12:44:06.673 INFO: [267] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint$7.onReady#909: Will wait for the remote side to open the data channel.
2020-06-04 12:44:06.673 SEVERE: [274] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-06-04 12:44:06.673 INFO: [274] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-06-04 12:44:06.674 INFO: [274] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint$7.lambda$onReady$1#890: Remote side opened a data channel.
Got sctp association state update: 1
sctp is now up. was ready? false
2020-06-04 12:44:07.057 INFO: [269] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint$7.onReady#882: SCTP connection is ready, creating the Data channel stack
2020-06-04 12:44:07.058 INFO: [269] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint$7.onReady#909: Will wait for the remote side to open the data channel.
2020-06-04 12:44:07.058 SEVERE: [275] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-06-04 12:44:07.058 SEVERE: [275] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-06-04 12:44:07.058 SEVERE: [275] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-06-04 12:44:07.058 SEVERE: [275] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-06-04 12:44:07.058 INFO: [275] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-06-04 12:44:07.058 INFO: [275] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint$7.lambda$onReady$1#890: Remote side opened a data channel.
2020-06-04 12:44:09.254 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] AbstractEndpoint.expire#303: Expiring.
2020-06-04 12:44:09.255 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Transceiver.teardown#315: Tearing down
2020-06-04 12:44:09.255 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] RtpReceiverImpl.tearDown#287: Tearing down
2020-06-04 12:44:09.255 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] RtpSenderImpl.tearDown#263: Tearing down
2020-06-04 12:44:09.257 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] DtlsTransport.stop#180: Stopping
2020-06-04 12:44:09.257 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.stop#235: Stopping
2020-06-04 12:44:09.257 INFO: [254] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri componentId=1 conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] MergingDatagramSocket$SocketContainer.runInReaderThread#770: Failed to receive: java.net.SocketException: Socket closed
2020-06-04 12:44:09.257 WARNING: [254] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri componentId=1 conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] MergingDatagramSocket.doRemove#349: Removing the active socket. Won’t be able to send until a new one is elected.
2020-06-04 12:44:09.259 INFO: [236] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri componentId=1 conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] MergingDatagramSocket.close#142: Closing.
2020-06-04 12:44:09.259 INFO: [35] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.startReadingData#201: Socket closed, stopping reader
2020-06-04 12:44:09.259 INFO: [35] [confId=6e0a97ce5b036079 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4 gid=ffd55e stats_id=jibri conf_name=test] IceTransport.startReadingData#213: No longer running, stopped reading packets
2020-06-04 12:44:09.259 INFO: [260] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=jibri componentId=1 conf_name=test ufrag=4bq711e9vlo7e4 name=stream-d74f8a15 epId=d74f8a15 local_ufrag=4bq711e9vlo7e4] MergingDatagramSocket$SocketContainer.runInReaderThread#770: Failed to receive: java.net.SocketException: Socket closed
2020-06-04 12:44:09.259 INFO: [236] [confId=6e0a97ce5b036079 epId=d74f8a15 gid=ffd55e stats_id=jibri conf_name=test] Endpoint.expire#809: Expired.
2020-06-04 12:44:16.306 INFO: [18] Videobridge.createConference#290: create_conf, id=a6ea8dd69c96323d gid=null logging=false
2020-06-04 12:44:16.309 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.003S. Sticky failure: false
2020-06-04 12:44:26.306 INFO: [18] Videobridge.createConference#290: create_conf, id=908b2c4478ba4bd1 gid=null logging=false
2020-06-04 12:44:26.312 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.006S. Sticky failure: false
2020-06-04 12:44:29.288 INFO: [244] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-06-04 12:44:29.295 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] AbstractEndpoint.expire#303: Expiring.
2020-06-04 12:44:29.295 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Transceiver.teardown#315: Tearing down
2020-06-04 12:44:29.295 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] RtpReceiverImpl.tearDown#287: Tearing down
2020-06-04 12:44:29.296 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] RtpSenderImpl.tearDown#263: Tearing down
2020-06-04 12:44:29.296 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] DtlsTransport.stop#180: Stopping
2020-06-04 12:44:29.296 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.stop#235: Stopping
2020-06-04 12:44:29.296 INFO: [275] [confId=6e0a97ce5b036079 gid=ffd55e conf_name=test] Conference.dominantSpeakerChanged#461: ds_change ds_id=null
2020-06-04 12:44:29.298 INFO: [258] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC componentId=1 conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] MergingDatagramSocket$SocketContainer.runInReaderThread#770: Failed to receive: java.net.SocketException: Socket closed
2020-06-04 12:44:29.298 WARNING: [258] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC componentId=1 conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] MergingDatagramSocket.doRemove#349: Removing the active socket. Won’t be able to send until a new one is elected.
2020-06-04 12:44:29.298 INFO: [236] [confId=6e0a97ce5b036079 gid=ffd55e stats_id=Rigoberto-NsC componentId=1 conf_name=test ufrag=8m14r1e9vlo7eo name=stream-4726ab68 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo] MergingDatagramSocket.close#142: Closing.
2020-06-04 12:44:29.298 INFO: [236] [confId=6e0a97ce5b036079 epId=4726ab68 gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] Endpoint.expire#809: Expired.
2020-06-04 12:44:29.299 INFO: [244] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.startReadingData#201: Socket closed, stopping reader
2020-06-04 12:44:29.299 INFO: [244] [confId=6e0a97ce5b036079 epId=4726ab68 local_ufrag=8m14r1e9vlo7eo gid=ffd55e stats_id=Rigoberto-NsC conf_name=test] IceTransport.startReadingData#213: No longer running, stopped reading packets
2020-06-04 12:44:36.306 INFO: [18] Videobridge.createConference#290: create_conf, id=ddc16f914f40b995 gid=null logging=false
2020-06-04 12:44:36.309 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.003S. Sticky failure: false
2020-06-04 12:44:45.852 INFO: [16] VideobridgeExpireThread.expire#144: Running expire()
2020-06-04 12:44:45.852 INFO: [16] VideobridgeExpireThread.expire#150: Conference 6e0a97ce5b036079 should expire, expiring it
2020-06-04 12:44:45.852 INFO: [277] [confId=6e0a97ce5b036079 gid=ffd55e conf_name=test] Conference.expire#542: Expiring.
2020-06-04 12:44:45.852 INFO: [277] [confId=6e0a97ce5b036079 gid=ffd55e conf_name=test] Conference.updateStatisticsOnExpire#625: expire_conf,duration=43,has_failed=false,has_partially_failed=false
2020-06-04 12:44:46.306 INFO: [18] Videobridge.createConference#290: create_conf, id=6a24fe56f3d20108 gid=null logging=false
2020-06-04 12:44:46.310 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.004S. Sticky failure: false
2020-06-04 12:44:56.307 INFO: [18] Videobridge.createConference#290: create_conf, id=7035bad866936b36 gid=null logging=false
2020-06-04 12:44:56.399 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.093S. Sticky failure: false
2020-06-04 12:45:06.306 INFO: [18] Videobridge.createConference#290: create_conf, id=9610e5d5ff32ea2a gid=null logging=false
2020-06-04 12:45:06.310 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.003S. Sticky failure: false
2020-06-04 12:45:16.306 INFO: [18] Videobridge.createConference#290: create_conf, id=130f297f0ec761a0 gid=null logging=false
2020-06-04 12:45:16.310 INFO: [18] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.004S. Sticky failure: false

prosody.log

Jun 04 12:43:37 c2s555aaa369e20 info Authenticated as jibri@auth.jitsi.test.at
Jun 04 12:44:00 conference.jitsi.test.at:muc_domain_mapper warn Session filters applied
Jun 04 12:44:00 mod_bosh info New BOSH session, assigned it sid ‘56c619d6-a17b-4d0a-b7ee-dd6f688f1a4a’
Jun 04 12:44:01 general warn Error verifying token err:not-allowed, reason:token required
Jun 04 12:44:01 bosh56c619d6-a17b-4d0a-b7ee-dd6f688f1a4a info BOSH client disconnected: session close
Jun 04 12:44:02 conference.jitsi.test.at:muc_domain_mapper warn Session filters applied
Jun 04 12:44:02 mod_bosh info New BOSH session, assigned it sid ‘3610d3fc-cb37-463b-af0e-95e4560ffd22’
Jun 04 12:44:02 bosh3610d3fc-cb37-463b-af0e-95e4560ffd22 info Authenticated as recorder@recorder.jitsi.test.at
Jun 04 12:44:15 c2s555aaa369e20 info Client disconnected: closed

Is your problem there

Thanks a lot for your comment.
You are right.

After the first boot process the used kernel is:

sudo uname -a
Linux ip-172-31-10-25 4.4.0-179-generic #209-Ubuntu SMP Fri Apr 24 17:48:44 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

after sudo reboot:

Linux ip-172-31-10-25 4.4.0-1105-aws #116-Ubuntu SMP Wed Mar 18 05:11:57 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

I have no idea why the kernel changes after reboot.

Previously I changed the kernel as described in: https://stackoverflow.com/questions/49538514/sound-driver-snd-aloop-kernel-module-setup-issue-with-aws-ec2-ubuntu-16-04-ins?answertab=active#tab-top

Suddenly after booting in grub are 4 AWS kernels and therefore my changes started the wrong kernel.

So if your kernels number increase and you can’t rely on default kernel pinning in grub, most probably you have unattended upgrades enabled. Ubuntu comes by default with unattended upgrades configured for kernel (IIRC unlike Debian).

You can check in /etc/apt/apt.conf.d/50unattended-upgrades and add to Package-Blacklist something like:

“linux-image”

or maybe even

“linux-*”

And your kernels won’t upgrade automatically, the numbering in grub will stay the same.

https://wiki.debian.org/UnattendedUpgrades

Thanks for your answer. That’s the solution.

This post was flagged by the community and is temporarily hidden.