v2.4.5

As discussed in MSC2284, this relaxes the identity server discovery to a
`FAIL_PROMPT` state so that clients can choose to warn and continue.

Part of https://github.com/vector-im/riot-web/issues/11102
Implements https://github.com/matrix-org/matrix-doc/pull/2284

CHANGELOG.md

@@ -1,3 +1,10 @@
+Changes in [2.4.5](https://github.com/matrix-org/matrix-js-sdk/releases/tag/v2.4.5) (2019-11-27)
+================================================================================================
+[Full Changelog](https://github.com/matrix-org/matrix-js-sdk/compare/v2.4.4...v2.4.5)
+
+* Relax identity server discovery checks to FAIL_PROMPT
+* Expand E2EE debug logging to diagnose "unable to decrypt" errors
+
 Changes in [2.4.4](https://github.com/matrix-org/matrix-js-sdk/releases/tag/v2.4.4) (2019-11-25)
 ================================================================================================
 [Full Changelog](https://github.com/matrix-org/matrix-js-sdk/compare/v2.4.4-rc.1...v2.4.4)

package.json

@@ -1,6 +1,6 @@
 {
   "name": "matrix-js-sdk",
-  "version": "2.4.4",
+  "version": "2.4.5",
   "description": "Matrix Client-Server SDK for Javascript",
   "main": "index.js",
   "scripts": {

spec/unit/autodiscovery.spec.js

@@ -416,8 +416,8 @@ describe("AutoDiscovery", function() {
         ]);
     });
 
-    it("should return FAIL_ERROR when the identity server configuration is wrong " +
-        "(missing base_url)", function() {
+    it("should return SUCCESS / FAIL_PROMPT when the identity server configuration " +
+        "is wrong (missing base_url)", function() {
         httpBackend.when("GET", "/_matrix/client/versions").check((req) => {
             expect(req.opts.uri)
                 .toEqual("https://chat.example.org/_matrix/client/versions");
@@ -438,14 +438,14 @@ describe("AutoDiscovery", function() {
             AutoDiscovery.findClientConfig("example.org").then((conf) => {
                 const expected = {
                     "m.homeserver": {
-                        state: "FAIL_ERROR",
-                        error: AutoDiscovery.ERROR_INVALID_IS,
+                        state: "SUCCESS",
+                        error: null,
 
                         // We still expect the base_url to be here for debugging purposes.
                         base_url: "https://chat.example.org",
                     },
                     "m.identity_server": {
-                        state: "FAIL_ERROR",
+                        state: "FAIL_PROMPT",
                         error: AutoDiscovery.ERROR_INVALID_IS_BASE_URL,
                         base_url: null,
                     },
@@ -456,8 +456,8 @@ describe("AutoDiscovery", function() {
         ]);
     });
 
-    it("should return FAIL_ERROR when the identity server configuration is wrong " +
-        "(empty base_url)", function() {
+    it("should return SUCCESS / FAIL_PROMPT when the identity server configuration " +
+        "is wrong (empty base_url)", function() {
         httpBackend.when("GET", "/_matrix/client/versions").check((req) => {
             expect(req.opts.uri)
                 .toEqual("https://chat.example.org/_matrix/client/versions");
@@ -478,14 +478,14 @@ describe("AutoDiscovery", function() {
             AutoDiscovery.findClientConfig("example.org").then((conf) => {
                 const expected = {
                     "m.homeserver": {
-                        state: "FAIL_ERROR",
-                        error: AutoDiscovery.ERROR_INVALID_IS,
+                        state: "SUCCESS",
+                        error: null,
 
                         // We still expect the base_url to be here for debugging purposes.
                         base_url: "https://chat.example.org",
                     },
                     "m.identity_server": {
-                        state: "FAIL_ERROR",
+                        state: "FAIL_PROMPT",
                         error: AutoDiscovery.ERROR_INVALID_IS_BASE_URL,
                         base_url: null,
                     },
@@ -496,8 +496,8 @@ describe("AutoDiscovery", function() {
         ]);
     });
 
-    it("should return FAIL_ERROR when the identity server configuration is wrong " +
-        "(validation error: 404)", function() {
+    it("should return SUCCESS / FAIL_PROMPT when the identity server configuration " +
+        "is wrong (validation error: 404)", function() {
         httpBackend.when("GET", "/_matrix/client/versions").check((req) => {
             expect(req.opts.uri)
                 .toEqual("https://chat.example.org/_matrix/client/versions");
@@ -519,14 +519,14 @@ describe("AutoDiscovery", function() {
             AutoDiscovery.findClientConfig("example.org").then((conf) => {
                 const expected = {
                     "m.homeserver": {
-                        state: "FAIL_ERROR",
-                        error: AutoDiscovery.ERROR_INVALID_IS,
+                        state: "SUCCESS",
+                        error: null,
 
                         // We still expect the base_url to be here for debugging purposes.
                         base_url: "https://chat.example.org",
                     },
                     "m.identity_server": {
-                        state: "FAIL_ERROR",
+                        state: "FAIL_PROMPT",
                         error: AutoDiscovery.ERROR_INVALID_IDENTITY_SERVER,
                         base_url: "https://identity.example.org",
                     },
@@ -537,8 +537,8 @@ describe("AutoDiscovery", function() {
         ]);
     });
 
-    it("should return FAIL_ERROR when the identity server configuration is wrong " +
-        "(validation error: 500)", function() {
+    it("should return SUCCESS / FAIL_PROMPT when the identity server configuration " +
+        "is wrong (validation error: 500)", function() {
         httpBackend.when("GET", "/_matrix/client/versions").check((req) => {
             expect(req.opts.uri)
                 .toEqual("https://chat.example.org/_matrix/client/versions");
@@ -560,14 +560,14 @@ describe("AutoDiscovery", function() {
             AutoDiscovery.findClientConfig("example.org").then((conf) => {
                 const expected = {
                     "m.homeserver": {
-                        state: "FAIL_ERROR",
-                        error: AutoDiscovery.ERROR_INVALID_IS,
+                        state: "SUCCESS",
+                        error: null,
 
                         // We still expect the base_url to be here for debugging purposes
                         base_url: "https://chat.example.org",
                     },
                     "m.identity_server": {
-                        state: "FAIL_ERROR",
+                        state: "FAIL_PROMPT",
                         error: AutoDiscovery.ERROR_INVALID_IDENTITY_SERVER,
                         base_url: "https://identity.example.org",
                     },

src/autodiscovery.js

@@ -1,5 +1,6 @@
 /*
 Copyright 2018 New Vector Ltd
+Copyright 2019 The Matrix.org Foundation C.I.C.
 
 Licensed under the Apache License, Version 2.0 (the "License");
 you may not use this file except in compliance with the License.
@@ -275,21 +276,11 @@ export class AutoDiscovery {
         let isUrl = "";
         if (wellknown["m.identity_server"]) {
             // We prepare a failing identity server response to save lines later
-            // in this branch. Note that we also fail the homeserver check in the
-            // object because according to the spec we're supposed to FAIL_ERROR
-            // if *anything* goes wrong with the IS validation, including invalid
-            // format. This means we're supposed to stop discovery completely.
+            // in this branch.
             const failingClientConfig = {
-                "m.homeserver": {
-                    state: AutoDiscovery.FAIL_ERROR,
-                    error: AutoDiscovery.ERROR_INVALID_IS,
-
-                    // We'll provide the base_url that was previously valid for
-                    // debugging purposes.
-                    base_url: clientConfig["m.homeserver"].base_url,
-                },
+                "m.homeserver": clientConfig["m.homeserver"],
                 "m.identity_server": {
-                    state: AutoDiscovery.FAIL_ERROR,
+                    state: AutoDiscovery.FAIL_PROMPT,
                     error: AutoDiscovery.ERROR_INVALID_IS,
                     base_url: null,
                 },

src/base-apis.js

@@ -2333,6 +2333,12 @@ MatrixBaseApis.prototype.sendToDevice = function(
         messages: contentMap,
     };
 
+    const targets = Object.keys(contentMap).reduce((obj, key) => {
+        obj[key] = Object.keys(contentMap[key]);
+        return obj;
+    }, {});
+    logger.log(`PUT ${path}`, targets);
+
     return this._http.authedRequest(undefined, "PUT", path, undefined, body);
 };
 

src/client.js

@@ -72,7 +72,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;
@@ -1625,7 +1625,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);
             }
         }
 
@@ -4687,7 +4687,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) {

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;
                             }
                         }

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.

src/crypto/index.js

@@ -1619,7 +1619,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;
     }
 
@@ -2277,6 +2277,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);

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;
 }

src/crypto/store/indexeddb-crypto-store.js

@@ -389,7 +389,7 @@ export default class IndexedDBCryptoStore {
         );
     }
 
-    // Inbound group saessions
+    // Inbound group sessions
 
     /**
      * Retrieve the end-to-end inbound group session for a given