Jibri Recording unable to start despite everything working fine


#1

Successfully installed jibri, jicofo and jitsi-meet. jicofo ver is 1.0-425-1; jibri version: 5.0.57-1
and jitsi-meet ver:
ii jitsi-meet 1.0.3229-1 all WebRTC JavaScript video conferences
ii jitsi-meet-prosody 1.0.2942-1 all Prosody configuration for Jitsi Meet
ii jitsi-meet-web 1.0.2942-1 all WebRTC JavaScript video conferences
ii jitsi-meet-web-config 1.0.2942-1 all Configuration for web serving of Jitsi Meet
trinetra@ubuntu:/home/jibri$

This is the status upon running : sudo systemctl status jibri:
jibri.service - Jibri Process
Loaded: loaded (/etc/systemd/system/jibri.service; disabled; vendor preset: enabled)
Active: active (running) since Fri 2018-08-17 01:28:32 IST; 11s ago
Process: 124975 ExecStop=/opt/jitsi/jibri/graceful_shutdown.sh (code=exited, status=7)
Main PID: 124984 (java)
Tasks: 45
Memory: 175.4M
CPU: 4.776s
CGroup: /system.slice/jibri.service
└─124984 java -Djava.util.logging.config.file=/etc/jitsi/jibri/logging.properties -jar /opt/jitsi/jibri/jibri.jar --config /etc/jitsi/jibri/config.json

Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.058 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accept
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.720 INFO: [1] class org.jitsi.xmpp.mucclient.MucClient.connected()
[SilvertipXMPPServer: auth.meet.silvertip.in@meet.silvertip.in] Xmpp connection status: connected
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.809 INFO: [1] class org.jitsi.xmpp.mucclient.MucClient.authenticated()
[SilvertipXMPPServer: auth.meet.silvertip.in@meet.silvertip.in] Xmpp connection status: authe
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.830:WARN:oejsh.ContextHandler:main: o.e.j.s.ServletContextHandler@265c5d69{/,null,null} contextPath ends with /*
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.830:WARN:oejsh.ContextHandler:main: Empty contextPath
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.831:INFO:oejs.Server:main: jetty-9.2.z-SNAPSHOT
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.884 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.HttpApi registered in SERVER runtime does
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.926:INFO:oejsh.ContextHandler:main: Started o.e.j.s.ServletContextHandler@265c5d69{/,null,AVAILABLE}
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.926:INFO:oejs.ServerConnector:main: Started ServerConnector@3aefae67{HTTP/1.1}{0.0.0.0:2222}
Aug 17 01:28:34 ubuntu launch.sh[124984]: 2018-08-17 01:28:34.927:INFO:oejs.Server:main: Started @2751ms

However, when clicking on the “Start Recording” I get “Recording failed to start”
Here is the console errors I noticed, from the browser:
Logger.js:125 [JitsiMeetJS.js] <Object.getGlobalOnErrorHandler>: UnhandledError: null Script: null Line: null Column: null StackTrace: <iq xmlns=​"jabber:​client" type=​"error" to=​"a45fca85-31af-4a5b-a71f-b68226e5089e@meet.silvertip.in/​c4a8dd97-0515-4a13-9122-2f4c2174c908" from=​"gopal@conference.meet.silvertip.in/​focus" id=​"4f4ae29a-e5f3-485a-b089-fe78aa3a5ce3:​sendIQ">​<error type=​"cancel">​<item-not-found xmlns=​"urn:​ietf:​params:​xml:​ns:​xmpp-stanzas">​​​​
n @ Logger.js:125
getGlobalOnErrorHandler @ JitsiMeetJS.js:539
window.onunhandledrejection @ middleware.js:111
Uncaught (in promise)

Please help me debug this issue.


#2

Can you attach Jibri and Jicofo logs?


#3

Note: new users are not allowed to upload logs. Hence pasting a portion of each of the logs (the rest actually is a repetition):


#4

As a new user, i get this message and am prevented from posting loggs, etc…
Sorry, new users can only mention 2 users in a pos


#5

Here are the links for jicofo and jibri logs:
https://silvertip.in/jicofo.log.1
https://silvertip.in/log.0.txt


#6

From those logs, Jibri is unable to connect to the xmpp server:

2018-08-17 01:44:36.897 WARNING: [25] org.jivesoftware.smack.AbstractXMPPConnection.callConnectionClosedOnErrorListener() Connection XMPPTCPConnection[jibri@auth.meet.silvertip.in/12e07d28-8c7f-471d-bb6e-6b0ec0b74ed4] (0) closed with error
java.net.SocketException: Connection timed out (Read failed)

#7

Thanks for the diagnosis. So, was there anything I missed ? How do i resolve this?


#8

per the above, did it initially connect and later got disconnected ?


#9

I rebooted the server and tried again: here’s in interesting new message " All recorders are currently busy. We are working freeing recording resources. Please try later " What does this mean ? Am just having one instance of recording session…


#10

I believe that means that Jicofo did see the Jibri, but the Jibri reported itself as busy. Again, Jicofo/Jibri logs would be useful.


#11

I restarted all services again (jicofo and jibri) and now upon clicking the start recording button i get a voice message that says “recording has stopped” followed by a text message that says “recording failed to start”. I checked the /tmp/recordings folder. There is nothing there. Note: this is folder has the full read/write permission and owner is changed to “jibri” and “jitsi”

You can access the latest logs from these links below:

https://silvertip.in/jicofo.log
https://silvertip.in/log.0.txt
https://silvertip.in/log.3.txt

NOTE: Here’s the output of : sudo systemctl status jibri (ran it just now):
jibri.service - Jibri Process
Loaded: loaded (/etc/systemd/system/jibri.service; disabled; vendor preset: enabled)
Active: active (running) since Sat 2018-08-18 00:47:51 IST; 2s ago
Process: 48706 ExecStop=/opt/jitsi/jibri/graceful_shutdown.sh (code=exited, status=7)
Main PID: 48712 (java)
Tasks: 100
Memory: 247.0M
CPU: 4.481s
CGroup: /system.slice/jibri.service
├─ 4052 /usr/local/bin/chromedriver --port=20350 --log-path=/tmp/chromedriver.log
├─ 5266 /usr/local/bin/chromedriver --port=3801 --log-path=/tmp/chromedriver.log
├─ 6980 /usr/local/bin/chromedriver --port=14512 --log-path=/tmp/chromedriver.log
├─ 7598 /usr/local/bin/chromedriver --port=15155 --log-path=/tmp/chromedriver.log
├─ 7674 /usr/local/bin/chromedriver --port=28934 --log-path=/tmp/chromedriver.log
├─20216 /usr/local/bin/chromedriver --port=9747 --log-path=/tmp/chromedriver.log
├─20980 /usr/local/bin/chromedriver --port=22026 --log-path=/tmp/chromedriver.log
├─21760 /usr/local/bin/chromedriver --port=14944 --log-path=/tmp/chromedriver.log
├─31567 /usr/local/bin/chromedriver --port=30604 --log-path=/tmp/chromedriver.log
├─31683 /usr/local/bin/chromedriver --port=29444 --log-path=/tmp/chromedriver.log
├─31838 /usr/local/bin/chromedriver --port=26541 --log-path=/tmp/chromedriver.log
└─48712 java -Djava.util.logging.config.file=/etc/jitsi/jibri/logging.properties -jar /opt/jitsi/jibri/jibri.jar --config /etc/jitsi/jibri/config.json

Aug 18 00:47:53 ubuntu launch.sh[48712]: 2018-08-18 00:47:53.675:INFO:oejs.ServerConnector:main: Started ServerConnector@48c40605{HTTP/1.1}{0.0.0.0:3333}
Aug 18 00:47:53 ubuntu launch.sh[48712]: 2018-08-18 00:47:53.675:INFO:oejs.Server:main: Started @1705ms
Aug 18 00:47:53 ubuntu launch.sh[48712]: 2018-08-18 00:47:53.814 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() Connecting to xmpp environment on 49.206.254.42 with config XmppEnviron
Aug 18 00:47:53 ubuntu launch.sh[48712]: 2018-08-18 00:47:53.822 INFO: [1] org.jitsi.jibri.api.xmpp.XmppApi.start() The trustAllXmppCerts config is enabled for this domain, all XMPP serve
Aug 18 00:47:54 ubuntu launch.sh[48712]: 2018-08-18 00:47:54.087 INFO: [1] class org.jitsi.xmpp.mucclient.MucClient.connected() [SilvertipXMPPServer: auth.meet.silvertip.in@49.206.254.42]
Aug 18 00:47:54 ubuntu launch.sh[48712]: 2018-08-18 00:47:54.188 INFO: [1] class org.jitsi.xmpp.mucclient.MucClient.authenticated() [SilvertipXMPPServer: auth.meet.silvertip.in@49.206.254
Aug 18 00:47:54 ubuntu launch.sh[48712]: 2018-08-18 00:47:54.223:WARN:oejsh.ContextHandler:main: o.e.j.s.ServletContextHandler@265c5d69{/,null,null} contextPath ends with /*
Aug 18 00:47:54 ubuntu launch.sh[48712]: 2018-08-18 00:47:54.223:WARN:oejsh.ContextHandler:main: Empty contextPath
Aug 18 00:47:54 ubuntu launch.sh[48712]: 2018-08-18 00:47:54.223:INFO:oejs.Server:main: jetty-9.2.z-SNAPSHOT
Aug 18 00:47:54 ubuntu launch.sh[48712]: 2018-08-18 00:47:54.265 WARNING: [1] org.glassfish.jersey.internal.inject.Providers.checkProviderRuntime() A provider org.jitsi.jibri.api.http.Htt
lines 1-32/32 (END)


#12

Here’s a snippet of /tmp/chromedriver.log :

[1534533509.127][INFO]: Launching chrome: /usr/bin/google-chrome --alsa-output-device=plug:amix --disable-background-networking --disable-client-side-phishing-detection --disable-default-apps --disable-hang-monitor --disable-infobars --disable-popup-blocking --disable-prompt-on-repost --disable-sync --disable-web-resources --enable-automation --enable-logging --enabled --force-fieldtrials=SiteIsolationExtensions/Control --ignore-certificate-errors --kiosk --load-extension=/tmp/.org.chromium.Chromium.MTZZIy/internal --log-level=0 --metrics-recording-only --no-first-run --password-store=basic --remote-debugging-port=0 --start-maximized --test-type=webdriver --use-fake-ui-for-media-stream --use-mock-keychain --user-data-dir=/tmp/.org.chromium.Chromium.1265rV --vmodule=*=3 data:,
[1534533509.287][INFO]: RESPONSE InitSession unknown error: Chrome failed to start: exited abnormally
(unknown error: DevToolsActivePort file doesn’t exist)
(The process started from chrome location /usr/bin/google-chrome is no longer running, so ChromeDriver is assuming that Chrome has crashed.)


#13

Do you have enough memory on the machine running jibri?


#14

The machine that runs jibri, jicofo and jvb has 16GB RAM. Is that not enought ? BTW, I increased the memory to 32 GB RAM, issue still remains - i first see the message " Recording has started" then quickly then quickly followed by another message " Recording Failed to start" with an accompanying voice message “Recording has stopped”


#15

This is the output of “free -m” :
free -m
total used free shared buff/cache available
Mem: 32157 1761 29020 82 1375 29851
Swap: 974 0 974


#16

32 even 16, should be enough. I was asking cause I was seeing chrome crashes when there is not enough ram.