Failed to grant owner status in Jicofo: Probably muc component connection failing in jicofo

Hi there,

I have successfully deployed docker-jitsi-meet to my aws instance and also configured a docker image for Jibri.
I am trying to integrate jibri now, but i am unable to do so.

I have setup token authentication in prosody.
Prosody successfully authenticates jibri, but I get errors in jicofo and jibri.

These are jicofo logs when i join a room.

jicofo.txt (4.0 KB)

These are jibri logs

jibri.txt (6.9 KB)

After i start the meeting i get this in Jibri.

jibri-after-recording.txt (9.0 KB)

ffmpeg does not get anything and closes. I think jicofo’s connection to the muc component is failing.

Please help me out.

This is the error I see:

2019-11-05 11:45:56.814 INFO: [35] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegProcessUpdate() Ffmpeg quit abruptly.  Last output line: plug:cloop: Input/output error
2019-11-05 11:45:56.816 INFO: [35] org.jitsi.jibri.capture.ffmpeg.FfmpegCapturer.onFfmpegStateMachineStateChange() Ffmpeg capturer transitioning from state Starting up to Error: SESSION Ffmpeg failed to start

Yes, Can you help me understand why this is happening? I feel as if something is wrong with jicofo.
Whenever i join the room, i get this in Jicofo logs

Jicofo 2019-11-05 12:06:05.219 INFO: [37] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@b6fa937 member=ChatMember[test@muc.meet.jitsi/b5bcb5dd, jid: null]@851155753]

Jicofo 2019-11-05 12:06:05.223 SEVERE: [37] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Failed to grant owner status to b5bcb5dd-6b71-4af9-84f9-80b860396509@meet.jitsi/ipJXbI8x

java.lang.RuntimeException: Failed to grant owner: <iq to='focus@auth.meet.jitsi/focus24618975078422' from='test@muc.meet.jitsi' id='X9r6x-132' 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.checkGrantOwnerToAuthUser(ChatRoomRoleAndPresence.java:357)

at org.jitsi.jicofo.ChatRoomRoleAndPresence.memberPresenceChanged(ChatRoomRoleAndPresence.java:163)

at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.lambda$notifyMemberJoined$1(ChatRoomImpl.java:915)

at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)

at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.notifyMemberJoined(ChatRoomImpl.java:915)

at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.processOtherPresence(ChatRoomImpl.java:1198)

at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.processPresence(ChatRoomImpl.java:1239)

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 2019-11-05 12:06:05.224 INFO: [37] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@muc.meet.jitsi/b5bcb5dd joined.

Also, i noticed that the jid is null in the logs. I am totally lost.

Post your prosody config. I suspect your jicofo is not an admin in prosody.


You may try moving this line in your main prosody config before any host or component definition and restart prosody, jvb, jicofo and then try again.

I have. Here is my prosody config.

admins = { "focus@auth.meet.jitsi" }
plugin_paths = { "/prosody-plugins/", "/prosody-plugins-custom" }
http_default_host = "meet.jitsi"

VirtualHost "meet.jitsi"
    authentication = "token"
    app_id = "<my_id>"
    app_secret = "<my_secret>"
    allow_empty_token = false
    ssl = {
        key = "/config/certs/meet.jitsi.key";
        certificate = "/config/certs/meet.jitsi.crt";
    }
    modules_enabled = {
        "bosh";
        "pubsub";
        "ping";
        "presence_identity";
        "muc_size";
    }

    c2s_require_encryption = false

VirtualHost "auth.meet.jitsi"
    ssl = {
        key = "/config/certs/auth.meet.jitsi.key";
        certificate = "/config/certs/auth.meet.jitsi.crt";
    }
    authentication = "internal_plain"

Component "internal-muc.meet.jitsi" "muc"
    modules_enabled = {
        "ping";
    }
    storage = "internal"
    muc_room_cache_size = 1000

VirtualHost "recorder.meet.jitsi"
    modules_enabled = {
        "ping";
    }
    authentication = "internal_plain"

Component "muc.meet.jitsi" "muc"
    storage = "memory"
    modules_enabled = {
        "token_verification";
    }

Component "focus.meet.jitsi"
    component_secret = "s3cr37"

And with this config you have the problem?

Yes :frowning:

I really think, this is something wrong with Jicofo. Can you please look at my logs and point me where i am going wrong?

Jicofo 2019-11-05 19:27:27.948 INFO: [10] org.jitsi.service.libjitsi.LibJitsi.log() Successfully started     LibJitsi using as implementation: org.jitsi.impl.libjitsi.LibJitsiOSGiImpl
Jicofo 2019-11-05 19:27:28.067 INFO: [10] impl.configuration.ConfigurationActivator.log() Using properties file configuration store.
Jicofo 2019-11-05 19:27:28.077 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.HOSTNAME=xmpp.meet.jitsi
Jicofo 2019-11-05 19:27:28.094 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.runtime.name=OpenJDK Runtime Environment
Jicofo 2019-11-05 19:27:28.094 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.boot.library.path=/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/amd64
Jicofo 2019-11-05 19:27:28.095 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.version=25.232-b09
Jicofo 2019-11-05 19:27:28.095 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.vendor=Oracle Corporation
Jicofo 2019-11-05 19:27:28.095 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vendor.url=http://java.oracle.com/
Jicofo 2019-11-05 19:27:28.097 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() path.separator=:
Jicofo 2019-11-05 19:27:28.098 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.util.logging.config.file=/config/logging.properties
Jicofo 2019-11-05 19:27:28.100 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.name=OpenJDK 64-Bit Server VM
Jicofo 2019-11-05 19:27:28.100 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() file.encoding.pkg=sun.io
Jicofo 2019-11-05 19:27:28.101 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() user.country=US
Jicofo 2019-11-05 19:27:28.101 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.java.launcher=SUN_STANDARD
Jicofo 2019-11-05 19:27:28.101 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.os.patch.level=unknown
Jicofo 2019-11-05 19:27:28.103 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() net.java.sip.communicator.service.media.DISABLE_AUDIO_SUPPORT=true
Jicofo 2019-11-05 19:27:28.104 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.specification.name=Java Virtual Machine Specification
Jicofo 2019-11-05 19:27:28.105 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() user.dir=/usr/share/jicofo
Jicofo 2019-11-05 19:27:28.109 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.FOCUS_USER_PASSWORD=**********
Jicofo 2019-11-05 19:27:28.109 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.runtime.version=1.8.0_232-8u232-b09-1~deb9u1-b09
Jicofo 2019-11-05 19:27:28.110 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment
Jicofo 2019-11-05 19:27:28.110 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.endorsed.dirs=/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/endorsed
Jicofo 2019-11-05 19:27:28.122 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() os.arch=amd64
Jicofo 2019-11-05 19:27:28.122 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.io.tmpdir=/tmp
Jicofo 2019-11-05 19:27:28.123 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() line.separator=

