From 6f0e781b4970274a7d3452b2821faa745f488f56 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Mon, 26 Sep 2022 19:15:13 +0200 Subject: [PATCH 01/21] WIP --- src/matrix/Session.js | 1 + src/matrix/calls/CallHandler.ts | 11 +- src/matrix/calls/PeerCall.ts | 8 +- src/matrix/calls/callEventTypes.ts | 4 +- src/matrix/calls/common.ts | 2 + src/matrix/calls/group/GroupCall.ts | 149 ++++++++++++++++++++-------- src/matrix/calls/group/Member.ts | 48 ++++++++- src/matrix/e2ee/DeviceTracker.js | 2 +- 8 files changed, 175 insertions(+), 50 deletions(-) diff --git a/src/matrix/Session.js b/src/matrix/Session.js index 31b57b57..291002c5 100644 --- a/src/matrix/Session.js +++ b/src/matrix/Session.js @@ -78,6 +78,7 @@ export class Session { this._user = new User(sessionInfo.userId); this._callHandler = new CallHandler({ clock: this._platform.clock, + random: this._platform.random, hsApi: this._hsApi, encryptDeviceMessage: async (roomId, userId, deviceId, message, log) => { if (!this._deviceTracker || !this._olmEncryption) { diff --git a/src/matrix/calls/CallHandler.ts b/src/matrix/calls/CallHandler.ts index 67cf3dc7..2b914a2f 100644 --- a/src/matrix/calls/CallHandler.ts +++ b/src/matrix/calls/CallHandler.ts @@ -55,12 +55,10 @@ export class CallHandler implements RoomStateHandler { private roomMemberToCallIds: Map> = new Map(); private groupCallOptions: GroupCallOptions; private sessionId = makeId("s"); - private turnServerSource: TurnServerSource; constructor(private readonly options: Options) { - this.turnServerSource = new TurnServerSource(this.options.hsApi, this.options.clock); this.groupCallOptions = Object.assign({}, this.options, { - turnServerSource: this.turnServerSource, + turnServerSource: new TurnServerSource(this.options.hsApi, this.options.clock), emitUpdate: (groupCall, params) => this._calls.update(groupCall.id, params), createTimeout: this.options.clock.createTimeout, sessionId: this.sessionId @@ -247,9 +245,10 @@ export class CallHandler implements RoomStateHandler { } dispose() { - this.turnServerSource.dispose(); - const joinedCalls = Array.from(this._calls.values()).filter(c => c.hasJoined); - Promise.all(joinedCalls.map(c => c.leave())).then(() => {}, () => {}); + this.groupCallOptions.turnServerSource.dispose(); + for(const call of this._calls.values()) { + call.dispose(); + } } } diff --git a/src/matrix/calls/PeerCall.ts b/src/matrix/calls/PeerCall.ts index 0f16b207..d7d815fa 100644 --- a/src/matrix/calls/PeerCall.ts +++ b/src/matrix/calls/PeerCall.ts @@ -1098,7 +1098,13 @@ export class PeerCall implements IDisposable { private async delay(timeoutMs: number): Promise { // Allow a short time for initial candidates to be gathered const timeout = this.disposables.track(this.options.createTimeout(timeoutMs)); - await timeout.elapsed(); + try { + await timeout.elapsed(); + } catch (err) { + if (err.name !== "AbortError") { + throw err; + } + } this.disposables.untrack(timeout); } diff --git a/src/matrix/calls/callEventTypes.ts b/src/matrix/calls/callEventTypes.ts index 09376c85..ca5c870c 100644 --- a/src/matrix/calls/callEventTypes.ts +++ b/src/matrix/calls/callEventTypes.ts @@ -24,7 +24,9 @@ export const SDPStreamMetadataKey = "org.matrix.msc3077.sdp_stream_metadata"; export interface CallDeviceMembership { device_id: string, - session_id: string + session_id: string, + ["m.expires_ts"]?: number, + feeds?: Array<{purpose: string}> } export interface CallMembership { diff --git a/src/matrix/calls/common.ts b/src/matrix/calls/common.ts index 66db6edc..dde55ddc 100644 --- a/src/matrix/calls/common.ts +++ b/src/matrix/calls/common.ts @@ -59,3 +59,5 @@ export class MuteSettings { } export const CALL_LOG_TYPE = "call"; +//export const CALL_MEMBER_VALIDITY_PERIOD_MS = 3600 * 1000; // 1h +export const CALL_MEMBER_VALIDITY_PERIOD_MS = 60 * 1000; diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index 4c038be9..cb027be8 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -15,9 +15,9 @@ limitations under the License. */ import {ObservableMap} from "../../../observable/map/ObservableMap"; -import {Member} from "./Member"; +import {Member, isMemberExpired, memberExpiresAt} from "./Member"; import {LocalMedia} from "../LocalMedia"; -import {MuteSettings, CALL_LOG_TYPE} from "../common"; +import {MuteSettings, CALL_LOG_TYPE, CALL_MEMBER_VALIDITY_PERIOD_MS} from "../common"; import {MemberChange, RoomMember} from "../../room/members/RoomMember"; import {EventEmitter} from "../../../utils/EventEmitter"; import {EventType, CallIntent} from "../callEventTypes"; @@ -26,7 +26,7 @@ import type {Options as MemberOptions} from "./Member"; import type {TurnServerSource} from "../TurnServerSource"; import type {BaseObservableMap} from "../../../observable/map/BaseObservableMap"; import type {Track} from "../../../platform/types/MediaDevices"; -import type {SignallingMessage, MGroupCallBase, CallMembership} from "../callEventTypes"; +import type {SignallingMessage, MGroupCallBase, CallMembership, CallMemberContent, CallDeviceMembership} from "../callEventTypes"; import type {Room} from "../../room/Room"; import type {StateEvent} from "../../storage/types"; import type {Platform} from "../../../platform/web/Platform"; @@ -34,6 +34,7 @@ import type {EncryptedMessage} from "../../e2ee/olm/Encryption"; import type {ILogItem, ILogger} from "../../../logging/types"; import type {Storage} from "../../storage/idb/Storage"; import type {BaseObservableValue} from "../../../observable/value/BaseObservableValue"; +import type {Clock, Timeout} from "../../../platform/web/dom/Clock"; export enum GroupCallState { Fledgling = "fledgling", @@ -59,11 +60,14 @@ export type Options = Omit void; encryptDeviceMessage: (roomId: string, userId: string, deviceId: string, message: SignallingMessage, log: ILogItem) => Promise, storage: Storage, + random: () => number, logger: ILogger, turnServerSource: TurnServerSource }; class JoinedData { + public renewMembershipTimeout?: Timeout; + constructor( public readonly logItem: ILogItem, public readonly membersLogItem: ILogItem, @@ -75,6 +79,7 @@ class JoinedData { dispose() { this.localMedia.dispose(); this.logItem.finish(); + this.renewMembershipTimeout?.dispose(); } } @@ -96,7 +101,17 @@ export class GroupCall extends EventEmitter<{change: never}> { this._state = newCall ? GroupCallState.Fledgling : GroupCallState.Created; this._memberOptions = Object.assign({}, options, { confId: this.id, - emitUpdate: member => this._members.update(getMemberKey(member.userId, member.deviceId), member), + emitUpdate: member => { + if (!member.isExpired) { + this._members.update(getMemberKey(member.userId, member.deviceId), member); + } else if (!member.isConnected) { + // don't just kick out connected members, even if their timestamp expired + this._members.remove(getMemberKey(member.userId, member.deviceId)); + } + if (member.isExpired && member.isConnected) { + console.trace("was about to kick a connected but expired member"); + } + }, encryptDeviceMessage: (userId: string, deviceId: string, message: SignallingMessage, log) => { return this.options.encryptDeviceMessage(this.roomId, userId, deviceId, message, log); } @@ -156,7 +171,7 @@ export class GroupCall extends EventEmitter<{change: never}> { this._state = GroupCallState.Joining; this.emitChange(); await log.wrap("update member state", async log => { - const memberContent = await this._createJoinPayload(); + const memberContent = await this._createMemberPayload(true); log.set("payload", memberContent); // send m.call.member state event const request = this.options.hsApi.sendState(this.roomId, EventType.GroupCallMember, this.options.ownUserId, memberContent, {log}); @@ -220,7 +235,9 @@ export class GroupCall extends EventEmitter<{change: never}> { } await joinedData.logItem.wrap("leave", async log => { try { - const memberContent = await this._leaveCallMemberContent(); + joinedData.renewMembershipTimeout?.dispose(); + joinedData.renewMembershipTimeout = undefined; + const memberContent = await this._createMemberPayload(false); // send m.call.member state event if (memberContent) { const request = this.options.hsApi.sendState(this.roomId, EventType.GroupCallMember, this.options.ownUserId, memberContent, {log}); @@ -296,19 +313,32 @@ export class GroupCall extends EventEmitter<{change: never}> { /** @internal */ updateMembership(userId: string, roomMember: RoomMember, callMembership: CallMembership, syncLog: ILogItem) { syncLog.wrap({l: "update call membership", t: CALL_LOG_TYPE, id: this.id, userId}, log => { + const now = this.options.clock.now(); const devices = callMembership["m.devices"]; const previousDeviceIds = this.getDeviceIdsForUserId(userId); for (const device of devices) { const deviceId = device.device_id; const memberKey = getMemberKey(userId, deviceId); - log.wrap({l: "update device membership", id: memberKey, sessionId: device.session_id}, log => { - if (userId === this.options.ownUserId && deviceId === this.options.ownDeviceId) { + if (userId === this.options.ownUserId && deviceId === this.options.ownDeviceId) { + log.wrap("update own membership", log => { + // TODO: should we check if new device is expired? + if (this.hasJoined) { + this.joinedData!.logItem.refDetached(log); + this._setupRenewMembershipTimeout(device, log); + } if (this._state === GroupCallState.Joining) { - log.set("update_own", true); + log.set("joined", true); this._state = GroupCallState.Joined; this.emitChange(); } - } else { + }); + } else { + log.wrap({l: "update device membership", id: memberKey, sessionId: device.session_id}, log => { + if (isMemberExpired(device, now)) { + log.set("expired", true); + this._members.remove(memberKey); + return; + } let member = this._members.get(memberKey); const sessionIdChanged = member && member.sessionId !== device.session_id; if (member && !sessionIdChanged) { @@ -328,6 +358,7 @@ export class GroupCall extends EventEmitter<{change: never}> { member = new Member( roomMember, device, this._memberOptions, + log ); this._members.add(memberKey, member); if (this.joinedData) { @@ -337,8 +368,8 @@ export class GroupCall extends EventEmitter<{change: never}> { // flush pending messages, either after having created the member, // or updated the session id with updateCallInfo this.flushPendingIncomingDeviceMessages(member, log); - } - }); + }); + } } const newDeviceIds = new Set(devices.map(call => call.device_id)); @@ -466,14 +497,14 @@ export class GroupCall extends EventEmitter<{change: never}> { } } - private async _createJoinPayload() { + private async _createMemberPayload(includeOwn: boolean): Promise { const {storage} = this.options; const txn = await storage.readTxn([storage.storeNames.roomState]); const stateEvent = await txn.roomState.get(this.roomId, EventType.GroupCallMember, this.options.ownUserId); - const stateContent = stateEvent?.event?.content ?? { + const stateContent: CallMemberContent = stateEvent?.event?.content as CallMemberContent ?? { ["m.calls"]: [] }; - const callsInfo = stateContent["m.calls"]; + let callsInfo = stateContent["m.calls"]; let callInfo = callsInfo.find(c => c["m.call_id"] === this.id); if (!callInfo) { callInfo = { @@ -482,32 +513,29 @@ export class GroupCall extends EventEmitter<{change: never}> { }; callsInfo.push(callInfo); } - callInfo["m.devices"] = callInfo["m.devices"].filter(d => d["device_id"] !== this.options.ownDeviceId); - callInfo["m.devices"].push({ - ["device_id"]: this.options.ownDeviceId, - ["session_id"]: this.options.sessionId, - feeds: [{purpose: "m.usermedia"}] - }); - return stateContent; - } - - private async _leaveCallMemberContent(): Promise | undefined> { - const {storage} = this.options; - const txn = await storage.readTxn([storage.storeNames.roomState]); - const stateEvent = await txn.roomState.get(this.roomId, EventType.GroupCallMember, this.options.ownUserId); - if (stateEvent) { - const content = stateEvent.event.content; - const callInfo = content["m.calls"]?.find(c => c["m.call_id"] === this.id); - if (callInfo) { - const devicesInfo = callInfo["m.devices"]; - const deviceIndex = devicesInfo.findIndex(d => d["device_id"] === this.options.ownDeviceId); - if (deviceIndex !== -1) { - devicesInfo.splice(deviceIndex, 1); - return content; - } + const now = this.options.clock.now(); + callInfo["m.devices"] = callInfo["m.devices"].filter(d => { + // remove our own device (to add it again below) + if (d["device_id"] === this.options.ownDeviceId) { + return false; } - + // also remove any expired devices (+ the validity period added again) + if (memberExpiresAt(d) === undefined || isMemberExpired(d, now, CALL_MEMBER_VALIDITY_PERIOD_MS)) { + return false; + } + return true; + }); + if (includeOwn) { + callInfo["m.devices"].push({ + ["device_id"]: this.options.ownDeviceId, + ["session_id"]: this.options.sessionId, + ["m.expires_ts"]: now + CALL_MEMBER_VALIDITY_PERIOD_MS, + feeds: [{purpose: "m.usermedia"}] + }); } + // filter out empty call membership + stateContent["m.calls"] = callsInfo.filter(c => c["m.devices"].length !== 0); + return stateContent; } private connectToMember(member: Member, joinedData: JoinedData, log: ILogItem) { @@ -524,11 +552,52 @@ export class GroupCall extends EventEmitter<{change: never}> { if (connectItem) { log.refDetached(connectItem); } - }) + }); } protected emitChange() { this.emit("change"); this.options.emitUpdate(this); } + + private _setupRenewMembershipTimeout(callDeviceMembership: CallDeviceMembership, log: ILogItem) { + const {joinedData} = this; + if (!joinedData) { + return; + } + joinedData.renewMembershipTimeout?.dispose(); + joinedData.renewMembershipTimeout = undefined; + const expiresAt = memberExpiresAt(callDeviceMembership); + if (typeof expiresAt !== "number") { + return; + } + const expiresFromNow = expiresAt - this.options.clock.now(); + // renew 1 to 5 minutes (8.3% of 1h) before expiring + // do it a bit beforehand and somewhat random to not collide with + // other clients trying to renew as well + const timeToRenewBeforeExpiration = Math.max(4000, Math.ceil((0.2 +(this.options.random() * 0.8)) * (0.08333 * CALL_MEMBER_VALIDITY_PERIOD_MS))); + const renewFromNow = Math.max(0, expiresFromNow - timeToRenewBeforeExpiration); + log.set("expiresIn", expiresFromNow); + log.set("renewIn", renewFromNow); + joinedData.renewMembershipTimeout = this.options.clock.createTimeout(renewFromNow); + joinedData.renewMembershipTimeout.elapsed().then( + () => { + joinedData.logItem.wrap("renew membership", async log => { + const memberContent = await this._createMemberPayload(true); + log.set("payload", memberContent); + // send m.call.member state event + const request = this.options.hsApi.sendState(this.roomId, EventType.GroupCallMember, this.options.ownUserId, memberContent, {log}); + await request.response(); + }); + }, + () => { /* assume we're swallowing AbortError from dispose above */ } + ); + } + + dispose() { + this.joinedData?.dispose(); + for (const member of this._members.values()) { + member.dispose(); + } + } } diff --git a/src/matrix/calls/group/Member.ts b/src/matrix/calls/group/Member.ts index b1c7b430..8e266fac 100644 --- a/src/matrix/calls/group/Member.ts +++ b/src/matrix/calls/group/Member.ts @@ -30,6 +30,7 @@ import type {RoomMember} from "../../room/members/RoomMember"; import type {EncryptedMessage} from "../../e2ee/olm/Encryption"; import type {ILogItem} from "../../../logging/types"; import type {BaseObservableValue} from "../../../observable/value/BaseObservableValue"; +import type {Clock, Timeout} from "../../../platform/web/dom/Clock"; export type Options = Omit & { confId: string, @@ -40,6 +41,7 @@ export type Options = Omit, log: ILogItem) => Promise, emitUpdate: (participant: Member, params?: any) => void, + clock: Clock } const errorCodesWithoutRetry = [ @@ -69,12 +71,33 @@ class MemberConnection { export class Member { private connection?: MemberConnection; + private expireTimeout?: Timeout; constructor( public member: RoomMember, private callDeviceMembership: CallDeviceMembership, private readonly options: Options, - ) {} + updateMemberLog: ILogItem + ) { + this._renewExpireTimeout(updateMemberLog); + } + + private _renewExpireTimeout(log: ILogItem) { + this.expireTimeout?.dispose(); + this.expireTimeout = undefined; + const expiresAt = memberExpiresAt(this.callDeviceMembership); + if (typeof expiresAt !== "number") { + return; + } + const expiresFromNow = Math.max(0, expiresAt - this.options.clock.now()); + log?.set("expiresIn", expiresFromNow); + // add 10ms to make sure isExpired returns true + this.expireTimeout = this.options.clock.createTimeout(expiresFromNow + 10); + this.expireTimeout.elapsed().then( + () => { this.options.emitUpdate(this, "isExpired"); }, + (err) => { /* ignore abort error */ }, + ); + } /** * Gives access the log item for this item once joined to the group call. @@ -89,6 +112,11 @@ export class Member { return this.connection?.peerCall?.remoteMedia; } + get isExpired(): boolean { + // never consider a peer we're connected to, to be expired + return !this.isConnected && isMemberExpired(this.callDeviceMembership, this.options.clock.now()); + } + get remoteMuteSettings(): MuteSettings | undefined { return this.connection?.peerCall?.remoteMuteSettings; } @@ -184,6 +212,7 @@ export class Member { /** @internal */ updateCallInfo(callDeviceMembership: CallDeviceMembership, causeItem: ILogItem) { this.callDeviceMembership = callDeviceMembership; + this._renewExpireTimeout(causeItem); if (this.connection) { this.connection.logItem.refDetached(causeItem); } @@ -352,4 +381,21 @@ export class Member { turnServer: connection.turnServer }), connection.logItem); } + + dispose() { + this.expireTimeout?.dispose(); + this.connection?.peerCall?.dispose(); + } +} + +export function memberExpiresAt(callDeviceMembership: CallDeviceMembership): number | undefined { + const expiresAt = callDeviceMembership["m.expires_ts"]; + if (Number.isSafeInteger(expiresAt)) { + return expiresAt; + } +} + +export function isMemberExpired(callDeviceMembership: CallDeviceMembership, now: number, margin: number = 0) { + const expiresAt = memberExpiresAt(callDeviceMembership); + return typeof expiresAt === "number" && ((expiresAt + margin) <= now); } diff --git a/src/matrix/e2ee/DeviceTracker.js b/src/matrix/e2ee/DeviceTracker.js index 0d0b0e8b..e0eea4fc 100644 --- a/src/matrix/e2ee/DeviceTracker.js +++ b/src/matrix/e2ee/DeviceTracker.js @@ -337,7 +337,7 @@ export class DeviceTracker { // verify signature const verifiedKeysPerUser = log.wrap("verify", log => this._filterVerifiedDeviceKeys(deviceKeyResponse["device_keys"], log)); //// END EXTRACT - + // TODO: what if verifiedKeysPerUser is empty or does not contain userId? const verifiedKeys = verifiedKeysPerUser .find(vkpu => vkpu.userId === userId).verifiedKeys .find(vk => vk["device_id"] === deviceId); From 05bb360c004f89ae48908e9f8497903df7c45cb7 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:12:04 +0200 Subject: [PATCH 02/21] allow to dequeue signalling messages with repeated seq (from other call) they will just be ignored by peerCall.getMessageAction() but we don't want to block dequeuing on these --- src/matrix/calls/group/Member.ts | 23 +++++++++++++++++------ 1 file changed, 17 insertions(+), 6 deletions(-) diff --git a/src/matrix/calls/group/Member.ts b/src/matrix/calls/group/Member.ts index 8e266fac..a21de30f 100644 --- a/src/matrix/calls/group/Member.ts +++ b/src/matrix/calls/group/Member.ts @@ -67,6 +67,22 @@ class MemberConnection { public turnServer: BaseObservableValue, public readonly logItem: ILogItem ) {} + + get canDequeueNextSignallingMessage() { + if (this.queuedSignallingMessages.length === 0) { + return false; + } + if (this.lastProcessedSeqNr === undefined) { + return true; + } + const first = this.queuedSignallingMessages[0]; + // allow messages with both a seq we've just seen and + // the next one to be dequeued as it can happen + // that messages for other callIds (which could repeat seq) + // are present in the queue + return first.content.seq === this.lastProcessedSeqNr || + first.content.seq === this.lastProcessedSeqNr + 1; + } } export class Member { @@ -335,12 +351,7 @@ export class Member { private dequeueSignallingMessages(connection: MemberConnection, peerCall: PeerCall, newMessage: SignallingMessage, syncLog: ILogItem): boolean { let hasNewMessageBeenDequeued = false; - while ( - connection.queuedSignallingMessages.length && ( - connection.lastProcessedSeqNr === undefined || - connection.queuedSignallingMessages[0].content.seq === connection.lastProcessedSeqNr + 1 - ) - ) { + while (connection.canDequeueNextSignallingMessage) { const message = connection.queuedSignallingMessages.shift()!; if (message === newMessage) { hasNewMessageBeenDequeued = true; From 8f8a964b3bc0159f98991f45e6972f90414b45fb Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:15:48 +0200 Subject: [PATCH 03/21] allow to actually process the invite in the new peer call --- src/matrix/calls/group/Member.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/src/matrix/calls/group/Member.ts b/src/matrix/calls/group/Member.ts index a21de30f..d4cc93f4 100644 --- a/src/matrix/calls/group/Member.ts +++ b/src/matrix/calls/group/Member.ts @@ -325,6 +325,7 @@ export class Member { } if (shouldReplace) { connection.peerCall = undefined; + action = IncomingMessageAction.Handle; } } } From 167a19a85babc34845700eb19caf687ae19666d3 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:16:09 +0200 Subject: [PATCH 04/21] untracking from a disposed Disposables is actually not alarming it happens under normal conditions when an abortable action is aborted and you untrack afterwards. --- src/utils/Disposables.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/utils/Disposables.ts b/src/utils/Disposables.ts index f7c7eb53..f27846be 100644 --- a/src/utils/Disposables.ts +++ b/src/utils/Disposables.ts @@ -50,8 +50,8 @@ export class Disposables { } untrack(disposable: Disposable): undefined { - if (this.isDisposed) { - console.warn("Disposables already disposed, cannot untrack"); + // already disposed + if (!this._disposables) { return undefined; } const idx = this._disposables!.indexOf(disposable); From 282cba0ff16016fe75a10c257e1a5310460dc8ec Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:17:07 +0200 Subject: [PATCH 05/21] call points for PeerCall.delay rely on AbortError actually being thrown + fix this in one call point where it wasn't the case --- src/matrix/calls/PeerCall.ts | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/src/matrix/calls/PeerCall.ts b/src/matrix/calls/PeerCall.ts index d7d815fa..a64a1524 100644 --- a/src/matrix/calls/PeerCall.ts +++ b/src/matrix/calls/PeerCall.ts @@ -771,7 +771,8 @@ export class PeerCall implements IDisposable { const {flushCandidatesLog} = this; // MSC2746 recommends these values (can be quite long when calling because the // callee will need a while to answer the call) - await this.delay(this.direction === CallDirection.Inbound ? 500 : 2000); + try { await this.delay(this.direction === CallDirection.Inbound ? 500 : 2000); } + catch (err) { return; } this.sendCandidateQueue(flushCandidatesLog); this.flushCandidatesLog = undefined; } @@ -1100,12 +1101,9 @@ export class PeerCall implements IDisposable { const timeout = this.disposables.track(this.options.createTimeout(timeoutMs)); try { await timeout.elapsed(); - } catch (err) { - if (err.name !== "AbortError") { - throw err; - } + } finally { + this.disposables.untrack(timeout); } - this.disposables.untrack(timeout); } private sendSignallingMessage(message: SignallingMessage, log: ILogItem) { From b5f686b10e052586bbeef935e10d9280301bdeb1 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:17:54 +0200 Subject: [PATCH 06/21] also allow clean up while still in Joining state, otherwise we get stuck in joined state but without joinedData --- src/matrix/calls/group/GroupCall.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index cb027be8..0c9d3e90 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -437,7 +437,7 @@ export class GroupCall extends EventEmitter<{change: never}> { /** @internal */ disconnect(log: ILogItem) { - if (this._state === GroupCallState.Joined) { + if (this.hasJoined) { for (const [,member] of this._members) { const disconnectLogItem = member.disconnect(true); if (disconnectLogItem) { From f2564ed5cc4ad9965d6c4670c56def57ba13a91d Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:20:00 +0200 Subject: [PATCH 07/21] also emit updates for expired, connected members that we didn't kick --- src/matrix/calls/group/GroupCall.ts | 17 +++++++++-------- 1 file changed, 9 insertions(+), 8 deletions(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index 0c9d3e90..db908004 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -102,14 +102,15 @@ export class GroupCall extends EventEmitter<{change: never}> { this._memberOptions = Object.assign({}, options, { confId: this.id, emitUpdate: member => { - if (!member.isExpired) { - this._members.update(getMemberKey(member.userId, member.deviceId), member); - } else if (!member.isConnected) { - // don't just kick out connected members, even if their timestamp expired - this._members.remove(getMemberKey(member.userId, member.deviceId)); - } - if (member.isExpired && member.isConnected) { - console.trace("was about to kick a connected but expired member"); + const memberKey = getMemberKey(member.userId, member.deviceId); + // only remove expired members from the call if we don't have a peer conn with them + if (member.isExpired && !member.isConnected) { + this._members.remove(memberKey); + } else { + if (member.isExpired && member.isConnected) { + console.trace("was about to kick a connected but expired member"); + } + this._members.update(memberKey, member); } }, encryptDeviceMessage: (userId: string, deviceId: string, message: SignallingMessage, log) => { From b694d13348e4f23141c49fa3a18b470a4893f834 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:20:33 +0200 Subject: [PATCH 08/21] can be readonly --- src/matrix/calls/group/GroupCall.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index db908004..729c152e 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -73,7 +73,7 @@ class JoinedData { public readonly membersLogItem: ILogItem, public localMedia: LocalMedia, public localMuteSettings: MuteSettings, - public turnServer: BaseObservableValue + public readonly turnServer: BaseObservableValue ) {} dispose() { From 1dddabc038b8a39e7d2c0a9f18928c1e67ae8884 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 11:21:26 +0200 Subject: [PATCH 09/21] make removing own membership a bit clearer in the logs --- src/matrix/calls/group/GroupCall.ts | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index 729c152e..60099c03 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -432,8 +432,9 @@ export class GroupCall extends EventEmitter<{change: never}> { } private removeOwnDevice(log: ILogItem) { - log.set("leave_own", true); - this.disconnect(log); + log.wrap("remove own membership", log => { + this.disconnect(log); + }); } /** @internal */ From 56ecd39f267de4fb770e9ecae2ca3f307ef0ee95 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 30 Sep 2022 17:46:57 +0200 Subject: [PATCH 10/21] don't assume joinedData is set here although not entirely sure why it wouldn't be --- src/matrix/calls/group/GroupCall.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index 60099c03..ac41a772 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -324,7 +324,9 @@ export class GroupCall extends EventEmitter<{change: never}> { log.wrap("update own membership", log => { // TODO: should we check if new device is expired? if (this.hasJoined) { - this.joinedData!.logItem.refDetached(log); + if (this.joinedData) { + this.joinedData.logItem.refDetached(log); + } this._setupRenewMembershipTimeout(device, log); } if (this._state === GroupCallState.Joining) { From 7eb8015ace99a3ce02455ade28af2eab91703544 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 15:20:05 +0200 Subject: [PATCH 11/21] ensure member.dispose is called when removing member so expiration timer is always stopped --- src/matrix/calls/group/GroupCall.ts | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index ac41a772..c787b00a 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -105,6 +105,7 @@ export class GroupCall extends EventEmitter<{change: never}> { const memberKey = getMemberKey(member.userId, member.deviceId); // only remove expired members from the call if we don't have a peer conn with them if (member.isExpired && !member.isConnected) { + member.dispose(); this._members.remove(memberKey); } else { if (member.isExpired && member.isConnected) { @@ -339,6 +340,7 @@ export class GroupCall extends EventEmitter<{change: never}> { log.wrap({l: "update device membership", id: memberKey, sessionId: device.session_id}, log => { if (isMemberExpired(device, now)) { log.set("expired", true); + this._members.get(memberKey)?.dispose(); this._members.remove(memberKey); return; } @@ -354,6 +356,7 @@ export class GroupCall extends EventEmitter<{change: never}> { if (disconnectLogItem) { log.refDetached(disconnectLogItem); } + member.dispose(); this._members.remove(memberKey); member = undefined; } @@ -462,11 +465,12 @@ export class GroupCall extends EventEmitter<{change: never}> { const member = this._members.get(memberKey); if (member) { log.set("leave", true); - this._members.remove(memberKey); const disconnectLogItem = member.disconnect(false); if (disconnectLogItem) { log.refDetached(disconnectLogItem); } + member.dispose(); + this._members.remove(memberKey); } this.emitChange(); }); From 2ecfb8f13911cd1ec35fcb92ba1227ecf5162d40 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 15:22:15 +0200 Subject: [PATCH 12/21] unify dispose logic in Member --- src/matrix/calls/group/Member.ts | 23 ++++++++++++++--------- 1 file changed, 14 insertions(+), 9 deletions(-) diff --git a/src/matrix/calls/group/Member.ts b/src/matrix/calls/group/Member.ts index d4cc93f4..5f6325b5 100644 --- a/src/matrix/calls/group/Member.ts +++ b/src/matrix/calls/group/Member.ts @@ -83,6 +83,12 @@ class MemberConnection { return first.content.seq === this.lastProcessedSeqNr || first.content.seq === this.lastProcessedSeqNr + 1; } + + dispose() { + this.peerCall?.dispose(); + this.localMedia.dispose(); + this.logItem.finish(); + } } export class Member { @@ -210,18 +216,15 @@ export class Member { return; } let disconnectLogItem; + // if if not sending the hangup, still log disconnect connection.logItem.wrap("disconnect", async log => { disconnectLogItem = log; - if (hangup) { - await connection.peerCall?.hangup(CallErrorCode.UserHangup, log); - } else { - await connection.peerCall?.close(undefined, log); + if (hangup && connection.peerCall) { + await connection.peerCall.hangup(CallErrorCode.UserHangup, log); } - connection.peerCall?.dispose(); - connection.localMedia?.dispose(); - this.connection = undefined; }); - connection.logItem.finish(); + connection.dispose(); + this.connection = undefined; return disconnectLogItem; } @@ -395,8 +398,10 @@ export class Member { } dispose() { + this.connection?.dispose(); + this.connection = undefined; this.expireTimeout?.dispose(); - this.connection?.peerCall?.dispose(); + this.expireTimeout = undefined; } } From c87fd4dfed64346449876faacf48f8fecaf25109 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 15:59:45 +0200 Subject: [PATCH 13/21] cleanup --- src/matrix/calls/group/GroupCall.ts | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index c787b00a..64249176 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -548,8 +548,11 @@ export class GroupCall extends EventEmitter<{change: never}> { private connectToMember(member: Member, joinedData: JoinedData, log: ILogItem) { const memberKey = getMemberKey(member.userId, member.deviceId); - const logItem = joinedData.membersLogItem.child({l: "member", id: memberKey}); - logItem.set("sessionId", member.sessionId); + const logItem = joinedData.membersLogItem.child({ + l: "member", + id: memberKey, + sessionId: member.sessionId + }); log.wrap({l: "connect", id: memberKey}, log => { const connectItem = member.connect( joinedData.localMedia, From 7ae9c3af0d7cec33cb82b8a9a87ad82d8220a985 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 16:00:38 +0200 Subject: [PATCH 14/21] renew at least 10s before own membership expires --- src/matrix/calls/group/GroupCall.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index 64249176..bdb3844b 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -583,10 +583,10 @@ export class GroupCall extends EventEmitter<{change: never}> { return; } const expiresFromNow = expiresAt - this.options.clock.now(); - // renew 1 to 5 minutes (8.3% of 1h) before expiring + // renew 1 to 5 minutes (8.3% of 1h, but min 10s) before expiring // do it a bit beforehand and somewhat random to not collide with // other clients trying to renew as well - const timeToRenewBeforeExpiration = Math.max(4000, Math.ceil((0.2 +(this.options.random() * 0.8)) * (0.08333 * CALL_MEMBER_VALIDITY_PERIOD_MS))); + const timeToRenewBeforeExpiration = Math.max(10000, Math.ceil((0.2 +(this.options.random() * 0.8)) * (0.08333 * CALL_MEMBER_VALIDITY_PERIOD_MS))); const renewFromNow = Math.max(0, expiresFromNow - timeToRenewBeforeExpiration); log.set("expiresIn", expiresFromNow); log.set("renewIn", renewFromNow); From a8ac504efdc0966badb670fd4186f601d8f7d957 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 16:10:36 +0200 Subject: [PATCH 15/21] explain when joinedData is set --- src/matrix/calls/group/GroupCall.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index bdb3844b..c90c7d2c 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -88,6 +88,7 @@ export class GroupCall extends EventEmitter<{change: never}> { private _memberOptions: MemberOptions; private _state: GroupCallState; private bufferedDeviceMessages = new Map>>(); + /** Set between calling join and leave. */ private joinedData?: JoinedData; constructor( From a07be730f94bc290df5b65af345e33f73ee05e2f Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 16:10:50 +0200 Subject: [PATCH 16/21] bring member validity period back to 1h --- src/matrix/calls/common.ts | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/src/matrix/calls/common.ts b/src/matrix/calls/common.ts index dde55ddc..015e0df8 100644 --- a/src/matrix/calls/common.ts +++ b/src/matrix/calls/common.ts @@ -59,5 +59,4 @@ export class MuteSettings { } export const CALL_LOG_TYPE = "call"; -//export const CALL_MEMBER_VALIDITY_PERIOD_MS = 3600 * 1000; // 1h -export const CALL_MEMBER_VALIDITY_PERIOD_MS = 60 * 1000; +export const CALL_MEMBER_VALIDITY_PERIOD_MS = 3600 * 1000; // 1h From 4a36fd96e464727c06a1c45ed64a52cf1d5f610c Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Thu, 6 Oct 2022 16:11:16 +0200 Subject: [PATCH 17/21] update bundled logviewer --- package.json | 2 +- yarn.lock | 8 ++++---- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/package.json b/package.json index e3f82fa1..f470bd9f 100644 --- a/package.json +++ b/package.json @@ -31,7 +31,7 @@ }, "homepage": "https://github.com/vector-im/hydrogen-web/#readme", "devDependencies": { - "@matrixdotorg/structured-logviewer": "^0.0.1", + "@matrixdotorg/structured-logviewer": "^0.0.3", "@typescript-eslint/eslint-plugin": "^4.29.2", "@typescript-eslint/parser": "^4.29.2", "acorn": "^8.6.0", diff --git a/yarn.lock b/yarn.lock index 0408a6e0..9b9e5453 100644 --- a/yarn.lock +++ b/yarn.lock @@ -56,10 +56,10 @@ version "3.2.8" resolved "https://gitlab.matrix.org/api/v4/projects/27/packages/npm/@matrix-org/olm/-/@matrix-org/olm-3.2.8.tgz#8d53636d045e1776e2a2ec6613e57330dd9ce856" -"@matrixdotorg/structured-logviewer@^0.0.1": - version "0.0.1" - resolved "https://registry.yarnpkg.com/@matrixdotorg/structured-logviewer/-/structured-logviewer-0.0.1.tgz#9c29470b552f874afbb1df16c6e8e9e0c55cbf59" - integrity sha512-IdPYxAFDEoEs2G1ImKCkCxFI3xF1DDctP3N9JOtHRvIPbPPdTT9DyNqKTewCb5zwjNB1mGBrnWyURnHDiOOL3w== +"@matrixdotorg/structured-logviewer@^0.0.3": + version "0.0.3" + resolved "https://registry.yarnpkg.com/@matrixdotorg/structured-logviewer/-/structured-logviewer-0.0.3.tgz#1555111159d83cde0cfd5ba1a571e1faa1a90871" + integrity sha512-QqFglx0M8ix0IoRsJXDg1If26ltbYfuLjJ0MQrJYze3yz4ayEESRpQEA0YxJRVVtbco5M94tmrDpikokTFnn3A== "@nodelib/fs.scandir@2.1.5": version "2.1.5" From 400df6a4fff84ac8fa0f7460541abcd1659e62ce Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 7 Oct 2022 10:07:10 +0200 Subject: [PATCH 18/21] ensure removing expired members from call is always logged also return the log item from logger.log so we can ref it --- src/logging/Logger.ts | 3 ++- src/logging/types.ts | 2 +- src/matrix/calls/group/GroupCall.ts | 11 +++++++---- 3 files changed, 10 insertions(+), 6 deletions(-) diff --git a/src/logging/Logger.ts b/src/logging/Logger.ts index 37a3326c..d3aa1d6d 100644 --- a/src/logging/Logger.ts +++ b/src/logging/Logger.ts @@ -30,10 +30,11 @@ export class Logger implements ILogger { this._platform = platform; } - log(labelOrValues: LabelOrValues, logLevel: LogLevel = LogLevel.Info): void { + log(labelOrValues: LabelOrValues, logLevel: LogLevel = LogLevel.Info): ILogItem { const item = new LogItem(labelOrValues, logLevel, this); item.end = item.start; this._persistItem(item, undefined, false); + return item; } /** Prefer `run()` or `log()` above this method; only use it if you have a long-running operation diff --git a/src/logging/types.ts b/src/logging/types.ts index 0ed3b0dc..0f4f6150 100644 --- a/src/logging/types.ts +++ b/src/logging/types.ts @@ -68,7 +68,7 @@ export interface ILogItemCreator { */ export interface ILogger { - log(labelOrValues: LabelOrValues, logLevel?: LogLevel): void; + log(labelOrValues: LabelOrValues, logLevel?: LogLevel): ILogItem; child(labelOrValues: LabelOrValues, logLevel?: LogLevel, filterCreator?: FilterCreator): ILogItem; wrapOrRun(item: ILogItem | undefined, labelOrValues: LabelOrValues, callback: LogCallback, logLevel?: LogLevel, filterCreator?: FilterCreator): T; runDetached(labelOrValues: LabelOrValues, callback: LogCallback, logLevel?: LogLevel, filterCreator?: FilterCreator): ILogItem; diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index c90c7d2c..a8b6605f 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -104,14 +104,17 @@ export class GroupCall extends EventEmitter<{change: never}> { confId: this.id, emitUpdate: member => { const memberKey = getMemberKey(member.userId, member.deviceId); - // only remove expired members from the call if we don't have a peer conn with them + // only remove expired members to whom we're not already connected if (member.isExpired && !member.isConnected) { + const logItem = this.options.logger.log({ + l: "removing expired member from call", + memberKey, + callId: this.id + }) + member.logItem?.refDetached(logItem); member.dispose(); this._members.remove(memberKey); } else { - if (member.isExpired && member.isConnected) { - console.trace("was about to kick a connected but expired member"); - } this._members.update(memberKey, member); } }, From 793686393414006c98f6a7dd73e5c092f2200362 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 7 Oct 2022 10:07:46 +0200 Subject: [PATCH 19/21] remove options on dispose in Member to ensure callback can't be called anymore, as we don't check that the member argument is the one currently in GroupCall._members. --- src/matrix/calls/group/Member.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/matrix/calls/group/Member.ts b/src/matrix/calls/group/Member.ts index 5f6325b5..8763bf5e 100644 --- a/src/matrix/calls/group/Member.ts +++ b/src/matrix/calls/group/Member.ts @@ -98,7 +98,7 @@ export class Member { constructor( public member: RoomMember, private callDeviceMembership: CallDeviceMembership, - private readonly options: Options, + private options: Options, updateMemberLog: ILogItem ) { this._renewExpireTimeout(updateMemberLog); @@ -402,6 +402,8 @@ export class Member { this.connection = undefined; this.expireTimeout?.dispose(); this.expireTimeout = undefined; + // ensure the emitUpdate callback can't be called anymore + this.options = undefined as any as Options; } } From 4350537004c3e9af6d2a6c633a1bbd440d321fd7 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 7 Oct 2022 10:58:12 +0200 Subject: [PATCH 20/21] cleanup --- src/matrix/calls/group/GroupCall.ts | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index a8b6605f..84fb9be9 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -344,8 +344,12 @@ export class GroupCall extends EventEmitter<{change: never}> { log.wrap({l: "update device membership", id: memberKey, sessionId: device.session_id}, log => { if (isMemberExpired(device, now)) { log.set("expired", true); - this._members.get(memberKey)?.dispose(); - this._members.remove(memberKey); + const member = this._members.get(memberKey); + if (member) { + member.dispose(); + this._members.remove(memberKey); + log.set("removed", true); + } return; } let member = this._members.get(memberKey); From 7d10bec4acb65c8fd2c696a0994a0f98c6467982 Mon Sep 17 00:00:00 2001 From: Bruno Windels <274386+bwindels@users.noreply.github.com> Date: Fri, 7 Oct 2022 10:59:13 +0200 Subject: [PATCH 21/21] remove comment not relevant anymore --- src/matrix/calls/group/GroupCall.ts | 1 - 1 file changed, 1 deletion(-) diff --git a/src/matrix/calls/group/GroupCall.ts b/src/matrix/calls/group/GroupCall.ts index 84fb9be9..f2561f32 100644 --- a/src/matrix/calls/group/GroupCall.ts +++ b/src/matrix/calls/group/GroupCall.ts @@ -327,7 +327,6 @@ export class GroupCall extends EventEmitter<{change: never}> { const memberKey = getMemberKey(userId, deviceId); if (userId === this.options.ownUserId && deviceId === this.options.ownDeviceId) { log.wrap("update own membership", log => { - // TODO: should we check if new device is expired? if (this.hasJoined) { if (this.joinedData) { this.joinedData.logItem.refDetached(log);