Room not being recreated successfully - sometimes

We host our own jitsi-meet server with http authentication and reservation API. It all works fine, mostly. But of late we have been getting weird behaviour when the same room is recreated at a later time. So let’s say we create a room A and once the meeting is done recreate the same room A at a later time. The first time Room A is created, all events are fired - room create, participant joined and participant left. And when the meeting is done, room destroy event is called. But the second time we try to create room A, once the authentication takes place there is no real room being created (no call to reservation system or no room create event is fired). Each participant trying to access the room A is in their own room and can not see each other.

The last few lines in the console log in the browser -

Logger.js:154 2021-01-26T20:13:05.082Z [modules/xmpp/moderator.js] <l._allocateConferenceFocusSuccess>: Waiting for the focus… 256000
Logger.js:154 2021-01-26T20:17:21.083Z [modules/xmpp/moderator.js] <l.createConferenceIq>: Session ID: f0e46029-c6e5-4824-a4f1-86a55416e47a machine UID: a7378565b6c0f7297e10eedfe54d845b
Logger.js:154 2021-01-26T20:17:21.196Z [modules/xmpp/moderator.js] <l.parseConfigOptions>: Authentication enabled: true
Logger.js:154 2021-01-26T20:17:21.197Z [modules/xmpp/moderator.js] <l.parseConfigOptions>: External authentication enabled: false
Logger.js:154 2021-01-26T20:17:21.197Z [modules/xmpp/moderator.js] <l.parseSessionId>: Received sessionId: f0e46029-c6e5-4824-a4f1-86a55416e47a
Logger.js:154 2021-01-26T20:17:21.198Z [modules/xmpp/moderator.js] <l.parseConfigOptions>: Sip gateway enabled: false
2021-01-26T20:17:21.198Z [modules/xmpp/moderator.js] <l._allocateConferenceFocusSuccess>: Waiting for the focus… 512000

Any ideas on what is going on here? Please note, room recreation does work sometimes, but not always.

Thanks for your time.

Check jicofo logs, do you see errors there?

Thank you so much for the prompt response.

I don’t see any errors. I have posted some lines from jicofo.log when it worked and when it did not.

Last few lines of the jicofo.log when room is not being created are as follows. Note there is no call to the reservation system.

Jicofo 2021-01-26 21:41:03.387 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.019S. Sticky failure: false
Jicofo 2021-01-26 21:41:13.390 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.022S. Sticky failure: false
Jicofo 2021-01-26 21:41:23.387 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.019S. Sticky failure: false
Jicofo 2021-01-26 21:41:28.796 INFO: [380] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test-180@conference.devjitsi3.safevchat.com
Jicofo 2021-01-26 21:41:28.796 INFO: [380] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: spemmara@devjitsi3.safevchat.com/hUUEfXGM with session: AuthSession[ID=spemmara@devjitsi3.safevchat.com, JID=spemmara@devjitsi3.safevchat.com/hUUEfXGM, SID=f0e46029-c6e5-4824-a4f1-86a55416e47a, MUID=a7378565b6c0f7297e10eedfe54d845b, LIFE_TM_SEC=99, R=test-180@conference.devjitsi3.safevchat.com]@1496391215
Jicofo 2021-01-26 21:41:28.796 INFO: [380] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid spemmara@devjitsi3.safevchat.com/hUUEfXGM authenticated as: spemmara@devjitsi3.safevchat.com
Jicofo 2021-01-26 21:41:30.183 INFO: [381] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test-180@conference.devjitsi3.safevchat.com
Jicofo 2021-01-26 21:41:30.183 INFO: [381] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: spemmara@devjitsi3.safevchat.com/hUUEfXGM with session: AuthSession[ID=spemmara@devjitsi3.safevchat.com, JID=spemmara@devjitsi3.safevchat.com/hUUEfXGM, SID=f0e46029-c6e5-4824-a4f1-86a55416e47a, MUID=a7378565b6c0f7297e10eedfe54d845b, LIFE_TM_SEC=1, R=test-180@conference.devjitsi3.safevchat.com]@1496391215
Jicofo 2021-01-26 21:41:30.183 INFO: [381] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid spemmara@devjitsi3.safevchat.com/hUUEfXGM authenticated as: spemmara@devjitsi3.safevchat.com
Jicofo 2021-01-26 21:41:32.290 INFO: [382] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test-180@conference.devjitsi3.safevchat.com
Jicofo 2021-01-26 21:41:32.291 INFO: [382] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: spemmara@devjitsi3.safevchat.com/hUUEfXGM with session: AuthSession[ID=spemmara@devjitsi3.safevchat.com, JID=spemmara@devjitsi3.safevchat.com/hUUEfXGM, SID=f0e46029-c6e5-4824-a4f1-86a55416e47a, MUID=a7378565b6c0f7297e10eedfe54d845b, LIFE_TM_SEC=2, R=test-180@conference.devjitsi3.safevchat.com]@1496391215
Jicofo 2021-01-26 21:41:32.291 INFO: [382] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid spemmara@devjitsi3.safevchat.com/hUUEfXGM authenticated as: spemmara@devjitsi3.safevchat.com
Jicofo 2021-01-26 21:41:33.392 INFO: [34] org.jitsi.health.HealthChecker.log() Performed a successful health check in PT0.024S. Sticky failure: false

When everything worked the log was as follows:

Jicofo 2021-01-26 16:50:51.424 INFO: [51] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: test-180@conference.devjitsi3.safevchat.com
Jicofo 2021-01-26 16:50:51.425 INFO: [51] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: spemmara@devjitsi3.safevchat.com/l6dUCwIt with session: AuthSession[ID=spemmara@devjitsi3.safevchat.com, JID=spemmara@devjitsi3.safevchat.com/l6dUCwIt, SID=7f0e6836-602b-4df5-acde-e982600a61fe, MUID=9512e9cb6bd5723726b5adb0df722124, LIFE_TM_SEC=3808, R=test-180@conference.devjitsi3.safevchat.com]@584632825
Jicofo 2021-01-26 16:50:51.425 INFO: [51] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid spemmara@devjitsi3.safevchat.com/l6dUCwIt authenticated as: spemmara@devjitsi3.safevchat.com
Jicofo 2021-01-26 16:50:51.428 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() Sending post: {name=test-180, mail_owner=spemmara@devjitsi3.safevchat.com, start_time=2021-01-26T16:50:51.426Z, duration=-1}
Jicofo 2021-01-26 16:50:51.438 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() STATUS CODE: 200
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() ID: 180
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() PIN: null
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() URL: null
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() SIP ID: null
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() START TIME: Tue Jan 26 16:50:00 UTC 2021
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.impl.reservation.rest.ApiHandler.log() DURATION: 1500
Jicofo 2021-01-26 16:50:51.440 INFO: [51] org.jitsi.jicofo.xmpp.FocusComponent.log() Create room result: Result[c=1, msg=null]@351105591 for test-180@conference.devjitsi3.safevchat.com
Jicofo 2021-01-26 16:50:51.441 INFO: [51] org.jitsi.jicofo.FocusManager.log() Created new focus for test-180@conference.devjitsi3.safevchat.com@auth.devjitsi3.safevchat.com. Conference count 2,options: channelLastN=-1 enableLipSync=false openSctp=false disableRtx=false
Jicofo 2021-01-26 16:50:51.441 INFO: [51] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Joining the room: test-180@conference.devjitsi3.safevchat.com
Jicofo 2021-01-26 16:50:51.776 INFO: [22] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.protocol.xmpp.ChatRoomImpl@37e361a3 member=ChatMember[test-180@conference.devjitsi3.safevchat.com/9d2d41fb, jid: null]@2054628557]
Jicofo 2021-01-26 16:50:51.785 INFO: [22] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member test-180@conference.devjitsi3.safevchat.com/9d2d41fb joined.

check prosody version. in prosody 0.11.x they’ve introduced the Tombstone feature -

Starting with Prosody 0.11.x, when a room is destroyed, it leaves behind a tombstone which prevents the room being entered or recreated. It also allows anyone who was not in the room at the time it was destroyed to learn about it, and to update their bookmarks. Tombstones prevents the case where someone could recreate a previously semi-anonymous room in order to learn the real JIDs of those who often join there.

disabling it or making the expiration time shorter helped me with this.
check this link - prosody tombstone

We are using prosody 0.11 version.

What is the default if there is no muc_tombstones value configured?

As I mentioned in my post, room recreation does work, but fails occasionally.

Thanks for your response.

Shuvo_Khan
January 27

check prosody version. in prosody 0.11.x they’ve introduced the Tombstone feature -

Starting with Prosody 0.11.x, when a room is destroyed, it leaves behind a tombstone which prevents the room being entered or recreated. It also allows anyone who was not in the room at the time it was destroyed to learn about it, and to update their bookmarks. Tombstones prevents the case where someone could recreate a previously semi-anonymous room in order to learn the real JIDs of those who often join there.

disabling it or making the expiration time shorter helped me with this.
check this link - prosody tombstone

Just wanted to add that once jicofo service was restarted, I was able to recreate one of the rooms that I was unable to recreate earlier.

Added

muc_tombstones = false

This did not help. 

Thanks.

I am wondering if this issue may be related to

I notice that sometimes, the muc room destroy event (that i notice is called a couple times) is called only once, and when this happens we can not recreate the room. Of course, when i restart jicofo, it all works again. Is there a way to clear the focus user session for a particular room?

Yeah that sounds like it …

I have a plan in the following weeks to test the reservation system and the PR for the reservation system implemented in prosody and will take a note to check this issue.

Thank You !!!

It seems like room recreation is a problem only when the conference is destroyed while in progress because the duration (set using the reservation API) expires. When the room is destroyed because all the participants have left, there seems to be no issue. So the problem seems to be tied to the reservation system as you alluded.
Is there anything I can do within prosody (hooking to any of the muc events ) to circumvent this problem?

You can test, whether this works for you: Reservations plugin by shawnchin · Pull Request #8386 · jitsi/jitsi-meet · GitHub

Yes ! Using this module does fix the issue. Thank you.

So you have switched to using that reservation module instead of jicofo and it works for you?
Trying to collect datapoints, as I need to test it and merge it in the repo …

Yes I did. I did notice one issue…but that had something to do with how I was hooking to room create/destroy and calling async http calls within it. Once I fixed my code (I was using async.waiter in a function that makes the http call, but was not calling the function using a runner) it works. I am still testing it and will report any issues.
There is the one issue (that was commented upon as a todo item in the code), that when the duration exipres, the user is not made aware of it - the participant is just kicked out of the meeting.

Yep, I plan to look at that …

Hello,
Any updates ? Did you have a chance to look at it?

Thanks.

Hello,
I was wondering if this jicofo issue is fixed. Any updates on this?

Thanks

Nope, I still have the PR request tab open in my browser so I don’t forget, just haven’t found time to do it … I hope soon to be able to allocate one or two days in looking into it.