Jicofo 2019-11-05 19:27:28.124 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.specification.vendor=Oracle Corporation
Jicofo 2019-11-05 19:27:28.124 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() os.name=Linux
Jicofo 2019-11-05 19:27:28.124 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.jnu.encoding=ANSI_X3.4-1968
Jicofo 2019-11-05 19:27:28.124 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() net.java.sip.communicator.CONFIGURATION_FILE_IS_READ_ONLY=true
Jicofo 2019-11-05 19:27:28.125 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.FOCUS_USER_DOMAIN=auth.meet.jitsi
Jicofo 2019-11-05 19:27:28.125 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.library.path=/usr/share/jicofo/lib/native/linux-64
Jicofo 2019-11-05 19:27:28.126 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.specification.name=Java Platform API Specification
Jicofo 2019-11-05 19:27:28.126 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.class.version=52.0
Jicofo 2019-11-05 19:27:28.128 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.service.audionotifier.AudioNotifierService=org.jitsi.impl.neomedia.notify.AudioNotifierServiceImpl
Jicofo 2019-11-05 19:27:28.128 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.management.compiler=HotSpot 64-Bit Tiered Compilers
Jicofo 2019-11-05 19:27:28.130 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() os.version=4.15.0-66-generic
Jicofo 2019-11-05 19:27:28.130 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() user.home=/usr/share/jicofo
Jicofo 2019-11-05 19:27:28.133 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() user.timezone=Europe/Amsterdam
Jicofo 2019-11-05 19:27:28.134 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.awt.printerjob=sun.print.PSPrinterJob
Jicofo 2019-11-05 19:27:28.136 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.FOCUS_USER_NAME=focus
Jicofo 2019-11-05 19:27:28.137 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() file.encoding=ANSI_X3.4-1968
Jicofo 2019-11-05 19:27:28.137 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.specification.version=1.8
Jicofo 2019-11-05 19:27:28.137 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() net.java.sip.communicator.service.media.DISABLE_VIDEO_SUPPORT=true
Jicofo 2019-11-05 19:27:28.150 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.XMPP_DOMAIN=meet.jitsi
Jicofo 2019-11-05 19:27:28.150 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.class.path=/usr/share/jicofo/jicofo.jar:/usr/share/jicofo/lib/agafua-syslog-0.4.jar:/usr/share/jicofo/lib/annotations-15.0.jar:/usr/share/jicofo/lib/bccontrib-1.0.jar:/usr/share/jicofo/lib/bcpkix-jdk15on-1.54.jar:/usr/share/jicofo/lib/bcprov-jdk15on-1.54.jar:/usr/share/jicofo/lib/cglib-nodep-2.2.jar:/usr/share/jicofo/lib/commons-codec-1.6.jar:/usr/share/jicofo/lib/commons-lang3-3.1.jar:/usr/share/jicofo/lib/commons-logging-1.2.jar:/usr/share/jicofo/lib/concurrentlinkedhashmap-lru-1.0_jdk5.jar:/usr/share/jicofo/lib/core-2.0.1.jar:/usr/share/jicofo/lib/dnsjava-2.1.7.jar:/usr/share/jicofo/lib/dom4j-1.6.1.jar:/usr/share/jicofo/lib/fmj-1.0-20190327.151046-25.jar:/usr/share/jicofo/lib/guava-15.0.jar:/usr/share/jicofo/lib/httpclient-4.4.jar:/usr/share/jicofo/lib/httpcore-4.4.jar:/usr/share/jicofo/lib/ice4j-2.0.0-20190327.160542-32.jar:/usr/share/jicofo/lib/jain-sip-ri-ossonly-1.2.98c7f8c-jitsi-oss1.jar:/usr/share/jicofo/lib/java-dogstatsd-client-2.5.jar:/usr/share/jicofo/lib/java-sdp-nist-bridge-1.1.jar:/usr/share/jicofo/lib/javax.servlet-api-3.1.0.jar:/usr/share/jicofo/lib/jbosh-0.9.1.jar:/usr/share/jicofo/lib/jcip-annotations-1.0.jar:/usr/share/jicofo/lib/jcl-core-2.8.jar:/usr/share/jicofo/lib/jetty-client-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-http-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-io-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-proxy-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-security-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-server-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-servlet-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-util-9.4.15.v20190215.jar:/usr/share/jicofo/lib/jetty-webapp-7.0.1.v20091125.jar:/usr/share/jicofo/lib/jetty-xml-7.0.1.v20091125.jar:/usr/share/jicofo/lib/jicoco-1.1-1-ge7184ab.jar:/usr/share/jicofo/lib/jitsi-android-osgi-1.0-20180322.162617-2.jar:/usr/share/jicofo/lib/jitsi-configuration-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-credentialsstorage-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-dnsservice-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-netaddr-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-protocol-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-protocol-jabber-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-protocol-media-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-util-2.13.cb5485e.jar:/usr/share/jicofo/lib/jitsi-utils-1.0-1-gaca0e20.jar:/usr/share/jicofo/lib/jitsi-xmpp-extensions-1.0-0-gf132d05.jar:/usr/share/jicofo/lib/jna-4.1.0.jar:/usr/share/jicofo/lib/jnsapi-0.0.3-jitsi-smack4.2-3.jar:/usr/share/jicofo/lib/json-simple-1.1.1.jar:/usr/share/jicofo/lib/jxmpp-core-0.6.2.jar:/usr/share/jicofo/lib/jxmpp-jid-0.6.2.jar:/usr/share/jicofo/lib/jxmpp-util-cache-0.6.2.jar:/usr/share/jicofo/lib/libidn-1.15.jar:/usr/share/jicofo/lib/libjitsi-1.0-0-gb3296cf.jar:/usr/share/jicofo/lib/object-cloner-0.1.jar:/usr/share/jicofo/lib/objenesis-2.1.jar:/usr/share/jicofo/lib/orange-extensions-1.3.0.jar:/usr/share/jicofo/lib/org.apache.felix.framework-4.4.0.jar:/usr/share/jicofo/lib/org.apache.felix.main-4.4.0.jar:/usr/share/jicofo/lib/org.osgi.core-4.3.1.jar:/usr/share/jicofo/lib/sdes4j-1.1.3.jar:/usr/share/jicofo/lib/sdp-api-1.0.jar:/usr/share/jicofo/lib/slf4j-api-1.7.26.jar:/usr/share/jicofo/lib/slf4j-jdk14-1.7.26.jar:/usr/share/jicofo/lib/smack-bosh-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-core-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-debug-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-experimental-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-extensions-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-im-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-java7-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-legacy-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-resolver-javax-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-sasl-javax-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/smack-tcp-4.2.4-47d17fc.jar:/usr/share/jicofo/lib/tinder-1.3.0.jar:/usr/share/jicofo/lib/weupnp-0.1.4.jar:/usr/share/jicofo/lib/xml-apis-1.0.b2.jar:/usr/share/jicofo/lib/xmlpull-1.1.3.4a.jar:/usr/share/jicofo/lib/xpp3-1.1.4c.jar:/usr/share/jicofo/lib/zrtp4j-light-4.1.0-jitsi-1-20190327.161225-1.jar
Jicofo 2019-11-05 19:27:28.151 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() user.name=jicofo
Jicofo 2019-11-05 19:27:28.152 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.specification.version=1.8
Jicofo 2019-11-05 19:27:28.165 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.java.command=org.jitsi.jicofo.Main --domain=meet.jitsi --host=xmpp.meet.jitsi --secret=X --user_name=focus --user_domain=auth.meet.jitsi --user_password=X
Jicofo 2019-11-05 19:27:28.170 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.home=/usr/lib/jvm/java-8-openjdk-amd64/jre
Jicofo 2019-11-05 19:27:28.170 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.arch.data.model=64
Jicofo 2019-11-05 19:27:28.170 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() user.language=en
Jicofo 2019-11-05 19:27:28.172 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.specification.vendor=Oracle Corporation
Jicofo 2019-11-05 19:27:28.178 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() awt.toolkit=sun.awt.X11.XToolkit
Jicofo 2019-11-05 19:27:28.178 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vm.info=mixed mode
Jicofo 2019-11-05 19:27:28.178 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.version=1.8.0_232
Jicofo 2019-11-05 19:27:28.179 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.ext.dirs=/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/ext:/usr/java/packages/lib/ext
Jicofo 2019-11-05 19:27:28.182 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.boot.class.path=/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/resources.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/rt.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/sunrsasign.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/jsse.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/jce.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/charsets.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/jfr.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/classes
Jicofo 2019-11-05 19:27:28.182 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() net.java.sip.communicator.SC_HOME_DIR_LOCATION=/
Jicofo 2019-11-05 19:27:28.194 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vendor=Oracle Corporation
Jicofo 2019-11-05 19:27:28.194 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() file.separator=/
Jicofo 2019-11-05 19:27:28.200 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() net.java.sip.communicator.impl.configuration.USE_PROPFILE_CONFIG=true
Jicofo 2019-11-05 19:27:28.206 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() net.java.sip.communicator.SC_HOME_DIR_NAME=config
Jicofo 2019-11-05 19:27:28.206 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() java.vendor.url.bug=http://bugreport.sun.com/bugreport/
Jicofo 2019-11-05 19:27:28.207 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.io.unicode.encoding=UnicodeLittle
Jicofo 2019-11-05 19:27:28.208 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.cpu.endian=little
Jicofo 2019-11-05 19:27:28.209 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() sun.cpu.isalist=
Jicofo 2019-11-05 19:27:28.209 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() Normal classloader
Jicofo 2019-11-05 19:27:28.222 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() failed to find jitsi-defaults.properties with class loader, will continue without it.
Jicofo 2019-11-05 19:27:28.222 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() Normal classloader
Jicofo 2019-11-05 19:27:28.230 INFO: [10] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() failed to find jitsi-default-overrides.properties with class loader, will continue without it.
Jicofo 2019-11-05 19:27:28.278 SEVERE: [10] impl.configuration.ConfigurationActivator.log() Error creating c lib instance for fixing file permissions
java.nio.file.FileSystemException: /config: Operation not permitted
	at sun.nio.fs.UnixException.translateToIOException(UnixException.java:91)
	at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
	at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
	at sun.nio.fs.UnixFileAttributeViews$Posix.setMode(UnixFileAttributeViews.java:238)
	at sun.nio.fs.UnixFileAttributeViews$Posix.setPermissions(UnixFileAttributeViews.java:260)
	at java.nio.file.Files.setPosixFilePermissions(Files.java:2045)
	at net.java.sip.communicator.impl.configuration.ConfigurationActivator.fixPermissions(ConfigurationActivator.java:167)
	at net.java.sip.communicator.impl.configuration.ConfigurationActivator.start(ConfigurationActivator.java:88)
	at org.jitsi.impl.osgi.framework.BundleImpl.start(BundleImpl.java:307)
	at org.jitsi.impl.osgi.framework.launch.FrameworkImpl.startLevelChanged(FrameworkImpl.java:472)
	at org.jitsi.impl.osgi.framework.startlevel.FrameworkStartLevelImpl$Command.run(FrameworkStartLevelImpl.java:137)
	at org.jitsi.impl.osgi.framework.AsyncExecutor.runInThread(AsyncExecutor.java:122)
	at org.jitsi.impl.osgi.framework.AsyncExecutor.access$000(AsyncExecutor.java:28)
	at org.jitsi.impl.osgi.framework.AsyncExecutor$1.run(AsyncExecutor.java:231)
