diff --git a/ts/background.ts b/ts/background.ts index 9697e0ae77..91a5c99cae 100644 --- a/ts/background.ts +++ b/ts/background.ts @@ -424,13 +424,18 @@ export async function startApp(): Promise { const { conversationId, senderUuid } = item; const conversation = window.ConversationController.get(conversationId); if (conversation) { - const now = Date.now(); + const receivedAt = Date.now(); + const receivedAtCounter = window.Signal.Util.incrementMessageCounter(); conversation.queueJob(() => - conversation.addDeliveryIssue(now, senderUuid) + conversation.addDeliveryIssue({ + receivedAt, + receivedAtCounter, + senderUuid, + }) ); } }); - }, 5 * 60 * 1000); + }, FIVE_MINUTES); // These make key operations available to IPC handlers created in preload.js window.Events = { @@ -2117,7 +2122,7 @@ export async function startApp(): Promise { await server.registerCapabilities({ 'gv2-3': true, 'gv1-migration': true, - senderKey: true, + senderKey: false, }); } catch (error) { window.log.error( @@ -3382,13 +3387,9 @@ export async function startApp(): Promise { sentAt, senderDevice, } = retryRequest; + const logId = `${requesterUuid}.${requesterDevice} ${sentAt}-${senderDevice}`; - window.log.info('onRetryRequest:', { - requesterUuid, - requesterDevice, - sentAt, - senderDevice, - }); + window.log.info(`onRetryRequest/${logId}: Starting...`); const requesterConversation = window.ConversationController.getOrCreate( requesterUuid, @@ -3416,15 +3417,13 @@ export async function startApp(): Promise { }); if (!targetMessage) { - window.log.info( - `onRetryRequest: Did not find message sent at ${sentAt}, sent to ${requesterUuid}` - ); + window.log.info(`onRetryRequest/${logId}: Did not find message`); return; } if (targetMessage.isErased()) { window.log.info( - `onRetryRequest: Message sent at ${sentAt} is erased, refusing to send again.` + `onRetryRequest/${logId}: Message is erased, refusing to send again.` ); return; } @@ -3433,7 +3432,7 @@ export async function startApp(): Promise { const ONE_DAY = 24 * HOUR; if (isOlderThan(sentAt, ONE_DAY)) { window.log.info( - `onRetryRequest: Message sent at ${sentAt} is too old, refusing to send again.` + `onRetryRequest/${logId}: Message is too old, refusing to send again.` ); return; } @@ -3448,15 +3447,11 @@ export async function startApp(): Promise { ); if (sentUnidentified && wasDelivered) { window.log.info( - `onRetryRequest: Message sent at ${sentAt} was sent sealed sender and was delivered, refusing to send again.` + `onRetryRequest/${logId}: Message was sent sealed sender and was delivered, refusing to send again.` ); return; } - window.log.info( - `onRetryRequest: Resending message ${sentAt} to user ${requesterUuid}` - ); - const ourDeviceId = parseIntOrThrow( window.textsecure.storage.user.getDeviceId(), 'onRetryRequest/getDeviceId' @@ -3464,11 +3459,12 @@ export async function startApp(): Promise { if (ourDeviceId === senderDevice) { const address = `${requesterUuid}.${requesterDevice}`; window.log.info( - `onRetryRequest: Devices match, archiving session with ${address}` + `onRetryRequest/${logId}: Devices match, archiving session` ); await window.textsecure.storage.protocol.archiveSession(address); } + window.log.info(`onRetryRequest/${logId}: Resending message`); targetMessage.resend(requesterUuid); } @@ -3478,9 +3474,10 @@ export async function startApp(): Promise { async function onDecryptionError(event: DecryptionErrorEventType) { const { decryptionError } = event; - const { senderUuid, senderDevice } = decryptionError; + const { senderUuid, senderDevice, timestamp } = decryptionError; + const logId = `${senderUuid}.${senderDevice} ${timestamp}`; - window.log.info(`onDecryptionError: ${senderUuid}.${senderDevice}`); + window.log.info(`onDecryptionError/${logId}: Starting...`); const conversation = window.ConversationController.getOrCreate( senderUuid, @@ -3492,11 +3489,12 @@ export async function startApp(): Promise { } if (conversation.get('capabilities')?.senderKey) { - requestResend(decryptionError); - return; + await requestResend(decryptionError); + } else { + await startAutomaticSessionReset(decryptionError); } - await startAutomaticSessionReset(decryptionError); + window.log.info(`onDecryptionError/${logId}: ...complete`); } async function requestResend(decryptionError: DecryptionErrorType) { @@ -3511,13 +3509,13 @@ export async function startApp(): Promise { senderUuid, timestamp, } = decryptionError; + const logId = `${senderUuid}.${senderDevice} ${timestamp}`; - window.log.info(`requestResend: ${senderUuid}.${senderDevice}`, { + window.log.info(`requestResend/${logId}: Starting...`, { cipherTextBytesLength: cipherTextBytes?.byteLength, cipherTextType, contentHint, groupId: groupId ? `groupv2(${groupId})` : undefined, - timestamp, }); // 1. Find the target conversation @@ -3532,9 +3530,12 @@ export async function startApp(): Promise { const conversation = group || sender; function immediatelyAddError() { - const receivedAt = Date.now(); conversation.queueJob(async () => { - conversation.addDeliveryIssue(receivedAt, senderUuid); + conversation.addDeliveryIssue({ + receivedAt: receivedAtDate, + receivedAtCounter, + senderUuid, + }); }); } @@ -3542,7 +3543,7 @@ export async function startApp(): Promise { if (!cipherTextBytes || !isNumber(cipherTextType)) { window.log.warn( - 'requestResend: Missing cipherText information, failing over to automatic reset' + `requestResend/${logId}: Missing cipherText information, failing over to automatic reset` ); startAutomaticSessionReset(decryptionError); return; @@ -3568,7 +3569,7 @@ export async function startApp(): Promise { } } catch (error) { window.log.error( - 'requestResend: Failed to send retry request, failing over to automatic reset', + `requestResend/${logId}: Failed to send retry request, failing over to automatic reset`, error && error.stack ? error.stack : error ); startAutomaticSessionReset(decryptionError); @@ -3581,7 +3582,8 @@ export async function startApp(): Promise { // 3. Determine how to represent this to the user. Three different options. - // This is a sync message of some kind that cannot be resent. Don't do anything. + // This is a sync message of some kind that cannot be resent. Reset session but don't + // show any UI for it. if (contentHint === ContentHint.SUPPLEMENTARY) { scheduleSessionReset(senderUuid, senderDevice); return; @@ -3592,7 +3594,7 @@ export async function startApp(): Promise { const { retryPlaceholders } = window.Signal.Services; assert(retryPlaceholders, 'requestResend: adding placeholder'); - window.log.warn('requestResend: Adding placeholder'); + window.log.info(`requestResend/${logId}: Adding placeholder`); await retryPlaceholders.add({ conversationId: conversation.get('id'), receivedAt: receivedAtDate, @@ -3604,6 +3606,9 @@ export async function startApp(): Promise { return; } + window.log.warn( + `requestResend/${logId}: No content hint, adding error immediately` + ); immediatelyAddError(); } @@ -3618,7 +3623,10 @@ export async function startApp(): Promise { } function startAutomaticSessionReset(decryptionError: DecryptionErrorType) { - const { senderUuid, senderDevice } = decryptionError; + const { senderUuid, senderDevice, timestamp } = decryptionError; + const logId = `${senderUuid}.${senderDevice} ${timestamp}`; + + window.log.info(`startAutomaticSessionReset/${logId}: Starting...`); scheduleSessionReset(senderUuid, senderDevice); @@ -3642,8 +3650,9 @@ export async function startApp(): Promise { } const receivedAt = Date.now(); + const receivedAtCounter = window.Signal.Util.incrementMessageCounter(); conversation.queueJob(async () => { - conversation.addChatSessionRefreshed(receivedAt); + conversation.addChatSessionRefreshed({ receivedAt, receivedAtCounter }); }); } diff --git a/ts/logging/set_up_renderer_logging.ts b/ts/logging/set_up_renderer_logging.ts index 407651d4a6..d615465ed3 100644 --- a/ts/logging/set_up_renderer_logging.ts +++ b/ts/logging/set_up_renderer_logging.ts @@ -193,7 +193,7 @@ window.addEventListener('unhandledrejection', rejectionEvent => { }); initLogger( - SignalClientLogLevel.Trace, + SignalClientLogLevel.Warn, ( level: unknown, target: string, diff --git a/ts/models/conversations.ts b/ts/models/conversations.ts index 3fc9f59444..8f18bd984d 100644 --- a/ts/models/conversations.ts +++ b/ts/models/conversations.ts @@ -2450,7 +2450,13 @@ export class ConversationModel extends window.Backbone return this.setVerified(); } - async addChatSessionRefreshed(receivedAt: number): Promise { + async addChatSessionRefreshed({ + receivedAt, + receivedAtCounter, + }: { + receivedAt: number; + receivedAtCounter: number; + }): Promise { window.log.info( `addChatSessionRefreshed: adding for ${this.idForLogging()}`, { receivedAt } @@ -2460,7 +2466,7 @@ export class ConversationModel extends window.Backbone conversationId: this.id, type: 'chat-session-refreshed', sent_at: receivedAt, - received_at: window.Signal.Util.incrementMessageCounter(), + received_at: receivedAtCounter, received_at_ms: receivedAt, unread: 1, // TODO: DESKTOP-722 @@ -2481,10 +2487,15 @@ export class ConversationModel extends window.Backbone this.trigger('newmessage', model); } - async addDeliveryIssue( - receivedAt: number, - senderUuid: string - ): Promise { + async addDeliveryIssue({ + receivedAt, + receivedAtCounter, + senderUuid, + }: { + receivedAt: number; + receivedAtCounter: number; + senderUuid: string; + }): Promise { window.log.info(`addDeliveryIssue: adding for ${this.idForLogging()}`, { receivedAt, senderUuid, @@ -2495,7 +2506,7 @@ export class ConversationModel extends window.Backbone type: 'delivery-issue', sourceUuid: senderUuid, sent_at: receivedAt, - received_at: window.Signal.Util.incrementMessageCounter(), + received_at: receivedAtCounter, received_at_ms: receivedAt, unread: 1, // TODO: DESKTOP-722 diff --git a/ts/textsecure/MessageReceiver.ts b/ts/textsecure/MessageReceiver.ts index d0c50cc957..a18c38d2b8 100644 --- a/ts/textsecure/MessageReceiver.ts +++ b/ts/textsecure/MessageReceiver.ts @@ -1122,6 +1122,7 @@ class MessageReceiverInner extends EventTarget { envelope: EnvelopeClass, ciphertext: ByteBufferClass ): Promise { + const logId = this.getEnvelopeId(envelope); const { serverTrustRoot } = this; const envelopeTypeEnum = window.textsecure.protobuf.Envelope.Type; const unidentifiedSenderTypeEnum = @@ -1149,6 +1150,7 @@ class MessageReceiverInner extends EventTarget { >; if (envelope.type === envelopeTypeEnum.PLAINTEXT_CONTENT) { + window.log.info(`decrypt/${logId}: plaintext message`); const buffer = Buffer.from(ciphertext.toArrayBuffer()); const plaintextContent = PlaintextContent.deserialize(buffer); @@ -1156,7 +1158,7 @@ class MessageReceiverInner extends EventTarget { this.unpad(typedArrayToArrayBuffer(plaintextContent.body())) ); } else if (envelope.type === envelopeTypeEnum.CIPHERTEXT) { - window.log.info('message from', this.getEnvelopeId(envelope)); + window.log.info(`decrypt/${logId}: ciphertext message`); if (!identifier) { throw new Error( 'MessageReceiver.decrypt: No identifier for CIPHERTEXT message' @@ -1184,7 +1186,7 @@ class MessageReceiverInner extends EventTarget { zone ); } else if (envelope.type === envelopeTypeEnum.PREKEY_BUNDLE) { - window.log.info('prekey message from', this.getEnvelopeId(envelope)); + window.log.info(`decrypt/${logId}: prekey message`); if (!identifier) { throw new Error( 'MessageReceiver.decrypt: No identifier for PREKEY_BUNDLE message' @@ -1214,7 +1216,7 @@ class MessageReceiverInner extends EventTarget { zone ); } else if (envelope.type === envelopeTypeEnum.UNIDENTIFIED_SENDER) { - window.log.info('received unidentified sender message'); + window.log.info(`decrypt/${logId}: unidentified message`); const buffer = Buffer.from(ciphertext.toArrayBuffer()); const decryptSealedSender = async (): Promise< @@ -1241,6 +1243,7 @@ class MessageReceiverInner extends EventTarget { ['sourceUuid'], 'message_receiver::decrypt::UNIDENTIFIED_SENDER' ); + // eslint-disable-next-line no-param-reassign envelope.sourceDevice = certificate.senderDeviceId(); // eslint-disable-next-line no-param-reassign @@ -1248,6 +1251,8 @@ class MessageReceiverInner extends EventTarget { originalSource || originalSourceUuid ); + const unidentifiedLogId = this.getEnvelopeId(envelope); + // eslint-disable-next-line no-param-reassign envelope.contentHint = messageContent.contentHint(); // eslint-disable-next-line no-param-reassign @@ -1275,6 +1280,9 @@ class MessageReceiverInner extends EventTarget { messageContent.msgType() === unidentifiedSenderTypeEnum.PLAINTEXT_CONTENT ) { + window.log.info( + `decrypt/${unidentifiedLogId}: unidentified message/plaintext contents` + ); const plaintextContent = PlaintextContent.deserialize( messageContent.contents() ); @@ -1286,6 +1294,9 @@ class MessageReceiverInner extends EventTarget { messageContent.msgType() === unidentifiedSenderTypeEnum.SENDERKEY_MESSAGE ) { + window.log.info( + `decrypt/${unidentifiedLogId}: unidentified message/sender key contents` + ); const sealedSenderIdentifier = certificate.senderUuid(); const sealedSenderSourceDevice = certificate.senderDeviceId(); const senderKeyStore = new SenderKeys(); @@ -1307,6 +1318,9 @@ class MessageReceiverInner extends EventTarget { ); } + window.log.info( + `decrypt/${unidentifiedLogId}: unidentified message/passing to sealedSenderDecryptMessage` + ); const sealedSenderIdentifier = envelope.sourceUuid || envelope.source; const address = `${sealedSenderIdentifier}.${envelope.sourceDevice}`; return window.textsecure.storage.protocol.enqueueSessionJob( @@ -1725,8 +1739,8 @@ class MessageReceiverInner extends EventTarget { envelope: EnvelopeClass, decryptionError: ByteBufferClass ) { - const envelopeId = this.getEnvelopeId(envelope); - window.log.info(`handleDecryptionError: ${envelopeId}`); + const logId = this.getEnvelopeId(envelope); + window.log.info(`handleDecryptionError: ${logId}`); const buffer = Buffer.from(decryptionError.toArrayBuffer()); const request = DecryptionErrorMessage.deserialize(buffer); @@ -1735,7 +1749,9 @@ class MessageReceiverInner extends EventTarget { const { sourceUuid, sourceDevice } = envelope; if (!sourceUuid || !sourceDevice) { - window.log.error('handleDecryptionError: Missing uuid or device!'); + window.log.error( + `handleDecryptionError/${logId}: Missing uuid or device!` + ); return; } @@ -1754,7 +1770,7 @@ class MessageReceiverInner extends EventTarget { distributionMessage: ByteBufferClass ): Promise { const envelopeId = this.getEnvelopeId(envelope); - window.log.info(`handleSenderKeyDistributionMessage: ${envelopeId}`); + window.log.info(`handleSenderKeyDistributionMessage/${envelopeId}`); // Note: we don't call removeFromCache here because this message can be combined // with a dataMessage, for example. That processing will dictate cache removal. diff --git a/ts/textsecure/WebAPI.ts b/ts/textsecure/WebAPI.ts index 6fbed700ab..43f589add7 100644 --- a/ts/textsecure/WebAPI.ts +++ b/ts/textsecure/WebAPI.ts @@ -1444,7 +1444,7 @@ export function initialize({ const capabilities: CapabilitiesUploadType = { 'gv2-3': true, 'gv1-migration': true, - senderKey: true, + senderKey: false, }; const { accessKey } = options; diff --git a/ts/util/sendToGroup.ts b/ts/util/sendToGroup.ts index c3eac73681..d960fc7442 100644 --- a/ts/util/sendToGroup.ts +++ b/ts/util/sendToGroup.ts @@ -111,7 +111,13 @@ export async function sendContentMessageToGroup({ 'sendContentMessageToGroup: textsecure.messaging not available!' ); - if (conversation.isGroupV2()) { + const ourConversationId = window.ConversationController.getOurConversationIdOrThrow(); + const ourConversation = window.ConversationController.get(ourConversationId); + + if ( + ourConversation?.get('capabilities')?.senderKey && + conversation.isGroupV2() + ) { try { return await sendToGroupViaSenderKey({ contentHint,