diff --git a/apps/webapp/src/script/mls/MLSConversations.test.ts b/apps/webapp/src/script/mls/MLSConversations.test.ts index a4ca2255948..3f00db75065 100644 --- a/apps/webapp/src/script/mls/MLSConversations.test.ts +++ b/apps/webapp/src/script/mls/MLSConversations.test.ts @@ -19,6 +19,7 @@ import {CONVERSATION_TYPE} from '@wireapp/api-client/lib/conversation'; import {CONVERSATION_PROTOCOL} from '@wireapp/api-client/lib/team'; +import {result, task} from 'true-myth'; import {randomUUID} from 'crypto'; @@ -47,6 +48,10 @@ function createMLSConversations(nbConversations: number, type?: CONVERSATION_TYP return Array.from(new Array(nbConversations)).map(() => createMLSConversation(type)); } +function mockSafeEpoch(core: Account) { + core.service!.mls!.getSafeEpoch = jest.fn().mockResolvedValue(task.fromResult(result.ok(1))); +} + describe('MLSConversations', () => { const testFactory = new TestFactory(); @@ -64,6 +69,10 @@ describe('MLSConversations', () => { const conversationRepository = await testFactory.exposeConversationActors(); const repositoryCore = (conversationRepository as any).core as Core; jest.spyOn(repositoryCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(false); + jest + .spyOn((conversationRepository as any).conversationService, 'getConversationById') + .mockResolvedValue({epoch: 1}); + mockSafeEpoch(repositoryCore); const joinSpy = jest.spyOn(repositoryCore.service!.conversation, 'joinByExternalCommit'); await initMLSGroupConversations(mlsConversations, conversationRepository, {core: repositoryCore}); @@ -81,6 +90,7 @@ describe('MLSConversations', () => { const repositoryCore = (conversationRepository as any).core as Core; jest.spyOn(repositoryCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(false); + mockSafeEpoch(repositoryCore); const joinSpy = jest.spyOn(repositoryCore.service!.conversation, 'joinByExternalCommit'); await initMLSGroupConversations([mlsConversation], conversationRepository, {core: repositoryCore}); @@ -96,6 +106,7 @@ describe('MLSConversations', () => { const mlsConversations = createMLSConversations(nbMLSConversations, CONVERSATION_TYPE.REGULAR); jest.spyOn(core.service!.conversation!, 'mlsGroupExistsLocally').mockResolvedValue(true); + mockSafeEpoch(core); jest.spyOn(core.service!.mls!, 'scheduleKeyMaterialRenewal'); const conversationRepository = await testFactory.exposeConversationActors(); @@ -119,6 +130,7 @@ describe('MLSConversations', () => { const mlsConversations = createMLSConversations(nbMLSConversations); const conversations = [teamConversation, ...mlsConversations, selfConversation]; + mockSafeEpoch(core); const conversationRepository = await testFactory.exposeConversationActors(); @@ -143,6 +155,9 @@ describe('MLSConversations', () => { const conversations = [teamConversation, ...mlsConversations, selfConversation]; const conversationRepository = await testFactory.exposeConversationActors(); + const repositoryCore = (conversationRepository as any).core as Core; + jest.spyOn(repositoryCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(true); + mockSafeEpoch(core); await initialiseSelfAndTeamConversations(conversations, conversationRepository, new User(), 'clientId', core); @@ -165,10 +180,15 @@ describe('MLSConversations', () => { const conversationRepository = await testFactory.exposeConversationActors(); const repositoryCore = (conversationRepository as any).core as Core; + mockSafeEpoch(repositoryCore); // MLS group is not yet established locally jest.spyOn(repositoryCore.service!.mls!, 'isConversationEstablished').mockResolvedValue(false); - const joinSpy = jest.spyOn(repositoryCore.service!.conversation!, 'joinByExternalCommit'); + jest.spyOn(repositoryCore.service!.conversation!, 'mlsGroupExistsLocally').mockResolvedValue(false); + jest + .spyOn((conversationRepository as any).conversationService, 'getConversationById') + .mockResolvedValue({epoch: 1}); + const joinSpy = jest.spyOn(repositoryCore.service!.conversation!, 'joinByExternalCommit'); await initialiseSelfAndTeamConversations( conversations, conversationRepository, @@ -199,6 +219,8 @@ describe('MLSConversations', () => { jest.spyOn(core.service!.mls!, 'isConversationEstablished').mockResolvedValue(true); const conversationRepository = await testFactory.exposeConversationActors(); + mockSafeEpoch(core); + await initialiseSelfAndTeamConversations(conversations, conversationRepository, new User(), 'clientId', core); expect(core.service!.mls!.registerConversation).not.toHaveBeenCalled(); diff --git a/apps/webapp/src/script/mls/MLSConversations.ts b/apps/webapp/src/script/mls/MLSConversations.ts index 9447a7e9ad4..a2b1b4252a3 100644 --- a/apps/webapp/src/script/mls/MLSConversations.ts +++ b/apps/webapp/src/script/mls/MLSConversations.ts @@ -91,6 +91,10 @@ export async function initMLSGroupConversation( onError?: (conversation: Conversation, error: unknown) => void; }, ): Promise { + logger.info('Initialising MLS group conversation', { + conversationId: mlsConversation.qualifiedId, + groupId: mlsConversation.groupId, + }); const {mls: mlsService, conversation: conversationService} = core.service || {}; if (!mlsService || !conversationService) { throw new Error('MLS or Conversation service is not available!'); @@ -112,7 +116,6 @@ export async function initMLSGroupConversation( await conversationRepository.ensureConversationExists({ groupId, conversationId: qualifiedId, - epoch: mlsConversation.epoch, core, }); @@ -138,6 +141,7 @@ export async function initialiseSelfAndTeamConversations( selfClientId: string, core: Account, ): Promise { + logger.info('Initialising self and team conversations'); const {mls: mlsService, conversation: conversationService} = core.service || {}; if (!mlsService || !conversationService) { throw new Error('MLS or Conversation service is not available!'); @@ -169,17 +173,15 @@ export async function initialiseSelfAndTeamConversations( return Promise.resolve(); } - logger.info('Conversation does not exist, ensuring establishment', { + logger.info('Conversation is not established, trying to establish', { conversationId: conversation.qualifiedId, groupId: conversation.groupId, - epoch: conversation.epoch, }); // Otherwise, we need to ensure the conversation exists by establishing it or joining it by external commit. await conversationRepository.ensureConversationExists({ conversationId: conversation.qualifiedId, groupId: conversation.groupId, - epoch: conversation.epoch, core, }); }), diff --git a/apps/webapp/src/script/mls/MLSMigration/migrationFinaliser/joinConversationsAfterMigrationFinalisation/joinConversationsAfterMigrationFinalisation.test.ts b/apps/webapp/src/script/mls/MLSMigration/migrationFinaliser/joinConversationsAfterMigrationFinalisation/joinConversationsAfterMigrationFinalisation.test.ts index f412ac4ed7d..3ca71cc9e48 100644 --- a/apps/webapp/src/script/mls/MLSMigration/migrationFinaliser/joinConversationsAfterMigrationFinalisation/joinConversationsAfterMigrationFinalisation.test.ts +++ b/apps/webapp/src/script/mls/MLSMigration/migrationFinaliser/joinConversationsAfterMigrationFinalisation/joinConversationsAfterMigrationFinalisation.test.ts @@ -115,6 +115,12 @@ const createConversation = ( return conversation; }; +const mockSafeEpoch = (core: Core) => { + (core.service!.mls! as any).getSafeEpoch = jest + .fn() + .mockResolvedValue({isOk: false, isErr: true, error: new Error('mocked getSafeEpoch error')}); +}; + describe('joinConversationsAfterMigrationFinalisation', () => { const testFactory = new TestFactory(); @@ -124,6 +130,7 @@ describe('joinConversationsAfterMigrationFinalisation', () => { it('Should join MLS groups of group conversations and call onSuccess callback after successful join', async () => { const mockCore = container.resolve(Core); + mockSafeEpoch(mockCore); jest.spyOn(mockCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(false); @@ -144,6 +151,10 @@ describe('joinConversationsAfterMigrationFinalisation', () => { const onSuccess = jest.fn(); const conversationRepository = await testFactory.exposeConversationActors(); + jest + .spyOn((conversationRepository as any).conversationService, 'getConversationById') + .mockResolvedValue({epoch: 1}); + await joinConversationsAfterMigrationFinalisation({ conversations: [mockedConversation], conversationRepository, @@ -161,6 +172,7 @@ describe('joinConversationsAfterMigrationFinalisation', () => { it('Should ignore other type of conversations (e.g. 1:1)', async () => { const mockCore = container.resolve(Core); + mockSafeEpoch(mockCore); jest.spyOn(mockCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(false); @@ -197,6 +209,7 @@ describe('joinConversationsAfterMigrationFinalisation', () => { it('Should not join MLS conversation that was already MLS in the store', async () => { const mockCore = container.resolve(Core); + mockSafeEpoch(mockCore); jest.spyOn(mockCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(false); @@ -233,6 +246,7 @@ describe('joinConversationsAfterMigrationFinalisation', () => { it('Should not join MLS conversation if conversation was not migrated', async () => { const mockCore = container.resolve(Core); + mockSafeEpoch(mockCore); jest.spyOn(mockCore.service!.conversation, 'mlsGroupExistsLocally').mockResolvedValue(false); diff --git a/apps/webapp/src/script/mls/MLSMigration/migrationInitialiser/joinUnestablishedMixedConversations/joinUnestablishedMixedConversations.test.ts b/apps/webapp/src/script/mls/MLSMigration/migrationInitialiser/joinUnestablishedMixedConversations/joinUnestablishedMixedConversations.test.ts index e4db0022f24..bcaa585aaff 100644 --- a/apps/webapp/src/script/mls/MLSMigration/migrationInitialiser/joinUnestablishedMixedConversations/joinUnestablishedMixedConversations.test.ts +++ b/apps/webapp/src/script/mls/MLSMigration/migrationInitialiser/joinUnestablishedMixedConversations/joinUnestablishedMixedConversations.test.ts @@ -60,8 +60,13 @@ describe('joinUnestablishedMixedConversations', () => { return Promise.resolve(!groupId.includes('unestablished')); }); + (repositoryCore.service!.mls! as any).getSafeEpoch = jest.fn().mockResolvedValue({isOk: true, error: null}); + // Spy on joinByExternalCommit of the repository's core instance const joinSpy = jest.spyOn(repositoryCore.service!.conversation!, 'joinByExternalCommit'); + jest + .spyOn((mockedConversationRepository as any).conversationService, 'getConversationById') + .mockResolvedValue({epoch: 1}); await joinUnestablishedMixedConversations( [mixedConversation1, mixedConversation2, mixedConversation3, mixedConversation4], diff --git a/apps/webapp/src/script/repositories/conversation/ConversationRepository.ts b/apps/webapp/src/script/repositories/conversation/ConversationRepository.ts index 9da3e857081..51bef6b31b8 100644 --- a/apps/webapp/src/script/repositories/conversation/ConversationRepository.ts +++ b/apps/webapp/src/script/repositories/conversation/ConversationRepository.ts @@ -2223,50 +2223,57 @@ export class ConversationRepository { public ensureConversationExists = async ({ conversationId, groupId, - epoch, core = this.core, - retry = true, }: { conversationId: QualifiedId; groupId: string; - epoch: number; core?: Account; - retry?: boolean; }): Promise => { - this.logger.info('Ensuring conversation exists', {conversationId, groupId, epoch}); - if (await this.conversationService.mlsGroupExistsLocally(groupId)) { - const coreCryptoEpochNumber = await core.service?.mls?.getEpoch(groupId); - this.logger.info('Conversation already exists locally', {conversationId, groupId, epoch, coreCryptoEpochNumber}); - if (coreCryptoEpochNumber === 0) { - if (!retry) { - this.logger.error('Epoch is 0, but retry is false, not retrying again', { - conversationId, - groupId, - epoch, - coreCryptoEpochNumber, - }); - return; - } - return this.recoverFromLocalUnestablishedMLSConversations({ - conversationId, - groupId, - epoch: coreCryptoEpochNumber, - core, - }); - } + const conversationExistsOnCoreCrypto = await this.conversationService.mlsGroupExistsLocally(groupId); + const coreCryptoEpochNumberResult = await core.service?.mls?.getSafeEpoch(groupId); + const coreCryptoEpochNumber = coreCryptoEpochNumberResult.isOk ? coreCryptoEpochNumberResult.value : undefined; + + this.logger.info('Ensuring conversation exists', { + conversationId, + groupId, + coreCryptoEpochNumber, + conversationExistsOnCoreCrypto, + }); + + if (coreCryptoEpochNumberResult.isErr) { + this.logger.warn( + 'conversation existed on core crypto but there was an error when retrieving its epoch number', + coreCryptoEpochNumberResult.error, + ); + } + + if (conversationExistsOnCoreCrypto && coreCryptoEpochNumber > 0) { + this.logger.info('Conversation is established and epoch is greater than 0, no action needed'); + // return early so we don't make unnecessary calls to the backend to fetch remote conversation return; } - // establish the conversation if epoch is 0 - if (epoch === 0) { - this.logger.info('Establishing conversation as epoch is 0', {conversationId, groupId, epoch}); - await this.establishMlsGroupConversation({conversationId, groupId, epoch, core}); + if (conversationExistsOnCoreCrypto && coreCryptoEpochNumber === 0) { + this.logger.info('Conversation already exists locally but epoch is 0, wiping it'); + + // The conversation was created locally but the initial commit was never accepted by the backend + // Wipe the conversation locally and join by external commit + await core.service?.conversation?.wipeMLSConversation(groupId); + } + + const remoteConversation = await this.conversationService.getConversationById(conversationId); + const remoteEpoch = remoteConversation.epoch; + + // establish the conversation if remote epoch is 0 + if (remoteEpoch === 0) { + this.logger.info('Establishing conversation as remote epoch is 0', {remoteEpoch}); + await this.establishMlsGroupConversation({conversationId, groupId, epoch: remoteEpoch, core}); return; } // join by external commit - this.logger.info('Joining conversation by external commit', {conversationId, epoch}); - if (epoch && epoch > 0) { + if (remoteEpoch && remoteEpoch > 0) { + this.logger.info('Joining conversation by external commit', {remoteEpoch}); await this.core.service?.conversation?.joinByExternalCommit(conversationId); } }; @@ -2310,55 +2317,6 @@ export class ConversationRepository { ); }; - /** - * Recovers from local unestablished MLS conversations by refetching metadata and re-establishing the conversation. - * This is typically needed when the local epoch is 0 but the epoch on backend is greater than 0 - * indicating that the conversation has not been properly established. - * throws error in case both local and remote MLS group are at epoch 0 or remote epoch is not available - */ - private recoverFromLocalUnestablishedMLSConversations = async ({ - conversationId, - groupId, - epoch, - core = this.core, - }: { - conversationId: QualifiedId; - groupId: string; - epoch: number; - core?: Account; - }) => { - try { - this.logger.info('Epoch is 0, refetching conversation metadata and re-establishing', { - conversationId, - groupId, - epoch, - }); - await core.service?.conversation?.wipeMLSConversation(groupId); - const remoteConversation = await this.conversationService.getConversationById(conversationId); - const remoteEpoch = remoteConversation.epoch; - if (!remoteEpoch) { - this.logger.error('Remote epoch is not available!', {remoteConversation}); - throw new Error('Remote epoch is not available!'); - } - if (remoteEpoch === epoch) { - const errorMessage = - 'Cannot recover: both local and remote MLS group are at epoch 0, the conversation was never established on the backend'; - this.logger.error(errorMessage, {remoteEpoch, epoch}); - throw new Error(errorMessage); - } - - return this.ensureConversationExists({conversationId, groupId, epoch: remoteEpoch, core, retry: false}); - } catch (error: unknown) { - this.logger.error('Failed to recover from local unestablished MLS conversation', { - error, - conversationId, - groupId, - epoch, - }); - throw error; - } - }; - /** * will locally delete conversations that no longer exist on backend side */ diff --git a/apps/webapp/src/script/repositories/conversation/MessageRepository.ts b/apps/webapp/src/script/repositories/conversation/MessageRepository.ts index e0b865f5e12..455f5dd6174 100644 --- a/apps/webapp/src/script/repositories/conversation/MessageRepository.ts +++ b/apps/webapp/src/script/repositories/conversation/MessageRepository.ts @@ -1003,10 +1003,10 @@ export class MessageRepository { try { if (isMLSConversation(conversation)) { + this.logger.info('Sending message to a MLS conversation, ensuring conversation exists'); await this.conversationRepositoryProvider().ensureConversationExists({ conversationId: conversation.qualifiedId, groupId: conversation.groupId, - epoch: conversation.epoch, }); } const result = await this.conversationService.send(sendOptions); diff --git a/libraries/core/src/conversation/conversationService/conversationService.ts b/libraries/core/src/conversation/conversationService/conversationService.ts index 2b69ed97eb9..310fc9e12eb 100644 --- a/libraries/core/src/conversation/conversationService/conversationService.ts +++ b/libraries/core/src/conversation/conversationService/conversationService.ts @@ -566,6 +566,7 @@ export class ConversationService extends TypedEventEmitter { * The join operation itself is not automatically re-run by policy. */ public async joinByExternalCommit(conversationId: QualifiedId): Promise { + this.logger.info('Joining MLS conversation via external commit (orchestrated)', {conversationId}); await this.MLSRecoveryOrchestrator.execute({ context: {operationName: OperationName.joinExternalCommit, qualifiedConversationId: conversationId}, callBack: () => this.performJoinByExternalCommitAPI(conversationId), @@ -574,6 +575,7 @@ export class ConversationService extends TypedEventEmitter { // Low-level API call for joining via external commit (no recovery logic) private async performJoinByExternalCommitAPI(conversationId: QualifiedId): Promise { + this.logger.info('Joining MLS conversation via external commit (low-level)', {conversationId}); await this.mlsService.joinByExternalCommit(() => this.apiClient.api.conversation.getGroupInfo(conversationId)); } diff --git a/libraries/core/src/messagingProtocols/mls/eventHandler/events/messageAdd/messageAdd.ts b/libraries/core/src/messagingProtocols/mls/eventHandler/events/messageAdd/messageAdd.ts index 62aff1d806d..99847beb2e3 100644 --- a/libraries/core/src/messagingProtocols/mls/eventHandler/events/messageAdd/messageAdd.ts +++ b/libraries/core/src/messagingProtocols/mls/eventHandler/events/messageAdd/messageAdd.ts @@ -49,6 +49,18 @@ export const handleMLSMessageAdd = async ({ const groupIdBytes = Decoder.fromBase64(groupId).asBytes; + // Helpful for correlating decrypt failures with rejoin/epoch transitions. + const coreCryptoEpochNumber = await mlsService.getSafeEpoch(groupId); + logger.info('Decrypting MLS message-add payload', { + qualifiedConversationId, + groupId, + coreCryptoEpochNumber: coreCryptoEpochNumber.match({ + Ok: epoch => epoch, + Err: error => error, + }), + eventTime: event.time, + }); + const decryptedMessage = await mlsService.decryptMessage( new ConversationId(groupIdBytes), encryptedData, diff --git a/libraries/core/src/messagingProtocols/mls/mlsService/mlsService.ts b/libraries/core/src/messagingProtocols/mls/mlsService/mlsService.ts index 6d26a6f53a7..140c0886ad4 100644 --- a/libraries/core/src/messagingProtocols/mls/mlsService/mlsService.ts +++ b/libraries/core/src/messagingProtocols/mls/mlsService/mlsService.ts @@ -28,6 +28,7 @@ import { import {ConversationMLSMessageAddEvent, ConversationMLSWelcomeEvent} from '@wireapp/api-client/lib/event'; import {QualifiedId} from '@wireapp/api-client/lib/user'; import {Converter, Decoder, Encoder} from 'bazinga64'; +import {Task, task} from 'true-myth'; import {APIClient} from '@wireapp/api-client'; import {LogFactory, TimeUtil, TypedEventEmitter} from '@wireapp/commons'; @@ -464,11 +465,34 @@ export class MLSService extends TypedEventEmitter { return {keyPackages: coreCryptoKeyPackagesPayload, failures}; } + /** + * @deprecated Use `getSafeEpoch` to receive a `Task` with explicit error handling. + */ public getEpoch(groupId: string | Uint8Array) { const groupIdBytes = typeof groupId === 'string' ? Decoder.fromBase64(groupId).asBytes : groupId; return this.coreCryptoClient.conversationEpoch(new ConversationId(groupIdBytes)); } + /** + * Safely reads the current MLS epoch for a conversation. + * + * Returns a `Task` so errors are modeled in the type instead of surfacing + * as an uncaught promise rejection. + * + * A common rejection reason is a core-crypto error equivalent to: + * `MlsErrorOther: Couldn't find conversation` (for example when the group is + * not present on core-crypto level). + */ + public getSafeEpoch(groupId: string | Uint8Array): Task { + return task.tryOrElse( + errorReason => `Failed to get safe epoch for group ${groupId}: ${errorReason}`, + () => { + const groupIdBytes = typeof groupId === 'string' ? Decoder.fromBase64(groupId).asBytes : groupId; + return this.coreCryptoClient.conversationEpoch(new ConversationId(groupIdBytes)); + }, + ); + } + public async joinByExternalCommit(getGroupInfo: () => Promise) { try { this.logger.info('Trying to join MLS group via external commit'); @@ -536,7 +560,21 @@ export class MLSService extends TypedEventEmitter { this.logger.info('Message decrypted successfully', {qualifiedConversationId, duration: Date.now() - start}); return decryptedMessage; } catch (error: unknown) { - this.logger.warn('Failed to decrypt MLS message', {qualifiedConversationId, error}); + // This is safe (read-only) and helps correlate decryption failures with local epoch. + const coreCryptoEpochNumber = await task.tryOrElse( + errorReason => `Failed to collect epoch details for decryption failure: ${conversationId}: ${errorReason}`, + () => { + return this.coreCryptoClient.conversationEpoch(conversationId); + }, + ); + this.logger.warn('Failed to decrypt MLS message', { + qualifiedConversationId, + coreCryptoEpochError: coreCryptoEpochNumber.match({ + Ok: epoch => epoch, + Err: errorReason => errorReason, + }), + error, + }); // According to CoreCrypto JS doc on .decryptMessage method, we should ignore some errors (corecrypto handle them internally) if (shouldMLSDecryptionErrorBeIgnored(error)) { return { @@ -1010,6 +1048,7 @@ export class MLSService extends TypedEventEmitter { await this.schedulePendingProposalsTask(groupId, firingDate); } else { + this.logger.info('Trying to commit pending proposals immediately', {groupId}); await this.commitPendingProposals(groupId); } } @@ -1018,7 +1057,10 @@ export class MLSService extends TypedEventEmitter { await this.coreDatabase.put('pendingProposals', {groupId, firingDate}, groupId); TaskScheduler.addTask({ - task: () => this.commitPendingProposals(groupId), + task: () => { + this.logger.info('Trying to commit pending proposals from scheduled task', {groupId}); + return this.commitPendingProposals(groupId); + }, firingDate, key: this.createPendingProposalsTaskKey(groupId), }); @@ -1098,7 +1140,12 @@ export class MLSService extends TypedEventEmitter { } TaskScheduler.addTask({ - task: () => this.commitPendingProposals(groupId), + task: () => { + this.logger.info('Trying to commit pending proposals from startup rehydration', { + groupId, + }); + return this.commitPendingProposals(groupId); + }, firingDate, key: this.createPendingProposalsTaskKey(groupId), });