Jicofo 2019-11-05 19:27:28.348 INFO: [10] util.NetworkUtils.<clinit>().117 java.net.preferIPv6Addresses=null
Jicofo 2019-11-05 19:27:28.349 INFO: [10] util.NetworkUtils.<clinit>().118 java.net.preferIPv4Stack=null
Jicofo 2019-11-05 19:27:28.383 INFO: [10] impl.netaddr.NetworkAddressManagerServiceImpl.start().92 Network Address Manager         ...[  STARTED ]
Jicofo 2019-11-05 19:27:28.384 INFO: [10] impl.netaddr.NetworkAddressManagerServiceImpl.start().98 Network Address Manager Service ...[REGISTERED]
Jicofo 2019-11-05 19:27:28.411 INFO: [10] org.jitsi.version.AbstractVersionActivator.log() VersionService registered: JiCoFo 1.0.1.0-481
Jicofo 2019-11-05 19:27:29.747 INFO: [10] org.jitsi.jicofo.JitsiMeetGlobalConfig.init().205 Automatically grant 'owner' role: true
Jicofo 2019-11-05 19:27:29.747 INFO: [10] org.jitsi.jicofo.JitsiMeetGlobalConfig.init().218 Jibri requests in PENDING state will be timed out after: 90 seconds
Jicofo 2019-11-05 19:27:29.748 INFO: [10] org.jitsi.jicofo.JitsiMeetGlobalConfig.init().230 Will attempt a maximum of 5 Jibri retries after failure
Jicofo 2019-11-05 19:27:29.750 INFO: [10] org.jitsi.jicofo.JitsiMeetGlobalConfig.init().243 Lonely participants will be "terminated" after 20000 milliseconds
Jicofo 2019-11-05 19:27:29.848 INFO: [10] org.jitsi.jicofo.BridgeSelector.log() Using org.jitsi.jicofo.BridgeSelector$SingleBridgeSelectionStrategy
Jicofo 2019-11-05 19:27:29.851 INFO: [10] org.jitsi.jicofo.BridgeSelector.log() Bridge failure reset threshold: 300000
Jicofo 2019-11-05 19:27:29.851 INFO: [10] org.jitsi.jicofo.BridgeSelector.log() Local region: null
Jicofo 2019-11-05 19:27:29.866 INFO: [10] org.jitsi.jicofo.JitsiMeetServices.log() Using a Jibri detector with MUC: jibribrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:29.868 INFO: [10] org.jitsi.jicofo.JitsiMeetServices.log() Using a Jigasi detector with MUC: jigasibrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:29.869 INFO: [10] org.jitsi.jicofo.JitsiMeetServices.log() Using a Bridge MUC detector with MUC: jvbbrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:29.953 INFO: [10] org.jitsi.jicofo.auth.AuthBundleActivator.start().188 Starting authentication service... URL: XMPP:meet.jitsi
Jicofo 2019-11-05 19:27:29.963 WARNING: [14] org.jitsi.impl.protocol.xmpp.XmppProtocolProvider.register().224 The always_trust config option is enabled. All XMPP server provided certificates are accepted.
Jicofo 2019-11-05 19:27:29.982 INFO: [10] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authentication lifetime: 86400000
Jicofo 2019-11-05 19:27:29.990 INFO: [10] org.jitsi.jicofo.auth.AuthBundleActivator.start().217 Auth authority: org.jitsi.jicofo.auth.XMPPDomainAuthAuthority@5ead0733
Jicofo 2019-11-05 19:27:30.119 INFO: [10] org.eclipse.jetty.util.log.initialized() Logging initialized @3134ms to org.eclipse.jetty.util.log.Slf4jLog
Jicofo 2019-11-05 19:27:31.174 INFO: [10] org.eclipse.jetty.server.Server.doStart() jetty-9.4.15.v20190215; built: 2019-02-15T16:53:49.381Z; git: eb70b240169fcf1abbd86af36482d1c49826fa0b; jvm 1.8.0_232-8u232-b09-1~deb9u1-b09
Jicofo 2019-11-05 19:27:31.702 INFO: [10] org.eclipse.jetty.server.AbstractConnector.doStart() Started MuxServerConnector@5a3d44db{HTTP/1.1,[http/1.1]}{0.0.0.0:8888}
Jicofo 2019-11-05 19:27:31.706 INFO: [10] org.eclipse.jetty.server.Server.doStart() Started @4730ms
Jicofo 2019-11-05 19:27:31.738 INFO: [1] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.BRIDGE_MUC=jvbbrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:31.740 INFO: [1] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.auth.URL=XMPP:meet.jitsi
Jicofo 2019-11-05 19:27:31.742 INFO: [1] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.jigasi.BREWERY=jigasibrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:31.745 INFO: [1] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.jibri.PENDING_TIMEOUT=90
Jicofo 2019-11-05 19:27:31.746 INFO: [1] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.jibri.BREWERY=jibribrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:31.746 INFO: [1] org.jitsi.impl.configuration.ConfigurationServiceImpl.log() org.jitsi.jicofo.ALWAYS_TRUST_MODE_ENABLED=true
Jicofo 2019-11-05 19:27:31.779 INFO: [1] java.util.prefs.run() Created user preferences directory.
Jicofo 2019-11-05 19:27:31.807 INFO: [1] org.jitsi.xmpp.component.ComponentBase.log() Component org.jitsi.jicofo. config: 
Jicofo 2019-11-05 19:27:31.810 INFO: [1] org.jitsi.xmpp.component.ComponentBase.log()   ping interval: 10000 ms
Jicofo 2019-11-05 19:27:31.813 INFO: [1] org.jitsi.xmpp.component.ComponentBase.log()   ping timeout: 5000 ms
Jicofo 2019-11-05 19:27:31.813 INFO: [1] org.jitsi.xmpp.component.ComponentBase.log()   ping threshold: 3
Jicofo 2019-11-05 19:27:33.154 INFO: [17] org.jitsi.jicofo.xmpp.BaseBrewery.start().192 Joined brewery room: jibribrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:33.209 INFO: [17] org.jitsi.jicofo.xmpp.BaseBrewery.start().192 Joined brewery room: jigasibrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:33.233 INFO: [17] org.jitsi.jicofo.xmpp.BaseBrewery.start().192 Joined brewery room: jvbbrewery@internal-muc.meet.jitsi
Jicofo 2019-11-05 19:27:33.246 INFO: [17] org.jitsi.jicofo.ComponentsDiscovery.log() New component discovered: muc.meet.jitsi, null
Jicofo 2019-11-05 19:27:33.249 INFO: [17] org.jitsi.jicofo.JitsiMeetServices.log() MUC component discovered: muc.meet.jitsi
Jicofo 2019-11-05 19:27:33.288 INFO: [17] org.jitsi.jicofo.ComponentsDiscovery.log() New component discovered: focus.meet.jitsi, null
Jicofo 2019-11-05 19:27:33.291 INFO: [17] org.jitsi.jicofo.ComponentsDiscovery.log() New component discovered: internal-muc.meet.jitsi, null
Jicofo 2019-11-05 19:27:33.296 INFO: [17] org.jitsi.jicofo.ComponentsDiscovery.log() New component discovered: recorder.meet.jitsi, IQ Stanza (query jabber:iq:version) [to=focus@auth.meet.jitsi/focus24283598207273,from=recorder.meet.jitsi,id=1gLD2-53,type=result,]
Jicofo 2019-11-05 19:27:33.304 INFO: [17] org.jitsi.jicofo.ComponentsDiscovery.log() New component discovered: auth.meet.jitsi, IQ Stanza (query jabber:iq:version) [to=focus@auth.meet.jitsi/focus24283598207273,from=auth.meet.jitsi,id=1gLD2-58,type=result,]
Jicofo 2019-11-05 19:27:33.305 INFO: [17] org.jitsi.jicofo.JitsiMeetServices.log() Detected XMPP server version: IQ Stanza (query jabber:iq:version) [to=focus@auth.meet.jitsi/focus24283598207273,from=auth.meet.jitsi,id=1gLD2-58,type=result,]
Jicofo 2019-11-05 19:27:33.305 INFO: [17] org.jitsi.jicofo.ComponentsDiscovery.log() Services re-discovery interval: 30000
Jicofo 2019-11-05 19:27:33.316 INFO: [17] org.jitsi.jicofo.FocusManager.log() XMPP provider reg state: RegistrationState=Registered
Jicofo 2019-11-05 19:27:33.412 INFO: [17] org.jitsi.impl.protocol.xmpp.XmppProtocolProvider.doConnect().299 XMPP provider Jabber:focus@auth.meet.jitsi/focus24283598207273@xmpp.meet.jitsi connected (JID: focus@auth.meet.jitsi/focus24283598207273)
Jicofo 2019-11-05 19:27:36.360 INFO: [37] org.jitsi.jicofo.xmpp.BaseBrewery.processInstanceStatusChanged().324 Added brewery instance: jvb@auth.meet.jitsi/C1sG19-j
Jicofo 2019-11-05 19:27:36.362 INFO: [37] org.jitsi.jicofo.BridgeSelector.log() Added videobridge: jvb@auth.meet.jitsi/C1sG19-j v: null
Jicofo 2019-11-05 19:27:36.362 WARNING: [37] org.jitsi.jicofo.BridgeSelector.log() No pub-sub node mapped for jvb@auth.meet.jitsi/C1sG19-j
Jicofo 2019-11-05 19:27:36.388 INFO: [45] org.jitsi.jicofo.JvbDoctor.log() Scheduled health-check task for: jvb@auth.meet.jitsi/C1sG19-j
Jicofo 2019-11-05 19:27:39.425 INFO: [37] org.jitsi.jicofo.xmpp.BaseBrewery.processInstanceStatusChanged().324 Added brewery instance: jibribrewery@internal-muc.meet.jitsi/jibri-instance-193156261
Jicofo 2019-11-05 19:27:39.438 INFO: [37] org.jitsi.jicofo.recording.jibri.JibriDetector.onInstanceStatusChanged().136 Received Jibri jibribrewery@internal-muc.meet.jitsi/jibri-instance-193156261 status <jibri-status xmlns='http://jitsi.org/protocol/jibri'><busy-status xmlns='http://jitsi.org/protocol/jibri' status='idle'/><health-status xmlns='http://jitsi.org/protocol/health' status='healthy'/></jibri-status>
Jicofo 2019-11-05 19:27:39.447 INFO: [37] org.jitsi.jicofo.recording.jibri.JibriDetector.notifyJibriStatus().174 Jibri: jibribrewery@internal-muc.meet.jitsi/jibri-instance-193156261 available: true
Jicofo 2019-11-05 19:27:46.946 INFO: [53] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: test@muc.meet.jitsi
Jicofo 2019-11-05 19:27:49.554 INFO: [55] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: test@muc.meet.jitsi
Jicofo 2019-11-05 19:27:49.556 INFO: [55] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authentication session created for 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi SID: 467652fa-d95b-4725-8394-3eec3581377f
Jicofo 2019-11-05 19:27:49.558 INFO: [55] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi/daTGb-AD with session: AuthSession[ID=96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi, JID=96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi/daTGb-AD, SID=467652fa-d95b-4725-8394-3eec3581377f, MUID=4a6065d62d96dd95968c2be200e4f377, LIFE_TM_SEC=0, R=test@muc.meet.jitsi]@33847391
Jicofo 2019-11-05 19:27:49.559 INFO: [55] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi/daTGb-AD authenticated as: 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi
Jicofo 2019-11-05 19:27:49.571 INFO: [55] org.jitsi.jicofo.FocusManager.log() Created new focus for test@muc.meet.jitsi@auth.meet.jitsi. Conference count 1,options: 
Jicofo 2019-11-05 19:27:49.574 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Lip-sync enabled in test@muc.meet.jitsi
Jicofo 2019-11-05 19:27:49.577 INFO: [55] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Joining the room: test@muc.meet.jitsi
Jicofo 2019-11-05 19:27:49.934 INFO: [37] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@147082ea member=ChatMember[test@muc.meet.jitsi/96ef4969, jid: null]@1186544498]
Jicofo 2019-11-05 19:27:49.936 SEVERE: [37] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Failed to grant owner status to 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi/daTGb-AD
java.lang.RuntimeException: Failed to grant owner: <iq to='focus@auth.meet.jitsi/focus24283598207273' from='test@muc.meet.jitsi' id='1gLD2-99' 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.checkGrantOwnerToAuthUser(ChatRoomRoleAndPresence.java:357)
	at org.jitsi.jicofo.ChatRoomRoleAndPresence.memberPresenceChanged(ChatRoomRoleAndPresence.java:163)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.lambda$notifyMemberJoined$1(ChatRoomImpl.java:915)
	at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.notifyMemberJoined(ChatRoomImpl.java:915)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.processOtherPresence(ChatRoomImpl.java:1198)
	at org.jitsi.impl.protocol.xmpp.ChatRoomImpl.processPresence(ChatRoomImpl.java:1239)
	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 2019-11-05 19:27:49.938 INFO: [37] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@muc.meet.jitsi/96ef4969 joined.
