Merge branch 'develop' into kegan/indexeddb

spec/TestClient.js

@@ -52,21 +52,21 @@ export default function TestClient(userId, deviceId, accessToken) {
 /**
  * start the client, and wait for it to initialise.
  *
- * @param {object?} existingDevices  the list of our existing devices to return from
- *    the /query request. Defaults to empty device list
  * @return {Promise}
  */
-TestClient.prototype.start = function(existingDevices) {
+TestClient.prototype.start = function() {
     this.httpBackend.when("GET", "/pushrules").respond(200, {});
     this.httpBackend.when("POST", "/filter").respond(200, { filter_id: "fid" });
-    this.expectKeyUpload(existingDevices);
+    this.expectKeyUpload();
 
     this.client.startClient({
         // set this so that we can get hold of failed events
         pendingEventOrdering: 'detached',
     });
 
-    return this.httpBackend.flush();
+    return this.httpBackend.flush().then(() => {
+        console.log('TestClient[' + this.userId + ']: started');
+    });
 };
 
 /**
@@ -78,22 +78,9 @@ TestClient.prototype.stop = function() {
 
 /**
  * Set up expectations that the client will upload device and one-time keys.
- *
- * @param {object?} existingDevices  the list of our existing devices to return from
- *    the /query request. Defaults to empty device list
  */
-TestClient.prototype.expectKeyUpload = function(existingDevices) {
+TestClient.prototype.expectKeyUpload = function() {
     const self = this;
-    this.httpBackend.when('POST', '/keys/query').respond(200, function(path, content) {
-        expect(Object.keys(content.device_keys)).toEqual([self.userId]);
-        expect(content.device_keys[self.userId]).toEqual({});
-        let res = existingDevices;
-        if (!res) {
-            res = { device_keys: {} };
-            res.device_keys[self.userId] = {};
-        }
-        return res;
-    });
     this.httpBackend.when("POST", "/keys/upload").respond(200, function(path, content) {
         expect(content.one_time_keys).toBe(undefined);
         expect(content.device_keys).toBeTruthy();
@@ -111,6 +98,24 @@ TestClient.prototype.expectKeyUpload = function(existingDevices) {
     });
 };
 
+/**
+ * Set up expectations that the client will query device keys.
+ *
+ * We check that the query contains each of the users in `response`.
+ *
+ * @param {Object} response   response to the query.
+ */
+TestClient.prototype.expectKeyQuery = function(response) {
+    this.httpBackend.when('POST', '/keys/query').respond(
+        200, (path, content) => {
+            Object.keys(response.device_keys).forEach((userId) => {
+                expect(content.device_keys[userId]).toEqual({});
+            });
+            return response;
+        });
+};
+
+
 /**
  * get the uploaded curve25519 device key
  *

spec/integ/matrix-client-crypto.spec.js

@@ -393,7 +393,9 @@ describe("MatrixClient crypto", function() {
 
     afterEach(function() {
         aliTestClient.stop();
+        aliTestClient.httpBackend.verifyNoOutstandingExpectation();
         bobTestClient.stop();
+        bobTestClient.httpBackend.verifyNoOutstandingExpectation();
     });
 
     it('Ali knows the difference between a new user and one with no devices',
@@ -620,16 +622,13 @@ describe("MatrixClient crypto", function() {
             .then(function() {
                 aliTestClient.client.setDeviceBlocked(bobUserId, bobDeviceId, true);
                 const p1 = sendMessage(aliTestClient.client);
-                const p2 = expectAliQueryKeys()
+                const p2 = expectSendMessageRequest(aliTestClient.httpBackend)
-                    .then(expectAliClaimKeys)
+                      .then(function(sentContent) {
-                    .then(function() {
+                          // no unblocked devices, so the ciphertext should be empty
-                        return expectSendMessageRequest(aliTestClient.httpBackend);
+                          expect(sentContent.ciphertext).toEqual({});
-                    }).then(function(sentContent) {
+                      });
-                        // no unblocked devices, so the ciphertext should be empty
-                        expect(sentContent.ciphertext).toEqual({});
-                    });
                 return q.all([p1, p2]);
-            }).catch(testUtils.failTest).nodeify(done);
+            }).nodeify(done);
     });
 
     it("Bob receives two pre-key messages", function(done) {
@@ -685,4 +684,44 @@ describe("MatrixClient crypto", function() {
             }).then(expectAliQueryKeys)
             .nodeify(done);
     });
+
+    it("Ali does a key query when encryption is enabled", function(done) {
+        // enabling encryption in the room should make alice download devices
+        // for both members.
+        q()
+            .then(() => startClient(aliTestClient))
+            .then(() => {
+                const syncData = {
+                    next_batch: '2',
+                    rooms: {
+                        join: {},
+                    },
+                };
+                syncData.rooms.join[roomId] = {
+                    state: {
+                        events: [
+                            testUtils.mkEvent({
+                                type: 'm.room.encryption',
+                                skey: '',
+                                content: {
+                                    algorithm: 'm.olm.v1.curve25519-aes-sha2',
+                                },
+                            }),
+                        ],
+                    },
+                };
+
+                aliTestClient.httpBackend.when('GET', '/sync').respond(
+                    200, syncData);
+                return aliTestClient.httpBackend.flush('/sync', 1);
+            }).then(() => {
+                aliTestClient.expectKeyQuery({
+                    device_keys: {
+                        [aliUserId]: {},
+                        [bobUserId]: {},
+                    },
+                });
+                return aliTestClient.httpBackend.flush('/keys/query', 1);
+            }).nodeify(done);
+    });
 });

spec/integ/matrix-client-methods.spec.js

@@ -351,7 +351,6 @@ describe("MatrixClient", function() {
 
             httpBackend.when("POST", "/keys/query").check(function(req) {
                 expect(req.data).toEqual({device_keys: {
-                    '@alice:localhost': {},
                     'boris': {},
                     'chaz': {},
                 }});

spec/integ/megolm.spec.js

@@ -349,6 +349,69 @@ describe("megolm", function() {
         }).nodeify(done);
     });
 
+    it("Alice receives a megolm message before the session keys", function(done) {
+        // https://github.com/vector-im/riot-web/issues/2273
+        let roomKeyEncrypted;
+
+        return aliceTestClient.start().then(function() {
+            const p2pSession = createOlmSession(testOlmAccount, aliceTestClient);
+
+            const groupSession = new Olm.OutboundGroupSession();
+            groupSession.create();
+
+            // make the room_key event, but don't send it yet
+            roomKeyEncrypted = encryptGroupSessionKey({
+                senderKey: testSenderKey,
+                recipient: aliceTestClient,
+                p2pSession: p2pSession,
+                groupSession: groupSession,
+                room_id: ROOM_ID,
+            });
+
+            // encrypt a message with the group session
+            const messageEncrypted = encryptMegolmEvent({
+                senderKey: testSenderKey,
+                groupSession: groupSession,
+                room_id: ROOM_ID,
+            });
+
+            // Alice just gets the message event to start with
+            const syncResponse = {
+                next_batch: 1,
+                rooms: {
+                    join: {},
+                },
+            };
+            syncResponse.rooms.join[ROOM_ID] = {
+                timeline: {
+                    events: [messageEncrypted],
+                },
+            };
+
+            aliceTestClient.httpBackend.when("GET", "/sync").respond(200, syncResponse);
+            return aliceTestClient.httpBackend.flush("/sync", 1);
+        }).then(function() {
+            const room = aliceTestClient.client.getRoom(ROOM_ID);
+            const event = room.getLiveTimeline().getEvents()[0];
+            expect(event.getContent().msgtype).toEqual('m.bad.encrypted');
+
+            // now she gets the room_key event
+            const syncResponse = {
+                next_batch: 2,
+                to_device: {
+                    events: [roomKeyEncrypted],
+                },
+            };
+
+            aliceTestClient.httpBackend.when("GET", "/sync").respond(200, syncResponse);
+            return aliceTestClient.httpBackend.flush("/sync", 1);
+        }).then(function() {
+            const room = aliceTestClient.client.getRoom(ROOM_ID);
+            const event = room.getLiveTimeline().getEvents()[0];
+            expect(event.getContent().body).toEqual('42');
+        }).nodeify(done);
+    });
+
     it("Alice gets a second room_key message", function(done) {
         return aliceTestClient.start().then(function() {
             const p2pSession = createOlmSession(testOlmAccount, aliceTestClient);
@@ -672,9 +735,7 @@ describe("megolm", function() {
         let inboundGroupSession;
         let decrypted;
 
-        return aliceTestClient.start(
+        return aliceTestClient.start().then(function() {
-            getTestKeysQueryResponse(aliceTestClient.userId),
-        ).then(function() {
             // an encrypted room with just alice
             const syncResponse = {
                 next_batch: 1,
@@ -701,6 +762,13 @@ describe("megolm", function() {
             };
             aliceTestClient.httpBackend.when('GET', '/sync').respond(200, syncResponse);
 
+            // the completion of the first initialsync hould make Alice
+            // invalidate the device cache for all members in e2e rooms (ie,
+            // herself), and do a key query.
+            aliceTestClient.expectKeyQuery(
+                getTestKeysQueryResponse(aliceTestClient.userId),
+            );
+
             return aliceTestClient.httpBackend.flush();
         }).then(function() {
             aliceTestClient.client.setDeviceKnown(aliceTestClient.userId, 'DEVICE_ID');

spec/mock-request.js

@@ -49,17 +49,17 @@ HttpBackend.prototype = {
         const tryFlush = function() {
             // if there's more real requests and more expected requests, flush 'em.
             console.log(
-                "  trying to flush queue => reqs=%s expected=%s [%s]",
+                "  trying to flush queue => reqs=[%s] expected=[%s]",
-                self.requests.length, self.expectedRequests.length, path,
+                self.requests, self.expectedRequests.map((er) => er.path),
             );
             if (self._takeFromQueue(path)) {
                 // try again on the next tick.
-                console.log("  flushed. Trying for more. [%s]", path);
                 flushed += 1;
                 if (numToFlush && flushed === numToFlush) {
-                    console.log("  [%s] Flushed assigned amount: %s", path, numToFlush);
+                    console.log("  Flushed assigned amount: %s", numToFlush);
                     defer.resolve();
                 } else {
+                    console.log("  flushed. Trying for more.");
                     setTimeout(tryFlush, 0);
                 }
             } else if (flushed === 0 && !triedWaiting) {
@@ -68,7 +68,7 @@ HttpBackend.prototype = {
                 setTimeout(tryFlush, 5);
                 triedWaiting = true;
             } else {
-                console.log("  no more flushes. [%s]", path);
+                console.log("  no more flushes.");
                 defer.resolve();
             }
         };

src/client.js

@@ -556,6 +556,9 @@ function _decryptEvent(client, event) {
     try {
         client._crypto.decryptEvent(event);
     } catch (e) {
+        console.warn(
+            `Error decrypting event (id=${event.getId()}): ${e}`,
+        );
         if (!(e instanceof Crypto.DecryptionError)) {
             throw e;
         }

src/crypto/DeviceList.js

@@ -64,7 +64,13 @@ export default class DeviceList {
                 // just wait for the existing download to complete
                 promises.push(this._keyDownloadsInProgressByUser[u]);
             } else {
-                if (forceDownload || !this.getStoredDevicesForUser(u)) {
+                if (forceDownload) {
+                    console.log("Invalidating device list for " + u +
+                                " for forceDownload");
+                    this.invalidateUserDeviceList(u);
+                } else if (!this.getStoredDevicesForUser(u)) {
+                    console.log("Invalidating device list for " + u +
+                                " due to empty cache");
                     this.invalidateUserDeviceList(u);
                 }
                 if (this._pendingUsersWithNewDevices[u]) {
@@ -398,7 +404,7 @@ function _updateStoredDeviceKeysForUser(_olmDevice, userId, userStore,
     const signKeyId = "ed25519:" + deviceId;
     const signKey = deviceResult.keys[signKeyId];
     if (!signKey) {
-        console.log("Device " + userId + ":" + deviceId +
+        console.warn("Device " + userId + ":" + deviceId +
             " has no ed25519 key");
         return false;
     }
@@ -408,8 +414,8 @@ function _updateStoredDeviceKeysForUser(_olmDevice, userId, userStore,
     try {
         olmlib.verifySignature(_olmDevice, deviceResult, userId, deviceId, signKey);
     } catch (e) {
-        console.log("Unable to verify signature on device " +
+        console.warn("Unable to verify signature on device " +
-            userId + ":" + deviceId + ":", e);
+            userId + ":" + deviceId + ":" + e);
         return false;
     }
 
@@ -425,7 +431,7 @@ function _updateStoredDeviceKeysForUser(_olmDevice, userId, userStore,
             // best off sticking with the original keys.
             //
             // Should we warn the user about it somehow?
-            console.warn("Ed25519 key for device" + userId + ": " +
+            console.warn("Ed25519 key for device " + userId + ":" +
                deviceId + " has changed");
             return false;
         }

src/crypto/algorithms/base.js

@@ -148,14 +148,42 @@ DecryptionAlgorithm.prototype.importRoomKey = function(session) {
 /**
  * Exception thrown when decryption fails
  *
+ * @alias module:crypto/algorithms/base.DecryptionError
  * @constructor
- * @param {string} msg message describing the problem
+ * @param {string} msg user-visible message describing the problem
+ *
+ * @param {Object=} details key/value pairs reported in the logs but not shown
+ *   to the user.
+ *
  * @extends Error
  */
-module.exports.DecryptionError = function(msg) {
+const DecryptionError = function(msg, details) {
+    this.name = 'DecryptionError';
     this.message = msg;
+    this.details = details;
 };
-utils.inherits(module.exports.DecryptionError, Error);
+utils.inherits(DecryptionError, Error);
+
+/** override the string used when logging
+ *
+ * @returns {String}
+ */
+DecryptionError.prototype.toString = function() {
+    let result = this.name + '[msg: ' + this.message;
+
+    if (this.details) {
+        result += ', ' +
+            Object.keys(this.details).map(
+                (k) => k + ': ' + this.details[k],
+            ).join(', ');
+    }
+
+    result += ']';
+
+    return result;
+};
+
+module.exports.DecryptionError = DecryptionError;
 
 /**
  * Exception thrown specifically when we want to warn the user to consider

src/crypto/algorithms/megolm.js

@@ -544,7 +544,11 @@ MegolmDecryption.prototype.decryptEvent = function(event) {
         if (e.message === 'OLM.UNKNOWN_MESSAGE_INDEX') {
             this._addEventToPendingList(event);
         }
-        throw new base.DecryptionError(e);
+        throw new base.DecryptionError(
+            e.toString(), {
+                session: content.sender_key + '|' + content.session_id,
+            },
+        );
     }
 
     if (res === null) {
@@ -552,6 +556,9 @@ MegolmDecryption.prototype.decryptEvent = function(event) {
         this._addEventToPendingList(event);
         throw new base.DecryptionError(
             "The sender's device has not sent us the keys for this message.",
+            {
+                session: content.sender_key + '|' + content.session_id,
+            },
         );
     }
 
@@ -593,24 +600,30 @@ MegolmDecryption.prototype._addEventToPendingList = function(event) {
  * @param {module:models/event.MatrixEvent} event key event
  */
 MegolmDecryption.prototype.onRoomKeyEvent = function(event) {
-    console.log("Adding key from ", event);
     const content = event.getContent();
+    const senderKey = event.getSenderKey();
+    const sessionId = content.session_id;
 
     if (!content.room_id ||
-        !content.session_id ||
+        !sessionId ||
         !content.session_key
        ) {
         console.error("key event is missing fields");
         return;
     }
+    if (!senderKey) {
+        console.error("key event has no sender key (not encrypted?)");
+        return;
+    }
 
+    console.log(`Adding key for megolm session ${senderKey}|${sessionId}`);
     this._olmDevice.addInboundGroupSession(
-        content.room_id, event.getSenderKey(), content.session_id,
+        content.room_id, senderKey, sessionId,
         content.session_key, event.getKeysClaimed(),
     );
 
     // have another go at decrypting events sent with this session.
-    this._retryDecryption(event.getSenderKey, content.session_id);
+    this._retryDecryption(senderKey, sessionId);
 };
 
 

src/crypto/algorithms/olm.js

@@ -64,7 +64,7 @@ OlmEncryption.prototype._ensureSession = function(roomMembers) {
     }
 
     const self = this;
-    this._prepPromise = self._crypto.downloadKeys(roomMembers, true).then(function(res) {
+    this._prepPromise = self._crypto.downloadKeys(roomMembers).then(function(res) {
         return self._crypto.ensureOlmSessionsForUsers(roomMembers);
     }).then(function() {
         self._sessionPrepared = true;
@@ -174,12 +174,12 @@ OlmDecryption.prototype.decryptEvent = function(event) {
     try {
         payloadString = this._decryptMessage(deviceKey, message);
     } catch (e) {
-        console.warn(
+        throw new base.DecryptionError(
-            "Failed to decrypt Olm event (id=" +
+            "Bad Encrypted Message", {
-                event.getId() + ") from " + deviceKey +
+                sender: deviceKey,
-                ": " + e.message,
+                err: e,
+            },
         );
-        throw new base.DecryptionError("Bad Encrypted Message");
     }
 
     const payload = JSON.parse(payloadString);
@@ -187,22 +187,18 @@ OlmDecryption.prototype.decryptEvent = function(event) {
     // check that we were the intended recipient, to avoid unknown-key attack
     // https://github.com/vector-im/vector-web/issues/2483
     if (payload.recipient != this._userId) {
-        console.warn(
-            "Event " + event.getId() + ": Intended recipient " +
-            payload.recipient + " does not match our id " + this._userId,
-        );
         throw new base.DecryptionError(
             "Message was intented for " + payload.recipient,
         );
     }
 
-    if (payload.recipient_keys.ed25519 !=
+    if (payload.recipient_keys.ed25519 != this._olmDevice.deviceEd25519Key) {
-               this._olmDevice.deviceEd25519Key) {
+        throw new base.DecryptionError(
-        console.warn(
+            "Message not intended for this device", {
-            "Event " + event.getId() + ": Intended recipient ed25519 key " +
+                intended: payload.recipient_keys.ed25519,
-            payload.recipient_keys.ed25519 + " did not match ours",
+                our_key: this._olmDevice.deviceEd25519Key,
+            },
         );
-        throw new base.DecryptionError("Message not intended for this device");
     }
 
     // check that the original sender matches what the homeserver told us, to
@@ -210,23 +206,19 @@ OlmDecryption.prototype.decryptEvent = function(event) {
     // (this check is also provided via the sender's embedded ed25519 key,
     // which is checked elsewhere).
     if (payload.sender != event.getSender()) {
-        console.warn(
-            "Event " + event.getId() + ": original sender " + payload.sender +
-            " does not match reported sender " + event.getSender(),
-        );
         throw new base.DecryptionError(
-            "Message forwarded from " + payload.sender,
+            "Message forwarded from " + payload.sender, {
+                reported_sender: event.getSender(),
+            },
         );
     }
 
     // Olm events intended for a room have a room_id.
     if (payload.room_id !== event.getRoomId()) {
-        console.warn(
-            "Event " + event.getId() + ": original room " + payload.room_id +
-            " does not match reported room " + event.room_id,
-        );
         throw new base.DecryptionError(
-            "Message intended for room " + payload.room_id,
+            "Message intended for room " + payload.room_id, {
+                reported_room: event.room_id,
+            },
         );
     }
 

src/crypto/index.js

@@ -86,9 +86,6 @@ function Crypto(baseApis, eventEmitter, sessionStore, userId, deviceId,
     );
 
     if (!myDevices) {
-        // we don't yet have a list of our own devices; make sure we
-        // get one when we flush the pendingUsersWithNewDevices.
-        this._deviceList.invalidateUserDeviceList(this._userId);
         myDevices = {};
     }
 
@@ -545,6 +542,23 @@ Crypto.prototype.setRoomEncryption = function(roomId, config) {
         config: config,
     });
     this._roomEncryptors[roomId] = alg;
+
+    // if encryption was not previously enabled in this room, we will have been
+    // ignoring new device events for these users so far. We may well have
+    // up-to-date lists for some users, for instance if we were sharing other
+    // e2e rooms with them, so there is room for optimisation here, but for now
+    // we just invalidate everyone in the room.
+    if (!existingConfig) {
+        console.log("Enabling encryption in " + roomId + " for the first time; " +
+                    "invalidating device lists for all users therein");
+        const room = this._clientStore.getRoom(roomId);
+        const members = room.getJoinedMembers();
+        members.forEach((m) => {
+            this._deviceList.invalidateUserDeviceList(m.userId);
+        });
+        // the actual refresh happens once we've finished processing the sync,
+        // in _onSyncCompleted.
+    }
 };
 
 
@@ -769,6 +783,8 @@ Crypto.prototype._onSyncCompleted = function(syncData) {
         } else {
             // otherwise, we have to invalidate all devices for all users we
             // share a room with.
+            console.log("Completed first initialsync; invalidating all " +
+                        "device list caches");
             this._invalidateDeviceListForAllActiveUsers();
         }
     }

src/sync.js

@@ -363,9 +363,6 @@ SyncApi.prototype.getSyncState = function() {
  * Main entry point
  */
 SyncApi.prototype.sync = function() {
-    debuglog("SyncApi.sync: starting with sync token " +
-             this.client.store.getSyncToken());
-
     const client = this.client;
     const self = this;
 
@@ -520,7 +517,7 @@ SyncApi.prototype._sync = function(syncOptions) {
         // Don't do an HTTP hit to /sync. Instead, load up the persisted /sync data,
         // if there is data there.
         if (data.nextBatch) {
-            console.log("sync(): not doing HTTP hit, instead returning stored /sync");
+            debuglog("sync(): not doing HTTP hit, instead returning stored /sync data");
             this._currentSyncRequest = q.resolve({
                 next_batch: data.nextBatch,
                 rooms: data.roomsData,
@@ -530,12 +527,15 @@ SyncApi.prototype._sync = function(syncOptions) {
     }
 
     if (!isCachedResponse) {
+        debuglog('Starting sync since=' + syncToken);
         this._currentSyncRequest = client._http.authedRequest(
             undefined, "GET", "/sync", qps, undefined, clientSideTimeoutMs,
         );
     }
 
     this._currentSyncRequest.done(function(data) {
+        debuglog('Completed sync, next_batch=' + data.next_batch);
+
         // set the sync token NOW *before* processing the events. We do this so
         // if something barfs on an event we can skip it rather than constantly
         // polling with the same token.
@@ -697,8 +697,10 @@ SyncApi.prototype._processSyncResponse = function(syncToken, data) {
                         toDeviceEvent.getType() == "m.room.message" &&
                             content.msgtype == "m.bad.encrypted"
                     ) {
-                        console.warn(
+                        // the mapper already logged a warning.
-                            "Unable to decrypt to-device event: " + content.body,
+                        console.log(
+                            'Ignoring undecryptable to-device event from ' +
+                                toDeviceEvent.getSender(),
                         );
                         return;
                     }