diff --git a/lib/components/debug-logs-context.js b/lib/components/debug-logs-context.js --- a/lib/components/debug-logs-context.js +++ b/lib/components/debug-logs-context.js @@ -3,6 +3,9 @@ import invariant from 'invariant'; import * as React from 'react'; +import type { OlmEncryptedMessageTypes } from '../types/crypto-types.js'; +import { type OutboundP2PMessageStatuses } from '../types/sqlite-types.js'; + export type DebugLog = { +title: string, +message: string, @@ -28,4 +31,85 @@ return debugLogsContext; } -export { DebugLogsContext, useDebugLogs }; +// The other party included in the operation +type Peer = { + +userID: string, + +deviceID: string, +}; + +// Only the part that is helpful for debugging +type LogEncryptedData = { + +messageType: OlmEncryptedMessageTypes, + +sessionVersion?: number, +}; + +export type OlmDebugLog = + | { + +operation: 'decryptAndPersist', + +messageID: string, + +peer: Peer, + +encryptedData: LogEncryptedData, + +decryptedData: { + +type: string, + +dmOpData?: { + +type?: string, + +messageID?: string, + +targetMessageID?: string, + +sourceMessageID?: string, + }, + }, + +success: boolean, + +resultDescription: string, + } + | { + +operation: 'encryptAndPersist', + +messageID: string, + +peer: Peer, + +status: OutboundP2PMessageStatuses, + +supportsAutoRetry: boolean, + +success: boolean, + +resultDescription: string, + } + | { + +operation: 'ephemeralEncrypt', + +messageID: string, + +peer: Peer, + +success: boolean, + +resultDescription: string, + } + | { + +operation: 'sendingAlreadyEncryptedMessage', + +messageID: string, + +peer: Peer, + +status: OutboundP2PMessageStatuses, + +supportsAutoRetry: boolean, + } + | { + +operation: 'contentInboundSessionCreator', + +peer: Peer, + +encryptedData: LogEncryptedData, + +success: boolean, + +resultDescription: string, + } + | { + +operation: 'contentOutboundSessionCreator', + +peer: Peer, + +sessionVersion: number, + +success: boolean, + +resultDescription: string, + } + | { + +operation: 'uploadOneTimeKeys', + +success: boolean, + +resultDescription: string, + }; + +function useOlmDebugLogs(): (olmLog: OlmDebugLog) => mixed { + const { addLog } = useDebugLogs(); + return React.useCallback( + (olmLog: OlmDebugLog) => addLog('Olm LOG', JSON.stringify(olmLog)), + [addLog], + ); +} + +export { DebugLogsContext, useDebugLogs, useOlmDebugLogs }; diff --git a/lib/components/peer-olm-session-creator-provider.react.js b/lib/components/peer-olm-session-creator-provider.react.js --- a/lib/components/peer-olm-session-creator-provider.react.js +++ b/lib/components/peer-olm-session-creator-provider.react.js @@ -3,6 +3,7 @@ import invariant from 'invariant'; import * as React from 'react'; +import { useOlmDebugLogs } from './debug-logs-context.js'; import { IdentityClientContext } from '../shared/identity-client-context.js'; import { useTunnelbroker } from '../tunnelbroker/tunnelbroker-context.js'; import { @@ -10,11 +11,14 @@ type DeviceSessionCreationRequest, } from '../utils/crypto-utils.js'; +export type CreateOlmSessionsWithUser = ( + userID: string, + devices: $ReadOnlyArray, + source: 'session_reset' | 'session_not_exists', +) => Promise; + export type PeerOlmSessionCreatorContextType = { - +createOlmSessionsWithUser: ( - userID: string, - devices: $ReadOnlyArray, - ) => Promise, + +createOlmSessionsWithUser: CreateOlmSessionsWithUser, }; const PeerOlmSessionCreatorContext: React.Context = @@ -34,10 +38,13 @@ [userID: string]: { [deviceID: string]: ?Promise }, }>({}); + const olmDebugLog = useOlmDebugLogs(); + const createOlmSessionsWithUserCallback = React.useCallback( async ( userID: string, devices: $ReadOnlyArray, + source: 'session_reset' | 'session_not_exists', ) => { if (!runningPromises.current[userID]) { runningPromises.current[userID] = {}; @@ -55,6 +62,8 @@ sendMessageToDevice, userID, filteredDevices, + source, + olmDebugLog, ); for (const request of filteredDevices) { @@ -75,7 +84,7 @@ await Promise.all(promises); }, - [identityClient, sendMessageToDevice, getAuthMetadata], + [getAuthMetadata, identityClient, olmDebugLog, sendMessageToDevice], ); const peerOlmSessionCreatorContextValue: PeerOlmSessionCreatorContextType = diff --git a/lib/push/send-utils.js b/lib/push/send-utils.js --- a/lib/push/send-utils.js +++ b/lib/push/send-utils.js @@ -23,6 +23,7 @@ } from './utils.js'; import { createWebNotification } from './web-notif-creators.js'; import { createWNSNotification } from './wns-notif-creators.js'; +import { type CreateOlmSessionsWithUser } from '../components/peer-olm-session-creator-provider.react.js'; import { hasPermission } from '../permissions/minimally-encoded-thread-permissions.js'; import { sortMessageInfoList } from '../shared/id-utils.js'; import { @@ -62,7 +63,6 @@ import type { ThickRawThreadInfos } from '../types/thread-types.js'; import type { UserInfos } from '../types/user-types.js'; import { getConfig } from '../utils/config.js'; -import type { DeviceSessionCreationRequest } from '../utils/crypto-utils.js'; import { type GetENSNames } from '../utils/ens-helpers.js'; import { type GetFCNames } from '../utils/farcaster-helpers.js'; import { values } from '../utils/objects.js'; @@ -1097,10 +1097,7 @@ userDevices: { +[userID: string]: $ReadOnlyArray, }, - olmSessionCreator: ( - userID: string, - devices: $ReadOnlyArray, - ) => Promise, + olmSessionCreator: CreateOlmSessionsWithUser, ): Promise { const { initializeCryptoAccount, @@ -1121,7 +1118,9 @@ deviceID, })); - olmSessionCreationPromises.push(olmSessionCreator(userID, devices)); + olmSessionCreationPromises.push( + olmSessionCreator(userID, devices, 'session_not_exists'), + ); } try { @@ -1187,10 +1186,7 @@ type PreparePushNotifsInputData = { +encryptedNotifUtilsAPI: EncryptedNotifUtilsAPI, +senderDeviceDescriptor: SenderDeviceDescriptor, - +olmSessionCreator: ( - userID: string, - devices: $ReadOnlyArray, - ) => Promise, + +olmSessionCreator: CreateOlmSessionsWithUser, +getLatestMessageEdit: (messageID: string) => Promise, +auxUserInfos: AuxUserInfos, +notifCreationData: ?{ @@ -1258,10 +1254,7 @@ type PrepareOwnDevicesPushNotifsInputData = { +encryptedNotifUtilsAPI: EncryptedNotifUtilsAPI, +senderInfo: SenderInfo, - +olmSessionCreator: ( - userID: string, - devices: $ReadOnlyArray, - ) => Promise, + +olmSessionCreator: CreateOlmSessionsWithUser, +auxUserInfos: AuxUserInfos, +rescindData?: { +threadID: string }, +badgeUpdateData?: { +threadID: string }, diff --git a/lib/tunnelbroker/peer-to-peer-context.js b/lib/tunnelbroker/peer-to-peer-context.js --- a/lib/tunnelbroker/peer-to-peer-context.js +++ b/lib/tunnelbroker/peer-to-peer-context.js @@ -8,8 +8,15 @@ type TunnelbrokerClientMessageToDevice, useTunnelbroker, } from './tunnelbroker-context.js'; -import { useDebugLogs } from '../components/debug-logs-context.js'; -import { usePeerOlmSessionsCreatorContext } from '../components/peer-olm-session-creator-provider.react.js'; +import { + type OlmDebugLog, + useDebugLogs, + useOlmDebugLogs, +} from '../components/debug-logs-context.js'; +import { + type CreateOlmSessionsWithUser, + usePeerOlmSessionsCreatorContext, +} from '../components/peer-olm-session-creator-provider.react.js'; import { useActionsQueue } from '../hooks/actions-queue.js'; import { useSendPushNotifs } from '../push/send-hooks.react.js'; import { getAllPeerDevices } from '../selectors/user-selectors.js'; @@ -21,7 +28,6 @@ import type { NotificationsCreationData } from '../types/notif-types.js'; import { type OutboundP2PMessage } from '../types/sqlite-types.js'; import { getConfig } from '../utils/config.js'; -import type { DeviceSessionCreationRequest } from '../utils/crypto-utils.js'; import { getMessageForException } from '../utils/errors.js'; import { entries } from '../utils/objects.js'; import { @@ -66,10 +72,7 @@ async function createMissingSession( userDevicesWithoutSession: { [userID: string]: Array }, - peerOlmSessionsCreator: ( - userID: string, - devices: $ReadOnlyArray, - ) => Promise, + peerOlmSessionsCreator: CreateOlmSessionsWithUser, addLog: (title: string, message: string) => mixed, ): Promise { const creatingSessionPromises = entries(userDevicesWithoutSession).map( @@ -78,6 +81,7 @@ await peerOlmSessionsCreator( userID, devices.map(deviceID => ({ deviceID })), + 'session_not_exists', ); } catch (e) { // Session creation may fail for some devices, @@ -118,13 +122,11 @@ messageID: ?string, ) => Promise, identityContext: IdentityClientContextType, - peerOlmSessionsCreator: ( - userID: string, - devices: $ReadOnlyArray, - ) => Promise, + peerOlmSessionsCreator: CreateOlmSessionsWithUser, messageIDs: ?$ReadOnlyArray, allPeerDevices: $ReadOnlySet, addLog: (title: string, message: string) => mixed, + olmDebugLog: (olmLog: OlmDebugLog) => mixed, ): Promise { let authMetadata; try { @@ -196,7 +198,12 @@ ); } else { messagesPromises.push( - handleOutboundP2PMessage(message, authMetadata, sendMessage), + handleOutboundP2PMessage( + message, + authMetadata, + sendMessage, + olmDebugLog, + ), ); } } @@ -236,7 +243,7 @@ // 5. Retry messages for which the session was missing. const retryPromises = messagesToRetry.map(message => - handleOutboundP2PMessage(message, authMetadata, sendMessage), + handleOutboundP2PMessage(message, authMetadata, sendMessage, olmDebugLog), ); const retryResults: Array = await Promise.all(retryPromises); @@ -262,6 +269,7 @@ const { children } = props; const { addLog } = useDebugLogs(); + const olmDebugLog = useOlmDebugLogs(); const { sendMessageToDevice } = useTunnelbroker(); const identityContext = React.useContext(IdentityClientContext); invariant(identityContext, 'Identity context should be set'); @@ -311,6 +319,7 @@ message.outboundMessageIDs, message.allPeerDevices, addLog, + olmDebugLog, ), sendPushNotifs(message.notificationsCreationData), ]); @@ -335,6 +344,7 @@ [ addLog, identityContext, + olmDebugLog, peerOlmSessionsCreator, sendMessageToDevice, sendPushNotifs, @@ -381,6 +391,7 @@ recipient, authMetadata, sendMessageToDevice, + olmDebugLog, ), ); const messagesResults = await Promise.all(recipientPromises); @@ -419,11 +430,12 @@ recipient, authMetadata, sendMessageToDevice, + olmDebugLog, ), ); await Promise.all(retryPromises); }, - [addLog, peerOlmSessionsCreator, sendMessageToDevice], + [addLog, olmDebugLog, peerOlmSessionsCreator, sendMessageToDevice], ); React.useEffect(() => { diff --git a/lib/tunnelbroker/use-peer-to-peer-message-handler.js b/lib/tunnelbroker/use-peer-to-peer-message-handler.js --- a/lib/tunnelbroker/use-peer-to-peer-message-handler.js +++ b/lib/tunnelbroker/use-peer-to-peer-message-handler.js @@ -9,7 +9,10 @@ import { removePeerUsersActionType } from '../actions/aux-user-actions.js'; import { invalidateTunnelbrokerDeviceTokenActionType } from '../actions/tunnelbroker-actions.js'; import { logOutActionTypes, useBaseLogOut } from '../actions/user-actions.js'; -import { useDebugLogs } from '../components/debug-logs-context.js'; +import { + useDebugLogs, + useOlmDebugLogs, +} from '../components/debug-logs-context.js'; import { usePeerOlmSessionsCreatorContext } from '../components/peer-olm-session-creator-provider.react.js'; import { useBroadcastDeviceListUpdates, @@ -200,6 +203,7 @@ const { createOlmSessionsWithUser } = usePeerOlmSessionsCreatorContext(); const { addLog } = useDebugLogs(); + const olmDebugLog = useOlmDebugLogs(); return React.useCallback( async (message: PeerToPeerMessage, messageID: string) => { @@ -225,6 +229,8 @@ return; } + let resultDescription = 'starting', + success = false; try { await olmAPI.initializeCryptoAccount(); const result = await olmAPI.contentInboundSessionCreator( @@ -233,50 +239,75 @@ sessionVersion, false, ); + success = true; + + resultDescription = 'resending messages to peers'; await resendPeerToPeerMessages(senderDeviceID); - console.log( + + resultDescription = 'Created inbound session with device ' + - `${senderDeviceID}: ${result}, ` + - `session version: ${sessionVersion}`, - ); + `${senderDeviceID}: ${result}, ` + + `session version: ${sessionVersion}`; } catch (e) { const errorMessage = getMessageForException(e) ?? ''; if (errorMessage.includes(olmSessionErrors.alreadyCreated)) { - console.log( + resultDescription = 'Received session request with lower session version from ' + - `${senderDeviceID}, session version: ${sessionVersion}`, - ); + `${senderDeviceID}, session version: ${sessionVersion}`; } else if (errorMessage.includes(olmSessionErrors.raceCondition)) { const currentDeviceID = await getContentSigningKey(); if (hasHigherDeviceID(currentDeviceID, senderDeviceID)) { - console.log( + resultDescription = 'Race condition while creating session with ' + - `${senderDeviceID}, session version: ${sessionVersion}, ` + - `this device has a higher deviceID and the session will be kept`, - ); + `${senderDeviceID}, session version: ${sessionVersion}, ` + + `this device has a higher deviceID and the session will be kept`; } else { + resultDescription = + 'Race condition while creating session with ' + + `${senderDeviceID}, session version: ${sessionVersion}, ` + + `this device has a lower deviceID and the session will overwritten`; + const result = await olmAPI.contentInboundSessionCreator( deviceKeys.identityKeysBlob.primaryIdentityPublicKeys, encryptedData, sessionVersion, true, ); - console.log( + + resultDescription = 'Overwrite session with device ' + - `${senderDeviceID}: ${result}, ` + - `session version: ${sessionVersion}`, - ); + `${senderDeviceID}: ${result}, ` + + `session version: ${sessionVersion}, starting resending messages`; + await resendPeerToPeerMessages(senderDeviceID); + + resultDescription = + 'Overwrite session with device ' + + `${senderDeviceID}: ${result}, ` + + `session version: ${sessionVersion}, finished resending messages`; } } else { - addLog( - 'Error creating inbound session with device ', + resultDescription = + 'Error creating inbound session with device ' + `${senderDeviceID}: ${errorMessage}, ` + - `session version: ${sessionVersion}`, - ); + `session version: ${sessionVersion}`; } + } finally { + olmDebugLog({ + operation: 'contentInboundSessionCreator', + peer: message.senderInfo, + encryptedData: { + messageType: message.encryptedData.messageType, + sessionVersion: message.sessionVersion, + }, + success, + resultDescription, + }); } } else if (message.type === peerToPeerMessageTypes.ENCRYPTED_MESSAGE) { + let resultDescription = 'starting', + success = false, + decryptedData = { type: 'unknown' }; try { await olmAPI.initializeCryptoAccount(); const decrypted = await olmAPI.decryptAndPersist( @@ -285,10 +316,34 @@ message.senderInfo.userID, messageID, ); - console.log( - 'Decrypted message from device ' + - `${message.senderInfo.deviceID}: ${decrypted}`, - ); + resultDescription = `Decrypted message from device ${message.senderInfo.deviceID}`; + success = true; + + try { + const parsedMessageToDevice = JSON.parse(decrypted); + if ( + parsedMessageToDevice?.type === + userActionsP2PMessageTypes.DM_OPERATION + ) { + decryptedData = { + type: parsedMessageToDevice?.type, + dmOpData: { + type: parsedMessageToDevice?.op?.type, + messageID: parsedMessageToDevice?.op?.messageID, + targetMessageID: parsedMessageToDevice?.op?.targetMessageID, + sourceMessageID: parsedMessageToDevice?.op?.sourceMessageID, + }, + }; + } else { + decryptedData = { + type: parsedMessageToDevice?.type, + }; + } + } catch (e) { + decryptedData = { + type: 'error_parsing', + }; + } try { await handleOlmMessageToDevice( @@ -297,15 +352,17 @@ messageID, ); } catch (e) { - console.log('Failed processing Olm P2P message:', e); + resultDescription = + `Failed processing Olm P2P message ${messageID}:` + + `${getMessageForException(e) ?? 'unknown error'}`; + console.log(resultDescription); } } catch (e) { const errorMessage = getMessageForException(e) ?? ''; if (errorMessage.includes(olmSessionErrors.invalidSessionVersion)) { - console.log( + resultDescription = 'Received message decrypted with different session from ' + - `${message.senderInfo.deviceID}.`, - ); + `${message.senderInfo.deviceID}.`; return; } @@ -314,11 +371,10 @@ messageID, ]); if (sqliteMessages.length > 0) { - console.log( + resultDescription = 'Message skipped because it was already decrypted ' + - `messageID: ${messageID} ` + - `sender: ${message.senderInfo.deviceID}.`, - ); + `messageID: ${messageID} ` + + `sender: ${message.senderInfo.deviceID}.`; return; } } @@ -328,6 +384,10 @@ `${message.senderInfo.deviceID}: ${errorMessage}`, ); + resultDescription = + 'Error decrypting message from device' + + `${message.senderInfo.deviceID}: ${errorMessage}`; + if ( !errorMessage.includes(OLM_ERROR_FLAG) && !errorMessage.includes(olmSessionErrors.sessionDoesNotExist) @@ -335,23 +395,56 @@ throw e; } - await createOlmSessionsWithUser(message.senderInfo.userID, [ - { - deviceID: message.senderInfo.deviceID, - sessionCreationOptions: { overwriteContentSession: true }, - }, - ]); + const source: 'session_reset' | 'session_not_exists' = + errorMessage.includes(olmSessionErrors.sessionDoesNotExist) + ? 'session_not_exists' + : 'session_reset'; + + await createOlmSessionsWithUser( + message.senderInfo.userID, + [ + { + deviceID: message.senderInfo.deviceID, + sessionCreationOptions: { overwriteContentSession: true }, + }, + ], + source, + ); await resendPeerToPeerMessages(message.senderInfo.deviceID); + } finally { + olmDebugLog({ + operation: 'decryptAndPersist', + messageID: messageID, + peer: message.senderInfo, + encryptedData: { + messageType: message.encryptedData.messageType, + sessionVersion: message.encryptedData.sessionVersion, + }, + decryptedData, + success, + resultDescription, + }); } } else if (message.type === peerToPeerMessageTypes.REFRESH_KEY_REQUEST) { + let resultDescription = 'starting', + success = false; try { await olmAPI.initializeCryptoAccount(); + resultDescription = 'getting OTKs'; const oneTimeKeys = await olmAPI.getOneTimeKeys(message.numberOfKeys); + resultDescription = 'uploading OTKs'; await identityClient.uploadOneTimeKeys(oneTimeKeys); + success = true; } catch (e) { - console.log( - `Error uploading one-time keys: ${getMessageForException(e) ?? ''}`, - ); + resultDescription = `Error uploading one-time keys: ${ + getMessageForException(e) ?? '' + }`; + } finally { + olmDebugLog({ + operation: 'uploadOneTimeKeys', + success, + resultDescription, + }); } } else if (message.type === peerToPeerMessageTypes.DEVICE_LIST_UPDATED) { try { @@ -444,6 +537,7 @@ handleOlmMessageToDevice, identityClient, olmAPI, + olmDebugLog, resendPeerToPeerMessages, sqliteAPI, ], diff --git a/lib/utils/crypto-utils.js b/lib/utils/crypto-utils.js --- a/lib/utils/crypto-utils.js +++ b/lib/utils/crypto-utils.js @@ -7,6 +7,7 @@ import { getMessageForException } from './errors.js'; import { primaryIdentityPublicKeyRegex } from './siwe-utils.js'; import { tRegex, tShape } from './validation-utils.js'; +import type { OlmDebugLog } from '../components/debug-logs-context.js'; import type { AuthMetadata } from '../shared/identity-client-context.js'; import type { TunnelbrokerClientMessageToDevice } from '../tunnelbroker/tunnelbroker-context.js'; import type { @@ -122,6 +123,8 @@ sendMessage: (message: TunnelbrokerClientMessageToDevice) => Promise, userID: string, devices: $ReadOnlyArray, + source: 'session_reset' | 'session_not_exists', + olmDebugLog: (olmLog: OlmDebugLog) => mixed, ): Promise { const { olmAPI } = getConfig(); await olmAPI.initializeCryptoAccount(); @@ -177,6 +180,9 @@ const keysResponse = await identityClient.getOutboundKeysForUser(userID); const devicePromises = filteredDevices.map(async sessionRequest => { + let resultDescription = 'starting', + success = false, + sessionVersionResult = -1; try { const { deviceID, hasContentSession, hasNotifsSession } = sessionRequest; const deviceKeysResponse = keysResponse.find( @@ -184,7 +190,7 @@ ); if (!deviceKeysResponse || !deviceKeysResponse.keys) { - console.log(`Keys missing for device ${deviceID}`); + resultDescription = `Keys missing for device ${deviceID}`; return; } const { keys } = deviceKeysResponse; @@ -194,22 +200,26 @@ const recipientDeviceID = primaryIdentityPublicKeys.ed25519; if (hasContentSession) { + resultDescription = 'creating only notif session'; await olmAPI.notificationsOutboundSessionCreator( recipientDeviceID, notificationIdentityPublicKeys, keys.notifInitializationInfo, ); + success = true; return; } let outboundSessionCreationResult: OutboundSessionCreationResult; if (hasNotifsSession) { + resultDescription = 'creating only content session'; outboundSessionCreationResult = await olmAPI.contentOutboundSessionCreator( primaryIdentityPublicKeys, keys.contentInitializationInfo, ); } else { + resultDescription = 'creating content and notif session'; [outboundSessionCreationResult] = await Promise.all([ await olmAPI.contentOutboundSessionCreator( primaryIdentityPublicKeys, @@ -224,6 +234,8 @@ } const { sessionVersion, encryptedData } = outboundSessionCreationResult; + success = true; + sessionVersionResult = sessionVersion; const sessionCreationMessage: OutboundSessionCreation = { type: peerToPeerMessageTypes.OUTBOUND_SESSION_CREATION, @@ -239,16 +251,22 @@ deviceID: recipientDeviceID, payload: JSON.stringify(sessionCreationMessage), }); - console.log( - `Request to create a session with device ${recipientDeviceID} sent.`, - ); + resultDescription = `Request to create a session with device ${recipientDeviceID} sent`; } catch (e) { - console.error( - `Error creating session with ${sessionRequest.deviceID}: ${ - getMessageForException(e) ?? 'unknown error' - }`, - e, - ); + resultDescription = `Error creating session with ${ + sessionRequest.deviceID + }: ${getMessageForException(e) ?? 'unknown error'}`; + } finally { + olmDebugLog({ + operation: 'contentOutboundSessionCreator', + peer: { + userID, + deviceID: sessionRequest.deviceID, + }, + sessionVersion: sessionVersionResult, + success, + resultDescription, + }); } }); await Promise.all(devicePromises); diff --git a/lib/utils/peer-to-peer-communication-utils.js b/lib/utils/peer-to-peer-communication-utils.js --- a/lib/utils/peer-to-peer-communication-utils.js +++ b/lib/utils/peer-to-peer-communication-utils.js @@ -1,8 +1,11 @@ // @flow +import uuid from 'uuid'; + import { getConfig } from './config.js'; import { getMessageForException } from './errors.js'; import { olmSessionErrors } from './olm-utils.js'; +import { type OlmDebugLog } from '../components/debug-logs-context.js'; import { type AuthMetadata } from '../shared/identity-client-context.js'; import { type P2PMessageRecipient } from '../tunnelbroker/peer-to-peer-context.js'; import type { TunnelbrokerClientMessageToDevice } from '../tunnelbroker/tunnelbroker-context.js'; @@ -73,15 +76,19 @@ message: TunnelbrokerClientMessageToDevice, messageID: ?string, ) => Promise, + olmDebugLog: (olmLog: OlmDebugLog) => mixed, ): Promise<'success' | 'failure' | 'missing_session'> { const { olmAPI } = getConfig(); - + let resultDescription = 'starting', + success = false; try { const result = await olmAPI.encryptAndPersist( message.plaintext, message.deviceID, message.messageID, ); + success = true; + resultDescription = 'message encrypted'; const encryptedMessage: OutboundP2PMessage = { ...message, @@ -92,10 +99,26 @@ if ( getMessageForException(e)?.includes(olmSessionErrors.sessionDoesNotExist) ) { + resultDescription = 'session is missing'; return 'missing_session'; } - console.log(`Error sending messages to peer ${message.deviceID}`, e); + resultDescription = `Error sending messages to peer ${message.deviceID}: ${ + getMessageForException(e) ?? 'unknown' + }`; return 'failure'; + } finally { + olmDebugLog({ + operation: 'encryptAndPersist', + messageID: message.messageID, + peer: { + userID: message.userID, + deviceID: message.deviceID, + }, + status: message.status, + supportsAutoRetry: message.supportsAutoRetry, + success, + resultDescription, + }); } } @@ -110,12 +133,14 @@ message: TunnelbrokerClientMessageToDevice, messageID: ?string, ) => Promise, + olmDebugLog: (olmLog: OlmDebugLog) => mixed, ): Promise { if (message.status === outboundP2PMessageStatuses.persisted) { const status = await encryptAndSendMessageToPeer( message, authMetadata, sendMessage, + olmDebugLog, ); return { status, @@ -123,6 +148,16 @@ }; } else if (message.status === outboundP2PMessageStatuses.encrypted) { const status = await sendMessageToPeer(message, authMetadata, sendMessage); + olmDebugLog({ + operation: 'sendingAlreadyEncryptedMessage', + messageID: message.messageID, + peer: { + userID: message.userID, + deviceID: message.deviceID, + }, + status: message.status, + supportsAutoRetry: message.supportsAutoRetry, + }); return { status, messageID: message.messageID, @@ -153,6 +188,7 @@ message: TunnelbrokerClientMessageToDevice, messageID: ?string, ) => Promise, + olmDebugLog: (olmLog: OlmDebugLog) => mixed, ): Promise { const { olmAPI } = getConfig(); @@ -164,30 +200,53 @@ userID: authMetadata.userID, }; + const clientMessageID = uuid.v4(); + + let resultDescription = 'starting', + success = false; + try { const encryptedData = await olmAPI.encrypt( contentPayload, recipient.deviceID, ); + success = true; + resultDescription = 'message encrypted'; + const encryptedMessage: EncryptedMessage = { type: peerToPeerMessageTypes.ENCRYPTED_MESSAGE, senderInfo, encryptedData, }; - await sendMessage({ - deviceID: recipient.deviceID, - payload: JSON.stringify(encryptedMessage), - }); + + await sendMessage( + { + deviceID: recipient.deviceID, + payload: JSON.stringify(encryptedMessage), + }, + clientMessageID, + ); return { status: 'success', recipient }; } catch (e) { if ( getMessageForException(e)?.includes(olmSessionErrors.sessionDoesNotExist) ) { + resultDescription = 'session is missing'; return { status: 'missing_session', recipient }; } - console.log(`Error sending messages to peer ${recipient.deviceID}`, e); + resultDescription = `Error sending messages to peer ${ + recipient.deviceID + }: ${getMessageForException(e) ?? 'unknown'}`; return { status: 'failure', recipient }; + } finally { + olmDebugLog({ + operation: 'ephemeralEncrypt', + messageID: clientMessageID, + peer: recipient, + success, + resultDescription, + }); } }