Jicofo 2019-11-05 19:28:17.266 INFO: [37] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberLeft sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@147082ea member=ChatMember[test@muc.meet.jitsi/96ef4969, jid: 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi/daTGb-AD]@1186544498]
Jicofo 2019-11-05 19:28:17.267 INFO: [37] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test@muc.meet.jitsi/96ef4969 is leaving
Jicofo 2019-11-05 19:28:17.267 WARNING: [37] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Participant not found for test@muc.meet.jitsi/96ef4969 terminated already or never started ?
Jicofo 2019-11-05 19:28:17.272 INFO: [37] org.jitsi.jicofo.FocusManager.log() Disposed conference for room: test@muc.meet.jitsi conference count: 0
Jicofo 2019-11-05 19:28:33.811 INFO: [42] org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().401 Focus request for room: test@muc.meet.jitsi
Jicofo 2019-11-05 19:28:33.811 INFO: [42] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: 17e9deb4-9508-4f87-b81e-22ebb4a4145f@meet.jitsi/8L5Pidfb with session: AuthSession[ID=96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi, JID=17e9deb4-9508-4f87-b81e-22ebb4a4145f@meet.jitsi/8L5Pidfb, SID=467652fa-d95b-4725-8394-3eec3581377f, MUID=4a6065d62d96dd95968c2be200e4f377, LIFE_TM_SEC=44, R=test@muc.meet.jitsi]@33847391
Jicofo 2019-11-05 19:28:33.812 INFO: [42] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid 17e9deb4-9508-4f87-b81e-22ebb4a4145f@meet.jitsi/8L5Pidfb authenticated as: 96ef4969-0d8e-43f1-bc9f-42b42a305abb@meet.jitsi
Jicofo 2019-11-05 19:28:33.812 INFO: [42] org.jitsi.jicofo.FocusManager.l

