diff --git a/src/client.js b/src/client.js index 8905c964e..715580d01 100644 --- a/src/client.js +++ b/src/client.js @@ -73,7 +73,7 @@ function keysFromRecoverySession(sessions, decryptionKey, roomId) { decrypted.room_id = roomId; keys.push(decrypted); } catch (e) { - logger.log("Failed to decrypt session from backup"); + logger.log("Failed to decrypt megolm session from backup", e); } } return keys; @@ -1626,7 +1626,7 @@ MatrixClient.prototype._restoreKeyBackup = function( key.session_id = targetSessionId; keys.push(key); } catch (e) { - logger.log("Failed to decrypt session from backup"); + logger.log("Failed to decrypt megolm session from backup", e); } } @@ -4708,7 +4708,7 @@ function setupCallEventHandler(client) { const content = event.getContent(); let call = content.call_id ? client.callList[content.call_id] : undefined; let i; - //console.log("RECV %s content=%s", event.getType(), JSON.stringify(content)); + //console.info("RECV %s content=%s", event.getType(), JSON.stringify(content)); if (event.getType() === "m.call.invite") { if (event.getSender() === client.credentials.userId) { diff --git a/src/crypto/OlmDevice.js b/src/crypto/OlmDevice.js index 7060074a7..b86b4f858 100644 --- a/src/crypto/OlmDevice.js +++ b/src/crypto/OlmDevice.js @@ -462,7 +462,7 @@ OlmDevice.prototype.createInboundSession = async function( */ OlmDevice.prototype.getSessionIdsForDevice = async function(theirDeviceIdentityKey) { if (this._sessionsInProgress[theirDeviceIdentityKey]) { - logger.log("waiting for session to be created"); + logger.log("waiting for olm session to be created"); try { await this._sessionsInProgress[theirDeviceIdentityKey]; } catch (e) { @@ -543,7 +543,7 @@ OlmDevice.prototype.getSessionIdForDevice = async function( */ OlmDevice.prototype.getSessionInfoForDevice = async function(deviceIdentityKey, nowait) { if (this._sessionsInProgress[deviceIdentityKey] && !nowait) { - logger.log("waiting for session to be created"); + logger.log("waiting for olm session to be created"); try { await this._sessionsInProgress[deviceIdentityKey]; } catch (e) { @@ -595,8 +595,8 @@ OlmDevice.prototype.encryptMessage = async function( (txn) => { this._getSession(theirDeviceIdentityKey, sessionId, txn, (sessionInfo) => { const sessionDesc = sessionInfo.session.describe(); - console.log( - "Session ID " + sessionId + " to " + + logger.log( + "encryptMessage: Olm Session ID " + sessionId + " to " + theirDeviceIdentityKey + ": " + sessionDesc, ); res = sessionInfo.session.encrypt(payloadString); @@ -627,8 +627,8 @@ OlmDevice.prototype.decryptMessage = async function( (txn) => { this._getSession(theirDeviceIdentityKey, sessionId, txn, (sessionInfo) => { const sessionDesc = sessionInfo.session.describe(); - console.log( - "Session ID " + sessionId + " to " + + logger.log( + "decryptMessage: Olm Session ID " + sessionId + " from " + theirDeviceIdentityKey + ": " + sessionDesc, ); payloadString = sessionInfo.session.decrypt(messageType, ciphertext); @@ -740,6 +740,8 @@ OlmDevice.prototype.createOutboundGroupSession = function() { OlmDevice.prototype.encryptGroupMessage = function(sessionId, payloadString) { const self = this; + logger.log(`encrypting msg with megolm session ${sessionId}`); + checkPayloadLength(payloadString); return this._getOutboundGroupSession(sessionId, function(session) { @@ -886,7 +888,9 @@ OlmDevice.prototype.addInboundGroupSession = async function( <= session.first_known_index()) { // existing session has lower index (i.e. can // decrypt more), so keep it - logger.log("Keeping existing session"); + logger.log( + `Keeping existing megolm session ${sessionId}`, + ); return; } } diff --git a/src/crypto/algorithms/megolm.js b/src/crypto/algorithms/megolm.js index 4262c2cee..286c29804 100644 --- a/src/crypto/algorithms/megolm.js +++ b/src/crypto/algorithms/megolm.js @@ -104,7 +104,7 @@ OutboundSessionInfo.prototype.sharedWithTooManyDevices = function( } if (!devicesInRoom.hasOwnProperty(userId)) { - logger.log("Starting new session because we shared with " + userId); + logger.log("Starting new megolm session because we shared with " + userId); return true; } @@ -115,7 +115,7 @@ OutboundSessionInfo.prototype.sharedWithTooManyDevices = function( if (!devicesInRoom[userId].hasOwnProperty(deviceId)) { logger.log( - "Starting new session because we shared with " + + "Starting new megolm session because we shared with " + userId + ":" + deviceId, ); return true; @@ -200,6 +200,8 @@ MegolmEncryption.prototype._ensureOutboundSession = function(devicesInRoom) { if (!session) { logger.log(`Starting new megolm session for room ${self._roomId}`); session = await self._prepareNewSession(); + logger.log(`Started new megolm session ${session.sessionId} ` + + `for room ${self._roomId}`); self._outboundSessions[session.sessionId] = session; } @@ -278,7 +280,7 @@ MegolmEncryption.prototype._prepareNewSession = async function() { ).catch((e) => { // This throws if the upload failed, but this is fine // since it will have written it to the db and will retry. - logger.log("Failed to back up group session", e); + logger.log("Failed to back up megolm session", e); }); } @@ -440,19 +442,19 @@ MegolmEncryption.prototype.reshareKeyWithDevice = async function( ) { const obSessionInfo = this._outboundSessions[sessionId]; if (!obSessionInfo) { - logger.debug("Session ID " + sessionId + " not found: not re-sharing keys"); + logger.debug(`megolm session ${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("Session ID " + sessionId + " never shared with user " + userId); + logger.debug(`megolm session ${sessionId} never shared with user ${userId}`); return; } const sentChainIndex = obSessionInfo.sharedWithDevices[userId][device.deviceId]; if (sentChainIndex === undefined) { logger.debug( - "Session ID " + sessionId + " never shared with device " + + "megolm session ID " + sessionId + " never shared with device " + userId + ":" + device.deviceId, ); return; @@ -466,7 +468,7 @@ MegolmEncryption.prototype.reshareKeyWithDevice = async function( if (!key) { logger.warn( - "No outbound session key found for " + sessionId + ": not re-sharing keys", + `No inbound session key found for megolm ${sessionId}: not re-sharing keys`, ); return; } @@ -513,9 +515,8 @@ MegolmEncryption.prototype.reshareKeyWithDevice = async function( [device.deviceId]: encryptedContent, }, }); - logger.debug( - `Re-shared key for session ${sessionId} with ${userId}:${device.deviceId}`, - ); + logger.debug(`Re-shared key for megolm session ${sessionId} ` + + `with ${userId}:${device.deviceId}`); }; /** @@ -550,10 +551,10 @@ MegolmEncryption.prototype._shareKeyWithDevices = async function(session, device await this._encryptAndSendKeysToDevices( session, key.chain_index, userDeviceMaps[i], payload, ); - logger.log(`Completed megolm keyshare in ${this._roomId} ` - + `(slice ${i + 1}/${userDeviceMaps.length})`); + logger.log(`Completed megolm keyshare for ${session.sessionId} ` + + `in ${this._roomId} (slice ${i + 1}/${userDeviceMaps.length})`); } catch (e) { - logger.log(`megolm keyshare in ${this._roomId} ` + logger.log(`megolm keyshare for ${session.sessionId} in ${this._roomId} ` + `(slice ${i + 1}/${userDeviceMaps.length}) failed`); throw e; @@ -922,7 +923,7 @@ MegolmDecryption.prototype.onRoomKeyEvent = function(event) { keysClaimed = event.getKeysClaimed(); } - logger.log(`Adding key for megolm session ${senderKey}|${sessionId}`); + logger.log(`Received and adding key for megolm session ${senderKey}|${sessionId}`); return this._olmDevice.addInboundGroupSession( content.room_id, senderKey, forwardingKeyChain, sessionId, content.session_key, keysClaimed, @@ -955,7 +956,7 @@ MegolmDecryption.prototype.onRoomKeyEvent = function(event) { ).catch((e) => { // This throws if the upload failed, but this is fine // since it will have written it to the db and will retry. - logger.log("Failed to back up group session", e); + logger.log("Failed to back up megolm session", e); }); } }).catch((e) => { @@ -1088,7 +1089,7 @@ MegolmDecryption.prototype.importRoomKey = function(session) { ).catch((e) => { // This throws if the upload failed, but this is fine // since it will have written it to the db and will retry. - logger.log("Failed to back up group session", e); + logger.log("Failed to back up megolm session", e); }); } // have another go at decrypting events sent with this session. diff --git a/src/crypto/index.js b/src/crypto/index.js index 12f4e7643..d749d1d3f 100644 --- a/src/crypto/index.js +++ b/src/crypto/index.js @@ -1638,7 +1638,7 @@ Crypto.prototype.setRoomEncryption = async function(roomId, config, inhibitDevic // It would otherwise just throw later as an unknown algorithm would, but we may // as well catch this here if (!config.algorithm) { - console.log("Ignoring setRoomEncryption with no algorithm"); + logger.log("Ignoring setRoomEncryption with no algorithm"); return; } @@ -2294,6 +2294,9 @@ Crypto.prototype._getTrackedE2eRooms = function() { Crypto.prototype._onToDeviceEvent = function(event) { try { + logger.log(`received to_device ${event.getType()} from: ` + + `${event.getSender()} id: ${event.getId()}`); + if (event.getType() == "m.room_key" || event.getType() == "m.forwarded_room_key") { this._onRoomKeyEvent(event); diff --git a/src/crypto/olmlib.js b/src/crypto/olmlib.js index 93a492e26..4af8e035d 100644 --- a/src/crypto/olmlib.js +++ b/src/crypto/olmlib.js @@ -287,12 +287,12 @@ async function _verifyKeyAndStartSession(olmDevice, oneTimeKey, userId, deviceIn ); } catch (e) { // possibly a bad key - logger.error("Error starting session with device " + + logger.error("Error starting olm session with device " + userId + ":" + deviceId + ": " + e); return null; } - logger.log("Started new sessionid " + sid + + logger.log("Started new olm sessionid " + sid + " for device " + userId + ":" + deviceId); return sid; } diff --git a/src/crypto/store/indexeddb-crypto-store.js b/src/crypto/store/indexeddb-crypto-store.js index 8b96631f8..2919fb9ca 100644 --- a/src/crypto/store/indexeddb-crypto-store.js +++ b/src/crypto/store/indexeddb-crypto-store.js @@ -407,7 +407,7 @@ export default class IndexedDBCryptoStore { }); } - // Inbound group saessions + // Inbound group sessions /** * Retrieve the end-to-end inbound group session for a given