Try putting room list handling behind a lock

Some of the logs relating to room list corruption appear to be badly timed race conditions so we'll try to linearize them here.
This commit is contained in:
Travis Ralston 2021-05-12 21:15:17 -06:00
parent 52420feab0
commit 9beb2b8d78
2 changed files with 193 additions and 152 deletions

View file

@ -34,6 +34,7 @@ import { OrderingAlgorithm } from "./list-ordering/OrderingAlgorithm";
import { getListAlgorithmInstance } from "./list-ordering"; import { getListAlgorithmInstance } from "./list-ordering";
import SettingsStore from "../../../settings/SettingsStore"; import SettingsStore from "../../../settings/SettingsStore";
import { VisibilityProvider } from "../filters/VisibilityProvider"; import { VisibilityProvider } from "../filters/VisibilityProvider";
import {MultiLock} from "../../../utils/MultiLock";
/** /**
* Fired when the Algorithm has determined a list has been updated. * Fired when the Algorithm has determined a list has been updated.
@ -77,6 +78,7 @@ export class Algorithm extends EventEmitter {
} = {}; } = {};
private allowedByFilter: Map<IFilterCondition, Room[]> = new Map<IFilterCondition, Room[]>(); private allowedByFilter: Map<IFilterCondition, Room[]> = new Map<IFilterCondition, Room[]>();
private allowedRoomsByFilters: Set<Room> = new Set<Room>(); private allowedRoomsByFilters: Set<Room> = new Set<Room>();
private handlerLock = new MultiLock();
/** /**
* Set to true to suspend emissions of algorithm updates. * Set to true to suspend emissions of algorithm updates.
@ -679,191 +681,200 @@ export class Algorithm extends EventEmitter {
public async handleRoomUpdate(room: Room, cause: RoomUpdateCause): Promise<boolean> { public async handleRoomUpdate(room: Room, cause: RoomUpdateCause): Promise<boolean> {
if (SettingsStore.getValue("advancedRoomListLogging")) { if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602 // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Handle room update for ${room.roomId} called with cause ${cause}`); console.log(`Acquiring lock for ${room.roomId} with cause ${cause}`);
} }
if (!this.algorithms) throw new Error("Not ready: no algorithms to determine tags from"); const release = await this.handlerLock.acquire(room.roomId);
try {
// Note: check the isSticky against the room ID just in case the reference is wrong if (SettingsStore.getValue("advancedRoomListLogging")) {
const isSticky = this._stickyRoom && this._stickyRoom.room && this._stickyRoom.room.roomId === room.roomId; // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
if (cause === RoomUpdateCause.NewRoom) { console.log(`Handle room update for ${room.roomId} called with cause ${cause}`);
const isForLastSticky = this._lastStickyRoom && this._lastStickyRoom.room === room;
const roomTags = this.roomIdsToTags[room.roomId];
const hasTags = roomTags && roomTags.length > 0;
// Don't change the cause if the last sticky room is being re-added. If we fail to
// pass the cause through as NewRoom, we'll fail to lie to the algorithm and thus
// lose the room.
if (hasTags && !isForLastSticky) {
console.warn(`${room.roomId} is reportedly new but is already known - assuming TagChange instead`);
cause = RoomUpdateCause.PossibleTagChange;
} }
if (!this.algorithms) throw new Error("Not ready: no algorithms to determine tags from");
// Check to see if the room is known first // Note: check the isSticky against the room ID just in case the reference is wrong
let knownRoomRef = this.rooms.includes(room); const isSticky = this._stickyRoom && this._stickyRoom.room && this._stickyRoom.room.roomId === room.roomId;
if (hasTags && !knownRoomRef) { if (cause === RoomUpdateCause.NewRoom) {
console.warn(`${room.roomId} might be a reference change - attempting to update reference`); const isForLastSticky = this._lastStickyRoom && this._lastStickyRoom.room === room;
this.rooms = this.rooms.map(r => r.roomId === room.roomId ? room : r); const roomTags = this.roomIdsToTags[room.roomId];
knownRoomRef = this.rooms.includes(room); const hasTags = roomTags && roomTags.length > 0;
if (!knownRoomRef) {
console.warn(`${room.roomId} is still not referenced. It may be sticky.`); // Don't change the cause if the last sticky room is being re-added. If we fail to
// pass the cause through as NewRoom, we'll fail to lie to the algorithm and thus
// lose the room.
if (hasTags && !isForLastSticky) {
console.warn(`${room.roomId} is reportedly new but is already known - assuming TagChange instead`);
cause = RoomUpdateCause.PossibleTagChange;
}
// Check to see if the room is known first
let knownRoomRef = this.rooms.includes(room);
if (hasTags && !knownRoomRef) {
console.warn(`${room.roomId} might be a reference change - attempting to update reference`);
this.rooms = this.rooms.map(r => r.roomId === room.roomId ? room : r);
knownRoomRef = this.rooms.includes(room);
if (!knownRoomRef) {
console.warn(`${room.roomId} is still not referenced. It may be sticky.`);
}
}
// If we have tags for a room and don't have the room referenced, something went horribly
// wrong - the reference should have been updated above.
if (hasTags && !knownRoomRef && !isSticky) {
throw new Error(`${room.roomId} is missing from room array but is known - trying to find duplicate`);
}
// Like above, update the reference to the sticky room if we need to
if (hasTags && isSticky) {
// Go directly in and set the sticky room's new reference, being careful not
// to trigger a sticky room update ourselves.
this._stickyRoom.room = room;
}
// If after all that we're still a NewRoom update, add the room if applicable.
// We don't do this for the sticky room (because it causes duplication issues)
// or if we know about the reference (as it should be replaced).
if (cause === RoomUpdateCause.NewRoom && !isSticky && !knownRoomRef) {
this.rooms.push(room);
} }
} }
// If we have tags for a room and don't have the room referenced, something went horribly let didTagChange = false;
// wrong - the reference should have been updated above. if (cause === RoomUpdateCause.PossibleTagChange) {
if (hasTags && !knownRoomRef && !isSticky) { const oldTags = this.roomIdsToTags[room.roomId] || [];
throw new Error(`${room.roomId} is missing from room array but is known - trying to find duplicate`); const newTags = this.getTagsForRoom(room);
} const diff = arrayDiff(oldTags, newTags);
if (diff.removed.length > 0 || diff.added.length > 0) {
for (const rmTag of diff.removed) {
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Removing ${room.roomId} from ${rmTag}`);
}
const algorithm: OrderingAlgorithm = this.algorithms[rmTag];
if (!algorithm) throw new Error(`No algorithm for ${rmTag}`);
await algorithm.handleRoomUpdate(room, RoomUpdateCause.RoomRemoved);
this._cachedRooms[rmTag] = algorithm.orderedRooms;
this.recalculateFilteredRoomsForTag(rmTag); // update filter to re-sort the list
this.recalculateStickyRoom(rmTag); // update sticky room to make sure it moves if needed
}
for (const addTag of diff.added) {
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Adding ${room.roomId} to ${addTag}`);
}
const algorithm: OrderingAlgorithm = this.algorithms[addTag];
if (!algorithm) throw new Error(`No algorithm for ${addTag}`);
await algorithm.handleRoomUpdate(room, RoomUpdateCause.NewRoom);
this._cachedRooms[addTag] = algorithm.orderedRooms;
}
// Like above, update the reference to the sticky room if we need to // Update the tag map so we don't regen it in a moment
if (hasTags && isSticky) { this.roomIdsToTags[room.roomId] = newTags;
// Go directly in and set the sticky room's new reference, being careful not
// to trigger a sticky room update ourselves.
this._stickyRoom.room = room;
}
// If after all that we're still a NewRoom update, add the room if applicable.
// We don't do this for the sticky room (because it causes duplication issues)
// or if we know about the reference (as it should be replaced).
if (cause === RoomUpdateCause.NewRoom && !isSticky && !knownRoomRef) {
this.rooms.push(room);
}
}
let didTagChange = false;
if (cause === RoomUpdateCause.PossibleTagChange) {
const oldTags = this.roomIdsToTags[room.roomId] || [];
const newTags = this.getTagsForRoom(room);
const diff = arrayDiff(oldTags, newTags);
if (diff.removed.length > 0 || diff.added.length > 0) {
for (const rmTag of diff.removed) {
if (SettingsStore.getValue("advancedRoomListLogging")) { if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602 // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Removing ${room.roomId} from ${rmTag}`); console.log(`Changing update cause for ${room.roomId} to Timeline to sort rooms`);
} }
const algorithm: OrderingAlgorithm = this.algorithms[rmTag]; cause = RoomUpdateCause.Timeline;
if (!algorithm) throw new Error(`No algorithm for ${rmTag}`); didTagChange = true;
await algorithm.handleRoomUpdate(room, RoomUpdateCause.RoomRemoved);
this._cachedRooms[rmTag] = algorithm.orderedRooms;
this.recalculateFilteredRoomsForTag(rmTag); // update filter to re-sort the list
this.recalculateStickyRoom(rmTag); // update sticky room to make sure it moves if needed
}
for (const addTag of diff.added) {
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Adding ${room.roomId} to ${addTag}`);
}
const algorithm: OrderingAlgorithm = this.algorithms[addTag];
if (!algorithm) throw new Error(`No algorithm for ${addTag}`);
await algorithm.handleRoomUpdate(room, RoomUpdateCause.NewRoom);
this._cachedRooms[addTag] = algorithm.orderedRooms;
}
// Update the tag map so we don't regen it in a moment
this.roomIdsToTags[room.roomId] = newTags;
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Changing update cause for ${room.roomId} to Timeline to sort rooms`);
}
cause = RoomUpdateCause.Timeline;
didTagChange = true;
} else {
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Received no-op update for ${room.roomId} - changing to Timeline update`);
}
cause = RoomUpdateCause.Timeline;
}
if (didTagChange && isSticky) {
// Manually update the tag for the sticky room without triggering a sticky room
// update. The update will be handled implicitly by the sticky room handling and
// requires no changes on our part, if we're in the middle of a sticky room change.
if (this._lastStickyRoom) {
this._stickyRoom = {
room,
tag: this.roomIdsToTags[room.roomId][0],
position: 0, // right at the top as it changed tags
};
} else { } else {
// We have to clear the lock as the sticky room change will trigger updates. if (SettingsStore.getValue("advancedRoomListLogging")) {
await this.setStickyRoom(room); // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`Received no-op update for ${room.roomId} - changing to Timeline update`);
}
cause = RoomUpdateCause.Timeline;
}
if (didTagChange && isSticky) {
// Manually update the tag for the sticky room without triggering a sticky room
// update. The update will be handled implicitly by the sticky room handling and
// requires no changes on our part, if we're in the middle of a sticky room change.
if (this._lastStickyRoom) {
this._stickyRoom = {
room,
tag: this.roomIdsToTags[room.roomId][0],
position: 0, // right at the top as it changed tags
};
} else {
// We have to clear the lock as the sticky room change will trigger updates.
await this.setStickyRoom(room);
}
} }
} }
}
// If the update is for a room change which might be the sticky room, prevent it. We // If the update is for a room change which might be the sticky room, prevent it. We
// need to make sure that the causes (NewRoom and RoomRemoved) are still triggered though // need to make sure that the causes (NewRoom and RoomRemoved) are still triggered though
// as the sticky room relies on this. // as the sticky room relies on this.
if (cause !== RoomUpdateCause.NewRoom && cause !== RoomUpdateCause.RoomRemoved) { if (cause !== RoomUpdateCause.NewRoom && cause !== RoomUpdateCause.RoomRemoved) {
if (this.stickyRoom === room) { if (this.stickyRoom === room) {
if (SettingsStore.getValue("advancedRoomListLogging")) { if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602 // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.warn(`[RoomListDebug] Received ${cause} update for sticky room ${room.roomId} - ignoring`); console.warn(`[RoomListDebug] Received ${cause} update for sticky room ${room.roomId} - ignoring`);
}
return false;
} }
return false;
} }
}
if (!this.roomIdsToTags[room.roomId]) { if (!this.roomIdsToTags[room.roomId]) {
if (CAUSES_REQUIRING_ROOM.includes(cause)) { if (CAUSES_REQUIRING_ROOM.includes(cause)) {
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.warn(`Skipping tag update for ${room.roomId} because we don't know about the room`);
}
return false;
}
if (SettingsStore.getValue("advancedRoomListLogging")) { if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602 // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.warn(`Skipping tag update for ${room.roomId} because we don't know about the room`); console.log(`[RoomListDebug] Updating tags for room ${room.roomId} (${room.name})`);
}
// Get the tags for the room and populate the cache
const roomTags = this.getTagsForRoom(room).filter(t => !isNullOrUndefined(this.cachedRooms[t]));
// "This should never happen" condition - we specify DefaultTagID.Untagged in getTagsForRoom(),
// which means we should *always* have a tag to go off of.
if (!roomTags.length) throw new Error(`Tags cannot be determined for ${room.roomId}`);
this.roomIdsToTags[room.roomId] = roomTags;
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`[RoomListDebug] Updated tags for ${room.roomId}:`, roomTags);
} }
return false;
} }
if (SettingsStore.getValue("advancedRoomListLogging")) { if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602 // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`[RoomListDebug] Updating tags for room ${room.roomId} (${room.name})`); console.log(`[RoomListDebug] Reached algorithmic handling for ${room.roomId} and cause ${cause}`);
} }
// Get the tags for the room and populate the cache const tags = this.roomIdsToTags[room.roomId];
const roomTags = this.getTagsForRoom(room).filter(t => !isNullOrUndefined(this.cachedRooms[t])); if (!tags) {
console.warn(`No tags known for "${room.name}" (${room.roomId})`);
return false;
}
// "This should never happen" condition - we specify DefaultTagID.Untagged in getTagsForRoom(), let changed = didTagChange;
// which means we should *always* have a tag to go off of. for (const tag of tags) {
if (!roomTags.length) throw new Error(`Tags cannot be determined for ${room.roomId}`); const algorithm: OrderingAlgorithm = this.algorithms[tag];
if (!algorithm) throw new Error(`No algorithm for ${tag}`);
this.roomIdsToTags[room.roomId] = roomTags; await algorithm.handleRoomUpdate(room, cause);
this._cachedRooms[tag] = algorithm.orderedRooms;
// Flag that we've done something
this.recalculateFilteredRoomsForTag(tag); // update filter to re-sort the list
this.recalculateStickyRoom(tag); // update sticky room to make sure it appears if needed
changed = true;
}
if (SettingsStore.getValue("advancedRoomListLogging")) { if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602 // TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`[RoomListDebug] Updated tags for ${room.roomId}:`, roomTags); console.log(`[RoomListDebug] Finished handling ${room.roomId} with cause ${cause} (changed=${changed})`);
} }
return changed;
} finally {
release();
} }
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`[RoomListDebug] Reached algorithmic handling for ${room.roomId} and cause ${cause}`);
}
const tags = this.roomIdsToTags[room.roomId];
if (!tags) {
console.warn(`No tags known for "${room.name}" (${room.roomId})`);
return false;
}
let changed = didTagChange;
for (const tag of tags) {
const algorithm: OrderingAlgorithm = this.algorithms[tag];
if (!algorithm) throw new Error(`No algorithm for ${tag}`);
await algorithm.handleRoomUpdate(room, cause);
this._cachedRooms[tag] = algorithm.orderedRooms;
// Flag that we've done something
this.recalculateFilteredRoomsForTag(tag); // update filter to re-sort the list
this.recalculateStickyRoom(tag); // update sticky room to make sure it appears if needed
changed = true;
}
if (SettingsStore.getValue("advancedRoomListLogging")) {
// TODO: Remove debug: https://github.com/vector-im/element-web/issues/14602
console.log(`[RoomListDebug] Finished handling ${room.roomId} with cause ${cause} (changed=${changed})`);
}
return changed;
} }
} }

30
src/utils/MultiLock.ts Normal file
View file

@ -0,0 +1,30 @@
/*
Copyright 2021 The Matrix.org Foundation C.I.C.
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/
import {EnhancedMap} from "./maps";
import AwaitLock from "await-lock";
export type DoneFn = () => void;
export class MultiLock {
private locks = new EnhancedMap<string, AwaitLock>();
public async acquire(key: string): Promise<DoneFn> {
const lock = this.locks.getOrCreate(key, new AwaitLock());
await lock.acquireAsync();
return () => lock.release();
}
}