This is docker setup, Hey @saghul have you seen this error before?

Nope, I have not. @sarthaknegi did you modify any values in your .env file after you started the containers? Did you wipe your $CONFIG directory in that case?

Yes, I always remove the $CONFIG directory when i do some changes to my .env file. :frowning: One thing though, I am running my docker compose project as a non root user, and my $CONFIG directory gets created with root:root user:group. I thought this might be the reason behind this line in jicofo log.

java.nio.file.FileSystemException: /config: Operation not permitted

So, i tried changing the user permissions to ubuntu:ubuntu but that does not solves the problem. Been stuck here for days :cry:

That warning is not related. Can you please paste your .env file to see if I can repro? Also, have you tried disabling token auth? (just to make the testing simpler)

Here is my env file, Going to try with token auth disabled now.env.txt (8.0 KB)

So, I tried with token auth disabled and somehow i was able to get over the error in jicofo, but still my video recording keeps failing. I am running my application on a docker container on AWS EC2 instance. I removed the DOCKER_HOST_ADDRESS from the .env and the JVB attains my public IP automatically, Is it how it is supposed to work?

Here are my jvb logs:

JVB 2019-11-07 13:15:08.127 INFO: [14] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@70cb0e8d

JVB 2019-11-07 13:15:13.159 INFO: [14] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@656df864

