Improve logging of e2ee messages (#2884)

Attempt to make the way we log megolm session ids more consistent.

Author: richvdh

src/crypto/OlmDevice.ts

@@ -1139,17 +1139,14 @@ export class OlmDevice {
                         }
 
                         if (existingSession) {
-                            logger.log(
-                                "Update for megolm session "
-                                + senderKey + "/" + sessionId,
-                            );
+                            logger.log(`Update for megolm session ${senderKey}|${sessionId}`);
                             if (existingSession.first_known_index() <= session.first_known_index()) {
                                 if (!existingSessionData!.untrusted || extraSessionData.untrusted) {
                                     // existing session has less-than-or-equal index
                                     // (i.e. can decrypt at least as much), and the
                                     // new session's trust does not win over the old
                                     // session's trust, so keep it
-                                    logger.log(`Keeping existing megolm session ${sessionId}`);
+                                    logger.log(`Keeping existing megolm session ${senderKey}|${sessionId}`);
                                     return;
                                 }
                                 if (existingSession.first_known_index() < session.first_known_index()) {
@@ -1164,15 +1161,15 @@ export class OlmDevice {
                                     ) {
                                         logger.info(
                                             "Upgrading trust of existing megolm session " +
-                                            sessionId + " based on newly-received trusted session",
+                                            `${senderKey}|${sessionId} based on newly-received trusted session`,
                                         );
                                         existingSessionData!.untrusted = false;
                                         this.cryptoStore.storeEndToEndInboundGroupSession(
                                             senderKey, sessionId, existingSessionData!, txn,
                                         );
                                     } else {
                                         logger.warn(
-                                            "Newly-received megolm session " + sessionId +
+                                            `Newly-received megolm session ${senderKey}|$sessionId}` +
                                             " does not match existing session! Keeping existing session",
                                         );
                                     }
@@ -1183,8 +1180,8 @@ export class OlmDevice {
                         }
 
                         logger.info(
-                            "Storing megolm session " + senderKey + "/" + sessionId +
-                            " with first index " + session.first_known_index(),
+                            `Storing megolm session ${senderKey}|${sessionId} with first index `+
+                            session.first_known_index(),
                         );
 
                         const sessionData = Object.assign({}, extraSessionData, {

src/crypto/algorithms/megolm.ts

@@ -696,28 +696,27 @@ class MegolmEncryption extends EncryptionAlgorithm {
     ): Promise<void> {
         const obSessionInfo = this.outboundSessions[sessionId];
         if (!obSessionInfo) {
-            logger.debug(`megolm session ${sessionId} not found: not re-sharing keys`);
+            logger.debug(`megolm session ${senderKey}|${sessionId} not found: not re-sharing keys`);
             return;
         }
 
         // The chain index of the key we previously sent this device
         if (obSessionInfo.sharedWithDevices[userId] === undefined) {
-            logger.debug(`megolm session ${sessionId} never shared with user ${userId}`);
+            logger.debug(`megolm session ${senderKey}|${sessionId} never shared with user ${userId}`);
             return;
         }
         const sessionSharedData = obSessionInfo.sharedWithDevices[userId][device.deviceId];
         if (sessionSharedData === undefined) {
             logger.debug(
-                "megolm session ID " + sessionId + " never shared with device " +
-                userId + ":" + device.deviceId,
+                `megolm session ${senderKey}|${sessionId} never shared with device ${userId}:${device.deviceId}`,
             );
             return;
         }
 
         if (sessionSharedData.deviceKey !== device.getIdentityKey()) {
             logger.warn(
-                `Session has been shared with device ${device.deviceId} but with identity ` +
-                `key ${sessionSharedData.deviceKey}. Key is now ${device.getIdentityKey()}!`,
+                `Megolm session ${senderKey}|${sessionId} has been shared with device ${device.deviceId} but ` +
+                `with identity key ${sessionSharedData.deviceKey}. Key is now ${device.getIdentityKey()}!`,
             );
             return;
         }
@@ -730,7 +729,7 @@ class MegolmEncryption extends EncryptionAlgorithm {
 
         if (!key) {
             logger.warn(
-                `No inbound session key found for megolm ${sessionId}: not re-sharing keys`,
+                `No inbound session key found for megolm session ${senderKey}|${sessionId}: not re-sharing keys`,
             );
             return;
         }
@@ -776,7 +775,7 @@ class MegolmEncryption extends EncryptionAlgorithm {
                 [device.deviceId]: encryptedContent,
             },
         });
-        logger.debug(`Re-shared key for megolm session ${sessionId} with ${userId}:${device.deviceId}`);
+        logger.debug(`Re-shared key for megolm session ${senderKey}|${sessionId} with ${userId}:${device.deviceId}`);
     }
 
     /**
@@ -1902,10 +1901,11 @@ class MegolmDecryption extends DecryptionAlgorithm {
     public async sendSharedHistoryInboundSessions(devicesByUser: Record<string, DeviceInfo[]>): Promise<void> {
         await olmlib.ensureOlmSessionsForDevices(this.olmDevice, this.baseApis, devicesByUser);
 
-        logger.log("sendSharedHistoryInboundSessions to users", Object.keys(devicesByUser));
-
         const sharedHistorySessions = await this.olmDevice.getSharedHistoryInboundGroupSessions(this.roomId);
-        logger.log("shared-history sessions", sharedHistorySessions);
+        logger.log(
+            `Sharing history in ${this.roomId} with users ${Object.keys(devicesByUser)}`,
+            sharedHistorySessions.map(([senderKey, sessionId]) => `${senderKey}|${sessionId}`),
+        );
         for (const [senderKey, sessionId] of sharedHistorySessions) {
             const payload = await this.buildKeyForwardingMessage(this.roomId, senderKey, sessionId);