BreakOut Rooms - Timer Functionality

Hello,

When someone leaves the breakout room, it is checked whether this is last user in all breakoutrooms + main room. If so, main room is destroyed after 5 s. Code sets a timer with module:add_timer(ROOMS_TTL_IF_ALL_LEFT, function()


function on_occupant_left(event)
    local room_jid = event.room.jid;

    if is_healthcheck_room(room_jid) then
        return;
    end

    local main_room = get_main_room(room_jid);

    if not main_room then
        return;
    end

    if main_room._data.breakout_rooms_active and jid_node(event.occupant.jid) ~= 'focus' then
        broadcast_breakout_rooms(room_jid);
    end

    -- Close the conference if all left for good.
    if main_room._data.breakout_rooms_active and not main_room._data.is_close_all_scheduled and not exist_occupants_in_rooms(main_room) then
        main_room._data.is_close_all_scheduled = true;
        main_room:save(true);

        module:log('info', 'on_occupant_left-- %s', socket.gettime());

        module:add_timer(ROOMS_TTL_IF_ALL_LEFT, function()
            -- we need to look up again the room as till the timer is fired, the room maybe already destroyed/recreated
            -- and we will have the old instance
            module:log('info', 'inside timer-- %s', socket.gettime());

            local main_room, main_room_jid = get_main_room(room_jid);
            if main_room and main_room._data.is_close_all_scheduled and not exist_occupants_in_rooms(main_room) then
                module:log('info', 'Closing conference %s as all left for good at %s ', main_room_jid, socket.gettime());
                main_room:set_persistent(false);
                main_room:destroy(nil, 'All occupants left.');
            end
        end)
    end
end

However, I see behavior that this timer does not always work after 5 s. It sometimes works earlier than 1s. This creates a raise condition when someone tries to leave a breakout room and join to another room. In scenario, it sends unavailable presence for the breakout room. While unavailable presence is processing, timer sets and works in same second, and main room is destroyed. So same client sending an iq for another breakout room/main room gets “No main room” error.

How can I assure that this timer works 5 sec after set?


Jun 17 14:19:09 muc_breakout_rooms: on_occupant_left-- 1655464749.3107
Jun 17 14:19:09muc_breakout_rooms: inside timer-- 1655464749.3444
Jun 17 14:19:09 muc_breakout_rooms: Closing conference [prp]esrayilmaz@xx as all left for good at 1655464749.3445

Full Log:

Jun 17 14:19:09 muc_breakout_rooms: on_occupant_left-- 1655464749.3107
Jun 17 14:19:09 c2s2f44760: Received[c2s]: <presence to='351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx/focus'>
Jun 17 14:19:09 pep: get_pep_service("focus")
Jun 17 14:19:09muc: presence update for 351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx/focus from session focus@auth.xx/focus
Jun 17 14:19:09 c2s2f44760: Sending[c2s]: <presence to='focus@auth.xx/focus' from='351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx/focus'>
Jun 17 14:19:09 c2s2f44760: Received[c2s]: <presence type='unavailable' to='351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx/focus' id='9K4JY-191'>
Jun 17 14:19:09 breakout.xx:muc: session focus@auth.xx/focus is leaving occupant 351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx/focus
Jun 17 14:19:09 c2s2f44760: Sending[c2s]: <presence type='unavailable' from='351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx/focus' to='focus@auth.xx/focus' id='9K4JY-191'>
Jun 17 14:19:09 breakout.xx:muc: "351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx" empty, destroying
Jun 17 14:19:09 breakout.xx:muc: Forgetting 351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx
Jun 17 14:19:09 breakout.xx:muc: Deleting 351c1711-6460-42ba-aeb1-8611b317fbf5@breakout.xx
Jun 17 14:19:09 mod_websocket: Websocket received frame: opcode=1, 26 bytes
Jun 17 14:19:09 c2s31a7600: Received[c2s]: <r xmlns='urn:xmpp:sm:3'>
Jun 17 14:19:09 :smacks: Received ack request, acking for 37
Jun 17 14:19:09 c2s31a7600: Sending[c2s]: <a xmlns='urn:xmpp:sm:3' h='37'>
Jun 17 14:19:09 c2s31a7600: Queuing <r> (in a moment) from piggybacked by handle_r - #queue=3
Jun 17 14:19:09 c2s31a7600: Sending <r> (inside timer, before send) from piggybacked by handle_r - #queue=3
Jun 17 14:19:09 c2s31a7600: Sending[c2s]: <r xmlns='urn:xmpp:sm:3'>
Jun 17 14:19:09 c2s31a7600: Sending <r> (inside timer, after send) from piggybacked by handle_r - #queue=3
Jun 17 14:19:09 mod_websocket: Websocket received frame: opcode=1, 33 bytes
Jun 17 14:19:09 c2s31a7600: Received[c2s]: <a h='54' xmlns='urn:xmpp:sm:3'>
Jun 17 14:19:09 c2s31a7600: #queue = 0
Jun 17 14:19:09 xx:muc_breakout_rooms: inside timer-- 1655464749.3444
Jun 17 14:19:09 xx:muc_breakout_rooms: Closing conference [prp]esrayilmaz@conference.xx as all left for good at 1655464749.3445
Jun 17 14:19:09 conference.xx:muc: Forgetting [prp]esrayilmaz@conference.xx
Jun 17 14:19:09 conference.xx:muc: Deleting [prp]esrayilmaz@conference.xx
Jun 17 14:19:09 xx:reservations: Sending DELETE /conference/1952/prp/PRIVATE_ROOM
Jun 17 14:19:09 http: Making HTTP DELETE request '2c97030' to uy:8080/conference/1952/prp/PRIVATE_ROOM
Jun 17 14:19:09 net.connect: [pending connection 4zeAtnGk] Starting connection process
Jun 17 14:19:09 net.connect: [pending connection 4zeAtnGk] Checking for targets...
Jun 17 14:19:09 adns: Records for uy not in cache, sending query (thread: 0x328bf00)...
Jun 17 14:19:09 server_epoll: Watching FD 35 (dns, 53, 0.0.0.0, 0)
Jun 17 14:19:09 adns: Sending DNS query to 10.218.128.140
Jun 17 14:19:09 adns: Records for uy in cache, sending query (thread: 0x21b6610)...
Jun 17 14:19:09 adns: Sending DNS query to 10.218.128.140
Jun 17 14:19:09 adns: Reply for uy (thread: 0x328bf00)
Jun 17 14:19:09 server_epoll: Close FD 35 (dns, 53, 0.0.0.0, 0) now
Jun 17 14:19:09 server_epoll: Unwatched FD 35 (dns, 53, 0.0.0.0, 0)
Jun 17 14:19:09 adns: Reply for uy (thread: 0x21b6610)
Jun 17 14:19:09 net.connect: [pending connection 4zeAtnGk] Next target to try is 172.21.193.94:8080
Jun 17 14:19:09 server_epoll: Watching FD 35 (172.21.193.121, 34524)
Jun 17 14:19:09 net.connect: [pending connection 4zeAtnGk] Successfully connected
Jun 17 14:19:09 mod_websocket: Websocket received frame: opcode=1, 433 bytes
Jun 17 14:19:09 c2s31a7600: Handled 38 incoming stanzas
Jun 17 14:19:09 c2s31a7600: Received[c2s]: <iq type='set' to='focus.xx' id='0b9eaed1-1966-4e9f-b6e4-95f30a387465:sendIQ'>
1 Like

I honestly don’t know, we set it to 5s and I’d expect it to run in 5. Maybe it’s a prosody bug?

I believe the concurrency issue will be fixed with fix(breakout-rooms): Stop previous leave timers if any. by damencho · Pull Request #11842 · jitsi/jitsi-meet · GitHub

1 Like

Yes it fixes. Thank you @damencho

There is another similar issue in broadcast_breakout_rooms method. It also creates a timer to publish the latest changes to prevent flooding of messages. But when there are a lot of users in breakout rooms, sometimes users dont get the latest status and everybody sees different breakout rooms. Like user1 sees 3 breakout room, but user2 sees only 1 breakout room. Similar fix also needs to be applied in there.

Thank you again.
Esra

1 Like

Ouch, you’re right!

I think this might fix it: fix(breakout-rooms) fix broadcast timer by saghul · Pull Request #12115 · jitsi/jitsi-meet · GitHub

1 Like