JVB 2019-11-07 13:15:14.928 INFO: [18] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=e9594b9ce1dd8b4f conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4

JVB 2019-11-07 13:15:14.973 WARNING: [15] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with e6800b9ace516693 not ready yet.

JVB 2019-11-07 13:15:14.973 WARNING: [15] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:15.174 INFO: [18] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 246ms. Sticky failure: false

JVB 2019-11-07 13:15:17.602 INFO: [66] org.ice4j.ice.Agent.log() Gathering candidates for component stream.RTP. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:17.603 INFO: [66] org.jitsi.videobridge.Conference.log() CAT=stat create_ice_tm,conf_id=fbcf72db578de647 ufrag=b8ukv1dp2skkj1,bundle=05b11a62,initiator=true

JVB 2019-11-07 13:15:17.603 INFO: [66] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=fbcf72db578de647,content=audio,ch_id=86893b6f0cf721e7,endp_id=null,stream=1152981342

JVB 2019-11-07 13:15:17.603 INFO: [66] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=fbcf72db578de647,content=audio,ch_id=86893b6f0cf721e7,endp_id=null,stream=1152981342 transport=default,bundle=05b11a62,initiator=true,media_type=audio,relay_type=null

JVB 2019-11-07 13:15:17.629 INFO: [66] org.jitsi.videobridge.RtpChannel.log() CAT=stat create_stream,conf_id=fbcf72db578de647,content=video,ch_id=a149297ab0e49aea,endp_id=null,stream=206534611

JVB 2019-11-07 13:15:17.652 INFO: [66] org.jitsi.videobridge.Content.log() CAT=stat create_channel,conf_id=fbcf72db578de647,content=video,ch_id=a149297ab0e49aea,endp_id=null,stream=206534611 transport=default,bundle=05b11a62,initiator=true,media_type=video,relay_type=null

JVB 2019-11-07 13:15:18.221 INFO: [14] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@28960b1a

JVB 2019-11-07 13:15:23.229 INFO: [14] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@49b2be4

JVB 2019-11-07 13:15:25.176 INFO: [18] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=9fba8d729ca52df2 conf_name=null,logging=false,conf_count=2,ch_count=9,v_streams=9

JVB 2019-11-07 13:15:25.469 INFO: [18] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 293ms. Sticky failure: false

JVB 2019-11-07 13:15:25.470 WARNING: [3564] org.ice4j.ice.Agent.log() Agent contains no IceMediaStream with name stream!

JVB 2019-11-07 13:15:27.455 INFO: [66] org.jitsi.videobridge.IceUdpTransportManager.log() Starting ICE agent without remote candidates.

JVB 2019-11-07 13:15:27.456 INFO: [66] org.ice4j.ice.Agent.log() Start ICE connectivity establishment. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:27.456 INFO: [66] org.ice4j.ice.Agent.log() Init checklist for stream stream

JVB 2019-11-07 13:15:27.457 INFO: [66] org.ice4j.ice.Agent.log() ICE state changed from Waiting to Running. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:27.457 INFO: [66] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62 old_state=Waiting,new_state=Running

JVB 2019-11-07 13:15:27.457 INFO: [66] org.ice4j.ice.ConnectivityCheckClient.log() Start connectivity checks. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.289 INFO: [14] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@2c8cf29c

JVB 2019-11-07 13:15:28.527 INFO: [3715] org.ice4j.ice.Agent.log() Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7926369428998979583):

LocalCandidate=candidate:1 1 udp 2130706431 172.19.0.6 10000 typ host

RemoteCandidate=candidate:10000 1 udp 1845501695 172.19.0.2 42109 typ prflx

JVB 2019-11-07 13:15:28.589 INFO: [3715] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 172.19.0.6:10000/udp/host -> 172.19.0.2:42109/udp/prflx (stream.RTP). Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.589 INFO: [3715] org.ice4j.socket.MergingDatagramSocket.log() Adding allowed address: 172.19.0.2:42109/udp

JVB 2019-11-07 13:15:28.589 INFO: [3715] org.ice4j.ice.ConnectivityCheckClient.log() Pair validated: 172.19.0.6:10000/udp/host -> 172.19.0.2:42109/udp/prflx (stream.RTP). Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.590 INFO: [3715] org.ice4j.ice.DefaultNominator.log() Nominate (first valid): 172.19.0.6:10000/udp/host -> 172.19.0.2:42109/udp/prflx (stream.RTP). Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.591 INFO: [3715] org.ice4j.ice.Agent.log() verify if nominated pair answer again

JVB 2019-11-07 13:15:28.591 INFO: [3715] org.ice4j.ice.ConnectivityCheckClient.log() IsControlling: true USE-CANDIDATE:false. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.611 INFO: [3715] org.ice4j.ice.ConnectivityCheckClient.log() Pair succeeded: 172.19.0.6:10000/udp/host -> 172.19.0.2:42109/udp/prflx (stream.RTP). Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.611 INFO: [3715] org.ice4j.ice.ConnectivityCheckClient.log() IsControlling: true USE-CANDIDATE:true. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.612 INFO: [3715] org.ice4j.ice.ConnectivityCheckClient.log() Nomination confirmed for pair: 172.19.0.6:10000/udp/host -> 172.19.0.2:42109/udp/prflx (stream.RTP). Loal ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.612 INFO: [3715] org.ice4j.ice.CheckList.log() Selected pair for stream stream.RTP: 172.19.0.6:10000/udp/host -> 172.19.0.2:42109/udp/prflx (stream.RTP)

JVB 2019-11-07 13:15:28.613 INFO: [3715] org.ice4j.ice.Agent.log() CheckList of stream stream is COMPLETED

JVB 2019-11-07 13:15:28.613 INFO: [3715] org.ice4j.ice.Agent.log() ICE state changed from Running to Completed. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:28.614 INFO: [3715] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62 old_state=Running,new_state=Completed

JVB 2019-11-07 13:15:28.614 INFO: [3693] org.jitsi.videobridge.Channel.log() CAT=stat transport_connected,conf_id=fbcf72db578de647,content=audio,ch_id=86893b6f0cf721e7,endp_id=05b11a62,stream=1152981342

JVB 2019-11-07 13:15:28.615 INFO: [3715] org.ice4j.ice.Agent.log() Harvester used for selected pair for stream.RTP (local ufrag b8ukv1dp2skkj1): host

JVB 2019-11-07 13:15:28.718 INFO: [3693] org.jitsi.videobridge.Channel.log() CAT=stat transport_connected,conf_id=fbcf72db578de647,content=video,ch_id=a149297ab0e49aea,endp_id=05b11a62,stream=206534611

JVB 2019-11-07 13:15:29.994 INFO: [3693] org.jitsi.videobridge.cc.BitrateController.log() new track projection for subjective_quality=0,primary_ssrc=2885728544,secondary_ssrcs={3194802954=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=2885728544,secondary_ssrcs={3194802954=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=2885728544,secondary_ssrcs={3194802954=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=2261320114,secondary_ssrcs={4257832851=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=2261320114,secondary_ssrcs={4257832851=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=2261320114,secondary_ssrcs={4257832851=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=3000713673,secondary_ssrcs={2432541632=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=3000713673,secondary_ssrcs={2432541632=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=3000713673,secondary_ssrcs={2432541632=rtx},temporal_id=2,spatial_id=-1

JVB 2019-11-07 13:15:30.011 INFO: [3693] org.jitsi.videobridge.cc.BitrateController.log() new track projection for subjective_quality=0,primary_ssrc=2491941748,secondary_ssrcs={3803528126=rtx},temporal_id=0,spatial_id=-1 subjective_quality=1,primary_ssrc=2491941748,secondary_ssrcs={3803528126=rtx},temporal_id=1,spatial_id=-1 subjective_quality=2,primary_ssrc=2491941748,secondary_ssrcs={3803528126=rtx},temporal_id=2,spatial_id=-1 subjective_quality=3,primary_ssrc=3893088102,secondary_ssrcs={3109148212=rtx},temporal_id=0,spatial_id=-1 subjective_quality=4,primary_ssrc=3893088102,secondary_ssrcs={3109148212=rtx},temporal_id=1,spatial_id=-1 subjective_quality=5,primary_ssrc=3893088102,secondary_ssrcs={3109148212=rtx},temporal_id=2,spatial_id=-1 subjective_quality=6,primary_ssrc=1265035038,secondary_ssrcs={3606286409=rtx},temporal_id=0,spatial_id=-1 subjective_quality=7,primary_ssrc=1265035038,secondary_ssrcs={3606286409=rtx},temporal_id=1,spatial_id=-1 subjective_quality=8,primary_ssrc=1265035038,secondary_ssrcs={3606286409=rtx},temporal_id=2,spatial_id=-1

JVB 2019-11-07 13:15:30.012 WARNING: [3693] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 05b11a62 not ready yet.

JVB 2019-11-07 13:15:30.012 WARNING: [3693] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:30.013 INFO: [3693] org.jitsi.videobridge.Channel.log() CAT=stat transport_connected,conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62

JVB 2019-11-07 13:15:30.139 WARNING: [3721] org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.log() Unknown DTLS handshake message type: -71

JVB 2019-11-07 13:15:30.147 WARNING: [3721] org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.log() Unknown DTLS handshake message type: 119

JVB 2019-11-07 13:15:30.151 WARNING: [3721] org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.log() Unknown DTLS handshake message type: 27

JVB 2019-11-07 13:15:30.163 WARNING: [3721] org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.log() Unknown DTLS handshake message type: 27

JVB 2019-11-07 13:15:30.247 INFO: [3721] org.jitsi.impl.neomedia.transform.srtp.AES.log() AES benchmark (of execution times expressed in nanoseconds): BouncyCastle 5582211, SunJCE 155019, SunPKCS11 1082913

JVB 2019-11-07 13:15:30.250 INFO: [3721] org.jitsi.impl.neomedia.transform.srtp.AES.log() Will employ AES implemented by SunJCE.

JVB 2019-11-07 13:15:30.400 INFO: [3744] org.jitsi.videobridge.SctpConnection.log() SCTP socket accepted on conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62

JVB 2019-11-07 13:15:30.404 INFO: [3744] org.jitsi.videobridge.EndpointMessageTransport.log() WebRTC data channel established for conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62

JVB 2019-11-07 13:15:31.615 INFO: [3535] org.ice4j.ice.Agent.log() ICE state changed from Completed to Terminated. Local ufrag b8ukv1dp2skkj1

JVB 2019-11-07 13:15:31.616 INFO: [3535] org.jitsi.videobridge.IceUdpTransportManager.log() CAT=stat ice_state_change,conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62 old_state=Completed,new_state=Terminated

JVB 2019-11-07 13:15:33.095 WARNING: [3746] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 11afedc2 not ready yet.

JVB 2019-11-07 13:15:33.101 WARNING: [3746] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:33.307 INFO: [14] org.jitsi.xmpp.mucclient.MucClientManager.log() Setting a presence extension: org.jitsi.xmpp.extensions.colibri.ColibriStatsExtension@26a891b1

JVB 2019-11-07 13:15:33.637 WARNING: [3747] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with bf1d46fc not ready yet.

JVB 2019-11-07 13:15:33.637 WARNING: [3747] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:33.638 WARNING: [3747] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 11afedc2 not ready yet.

JVB 2019-11-07 13:15:33.638 WARNING: [3747] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:33.774 WARNING: [3748] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with bf1d46fc not ready yet.

JVB 2019-11-07 13:15:33.774 WARNING: [3748] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.213 WARNING: [3749] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 11afedc2 not ready yet.

JVB 2019-11-07 13:15:34.213 WARNING: [3749] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.213 WARNING: [3749] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with bf1d46fc not ready yet.

JVB 2019-11-07 13:15:34.214 WARNING: [3749] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.414 WARNING: [3750] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with bf1d46fc not ready yet.

JVB 2019-11-07 13:15:34.415 WARNING: [3750] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.418 WARNING: [3750] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 11afedc2 not ready yet.

JVB 2019-11-07 13:15:34.421 WARNING: [3750] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.485 WARNING: [3751] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with bf1d46fc not ready yet.

JVB 2019-11-07 13:15:34.486 WARNING: [3751] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.486 WARNING: [3751] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 11afedc2 not ready yet.

JVB 2019-11-07 13:15:34.487 WARNING: [3751] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.796 INFO: [66] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=fbcf72db578de647,content=audio,ch_id=86893b6f0cf721e7,endp_id=05b11a62,stream=1152981342

JVB 2019-11-07 13:15:34.796 INFO: [66] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=fbcf72db578de647,content=audio,ch_id=86893b6f0cf721e7,endp_id=05b11a62,stream=1152981342 bRecv=0,bSent=84,pRecv=0,pSent=1,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0

JVB 2019-11-07 13:15:34.798 INFO: [66] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=fbcf72db578de647,content=video,ch_id=a149297ab0e49aea,endp_id=05b11a62,stream=206534611

JVB 2019-11-07 13:15:34.806 INFO: [66] org.jitsi.videobridge.RtpChannel.log() CAT=stat expire_ch_stats,conf_id=fbcf72db578de647,content=video,ch_id=a149297ab0e49aea,endp_id=05b11a62,stream=206534611 bRecv=104,bSent=76,pRecv=13,pSent=1,bRetr=0,bNotRetr=0,pRetr=0,pNotRetr=0,pMiss=0

JVB 2019-11-07 13:15:34.815 INFO: [3714] org.ice4j.socket.MergingDatagramSocket.log() Failed to receive: java.net.SocketException: Socket closed

JVB 2019-11-07 13:15:34.817 WARNING: [3714] org.ice4j.socket.MergingDatagramSocket.log() Removing the active socket. Won't be able to send until a new one is elected.

JVB 2019-11-07 13:15:34.819 INFO: [66] org.ice4j.socket.MergingDatagramSocket.log() Closing.

JVB 2019-11-07 13:15:34.822 WARNING: [66] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with 05b11a62 not ready yet.

JVB 2019-11-07 13:15:34.825 WARNING: [66] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:34.825 INFO: [66] org.jitsi.videobridge.Channel.log() CAT=stat expire_ch,conf_id=fbcf72db578de647,content=data,ch_id=fc4bb07d1a4de73f,endp_id=05b11a62

JVB 2019-11-07 13:15:35.470 INFO: [18] org.jitsi.videobridge.Videobridge.log() CAT=stat create_conf,conf_id=cebd258b37c1aeeb conf_name=null,logging=false,conf_count=2,ch_count=6,v_streams=4

JVB 2019-11-07 13:15:35.487 WARNING: [15] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with aef185771022550f not ready yet.

JVB 2019-11-07 13:15:35.487 WARNING: [15] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:35.488 WARNING: [15] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with fca86971467c1033 not ready yet.

JVB 2019-11-07 13:15:35.488 WARNING: [15] org.jitsi.videobridge.EndpointMessageTransport.log() No available transport channel, can't send a message

JVB 2019-11-07 13:15:35.653 INFO: [18] org.jitsi.videobridge.health.Health.log() Performed a successful health check in 183ms. Sticky failure: false

Also, i am getting this error, in the console:

Bridge Channel send: no opened channel.
[modules/xmpp/JingleSessionPC.js] <A.peerconnection.oniceconnectionstatechange>: (TIME) ICE failed P2P? false: 26104.570000024978

and this warning:

[JitsiConference.js] <e.sendMessage>: Failed to send a ping request or response.

Let’s go back to the basics.

Does a normal conference with more than 2 participants work?

Correct, in AWS you can skip it as it’s automagically detected.

Yes, a normal conference call works. Only, the recording fails.

There might be a bug in the Jibri config, the PR has not been merged yet, there is a reason for that (mostly time though). I’ll try to get to it next week.

Okay, thanks for helping. Meanwhile i will try to get jibri running independently outside docker. How should i change the config.js?

I tried changing the xmpp_domain to 127.0.0.1.

Is it how it is supposed to work?

Here is my config.js

{
"recording_directory":"/tmp/recordings",
"finalize_recording_script_path": "/path/to/finalize_recording.sh",
"xmpp_environments": [
    {
        "name": "prod environment",
        "xmpp_server_hosts": [
            "xmpp.127.0.0.1"
        ],
        "xmpp_domain": "127.0.0.1",
        "control_login": {
            "domain": "auth.127.0.0.1",
            "username": "jibri",
            "password": "passw0rd"
        },
        "control_muc": {
            "domain": "internal-muc.127.0.0.1",
            "room_name": "jibribrewery",
            "nickname": "jibri-nickname"
        },
        "call_login": {
            "domain": "recorder.127.0.0.1",
            "username": "recorder",
            "password": "passw0rd"
        },

        "room_jid_domain_string_to_strip_from_start": "internal-muc.",
        "usage_timeout": "0"
        }
    ]
}