Dismiss "Key storage out of sync" toast when secrets received (#29348)

* DeviceListener: improve logging

use a LogSpan to tie together logs from the same run, and add some more logs
for various cases

* Regression playwright test

* Remove unused mocking of `getCrossSigningId`

DeviceListener no longer reads this thing

* Clean up unit tests

Remove redundant describe block

* Remove the "out of sync" toast when we are no longer out of sync

Receiving the crypto secrets via secret sharing should make the toast go away.

playwright/e2e/crypto/device-verification.spec.ts

@@ -21,6 +21,7 @@ import {
     waitForVerificationRequest,
 } from "./utils";
 import { type Bot } from "../../pages/bot";
+import { Toasts } from "../../pages/toasts.ts";
 
 test.describe("Device verification", { tag: "@no-webkit" }, () => {
     let aliceBotClient: Bot;
@@ -72,6 +73,51 @@ test.describe("Device verification", { tag: "@no-webkit" }, () => {
         await checkDeviceIsConnectedKeyBackup(app, expectedBackupVersion, false);
     });
 
+    // Regression test for https://github.com/element-hq/element-web/issues/29110
+    test("No toast after verification, even if the secrets take a while to arrive", async ({ page, credentials }) => {
+        // Before we log in, the bot creates an encrypted room, so that we can test the toast behaviour that only happens
+        // when we are in an encrypted room.
+        await aliceBotClient.createRoom({
+            initial_state: [
+                {
+                    type: "m.room.encryption",
+                    state_key: "",
+                    content: { algorithm: "m.megolm.v1.aes-sha2" },
+                },
+            ],
+        });
+
+        // In order to simulate a real environment more accurately, we need to slow down the arrival of the
+        // `m.secret.send` to-device messages. That's slightly tricky to do directly, so instead we delay the *outgoing*
+        // `m.secret.request` messages.
+        await page.route("**/_matrix/client/v3/sendToDevice/m.secret.request/**", async (route) => {
+            await route.fulfill({ json: {} });
+            await new Promise((f) => setTimeout(f, 1000));
+            await route.fetch();
+        });
+
+        await logIntoElement(page, credentials);
+
+        // Launch the verification request between alice and the bot
+        const verificationRequest = await initiateAliceVerificationRequest(page);
+
+        // Handle emoji SAS verification
+        const infoDialog = page.locator(".mx_InfoDialog");
+        // the bot chooses to do an emoji verification
+        const verifier = await verificationRequest.evaluateHandle((request) => request.startVerification("m.sas.v1"));
+
+        // Handle emoji request and check that emojis are matching
+        await doTwoWaySasVerification(page, verifier);
+
+        await infoDialog.getByRole("button", { name: "They match" }).click();
+        await infoDialog.getByRole("button", { name: "Got it" }).click();
+
+        // There should be no toast (other than the notifications one)
+        const toasts = new Toasts(page);
+        await toasts.rejectToast("Notifications");
+        await toasts.assertNoToasts();
+    });
+
     test("Verify device with QR code during login", async ({ page, app, credentials, homeserver }) => {
         // A mode 0x02 verification: "self-verifying in which the current device does not yet trust the master key"
         await logIntoElement(page, credentials);

src/DeviceListener.ts

@@ -15,9 +15,10 @@ import {
     type SyncState,
     ClientStoppedError,
 } from "matrix-js-sdk/src/matrix";
-import { logger as baseLogger } from "matrix-js-sdk/src/logger";
+import { logger as baseLogger, LogSpan } from "matrix-js-sdk/src/logger";
 import { CryptoEvent, type KeyBackupInfo } from "matrix-js-sdk/src/crypto-api";
 import { type CryptoSessionStateChange } from "@matrix-org/analytics-events/types/typescript/CryptoSessionStateChange";
+import { secureRandomString } from "matrix-js-sdk/src/randomstring";
 
 import { PosthogAnalytics } from "./PosthogAnalytics";
 import dis from "./dispatcher/dispatcher";
@@ -96,6 +97,7 @@ export default class DeviceListener {
         this.client.on(ClientEvent.AccountData, this.onAccountData);
         this.client.on(ClientEvent.Sync, this.onSync);
         this.client.on(RoomStateEvent.Events, this.onRoomStateEvents);
+        this.client.on(ClientEvent.ToDeviceEvent, this.onToDeviceEvent);
         this.shouldRecordClientInformation = SettingsStore.getValue("deviceClientInformationOptIn");
         // only configurable in config, so we don't need to watch the value
         this.enableBulkUnverifiedSessionsReminder = SettingsStore.getValue(UIFeature.BulkUnverifiedSessionsReminder);
@@ -118,6 +120,7 @@ export default class DeviceListener {
             this.client.removeListener(ClientEvent.AccountData, this.onAccountData);
             this.client.removeListener(ClientEvent.Sync, this.onSync);
             this.client.removeListener(RoomStateEvent.Events, this.onRoomStateEvents);
+            this.client.removeListener(ClientEvent.ToDeviceEvent, this.onToDeviceEvent);
         }
         SettingsStore.unwatchSetting(this.deviceClientInformationSettingWatcherRef);
         dis.unregister(this.dispatcherRef);
@@ -225,6 +228,11 @@ export default class DeviceListener {
         this.updateClientInformation();
     };
 
+    private onToDeviceEvent = (event: MatrixEvent): void => {
+        // Receiving a 4S secret can mean we are in sync where we were not before.
+        if (event.getType() === EventType.SecretSend) this.recheck();
+    };
+
     /**
      * Fetch the key backup information from the server.
      *
@@ -273,18 +281,29 @@ export default class DeviceListener {
 
     private async doRecheck(): Promise<void> {
         if (!this.running || !this.client) return; // we have been stopped
+        const logSpan = new LogSpan(logger, "check_" + secureRandomString(4));
+
         const cli = this.client;
 
         // cross-signing support was added to Matrix in MSC1756, which landed in spec v1.1
-        if (!(await cli.isVersionSupported("v1.1"))) return;
+        if (!(await cli.isVersionSupported("v1.1"))) {
+            logSpan.debug("cross-signing not supported");
+            return;
+        }
 
         const crypto = cli.getCrypto();
-        if (!crypto) return;
+        if (!crypto) {
+            logSpan.debug("crypto not enabled");
+            return;
+        }
 
         // don't recheck until the initial sync is complete: lots of account data events will fire
         // while the initial sync is processing and we don't need to recheck on each one of them
         // (we add a listener on sync to do once check after the initial sync is done)
-        if (!cli.isInitialSyncComplete()) return;
+        if (!cli.isInitialSyncComplete()) {
+            logSpan.debug("initial sync not yet complete");
+            return;
+        }
 
         const crossSigningReady = await crypto.isCrossSigningReady();
         const secretStorageReady = await crypto.isSecretStorageReady();
@@ -306,6 +325,7 @@ export default class DeviceListener {
         await this.reportCryptoSessionStateToAnalytics(cli);
 
         if (this.dismissedThisDeviceToast || allSystemsReady) {
+            logSpan.info("No toast needed");
             hideSetupEncryptionToast();
 
             this.checkKeyBackupStatus();
@@ -316,27 +336,33 @@ export default class DeviceListener {
             if (!crossSigningReady) {
                 // This account is legacy and doesn't have cross-signing set up at all.
                 // Prompt the user to set it up.
-                logger.info("Cross-signing not ready: showing SET_UP_ENCRYPTION toast");
+                logSpan.info("Cross-signing not ready: showing SET_UP_ENCRYPTION toast");
                 showSetupEncryptionToast(SetupKind.SET_UP_ENCRYPTION);
             } else if (!isCurrentDeviceTrusted) {
                 // cross signing is ready but the current device is not trusted: prompt the user to verify
-                logger.info("Current device not verified: showing VERIFY_THIS_SESSION toast");
+                logSpan.info("Current device not verified: showing VERIFY_THIS_SESSION toast");
                 showSetupEncryptionToast(SetupKind.VERIFY_THIS_SESSION);
             } else if (!allCrossSigningSecretsCached) {
                 // cross signing ready & device trusted, but we are missing secrets from our local cache.
                 // prompt the user to enter their recovery key.
-                logger.info("Some secrets not cached: showing KEY_STORAGE_OUT_OF_SYNC toast");
+                logSpan.info(
+                    "Some secrets not cached: showing KEY_STORAGE_OUT_OF_SYNC toast",
+                    crossSigningStatus.privateKeysCachedLocally,
+                );
                 showSetupEncryptionToast(SetupKind.KEY_STORAGE_OUT_OF_SYNC);
             } else if (defaultKeyId === null) {
                 // the user just hasn't set up 4S yet: prompt them to do so (unless they've explicitly said no to key storage)
                 const disabledEvent = cli.getAccountData(BACKUP_DISABLED_ACCOUNT_DATA_KEY);
                 if (!disabledEvent?.getContent().disabled) {
+                    logSpan.info("No default 4S key: showing SET_UP_RECOVERY toast");
                     showSetupEncryptionToast(SetupKind.SET_UP_RECOVERY);
+                } else {
+                    logSpan.info("No default 4S key but backup disabled: no toast needed");
                 }
             } else {
                 // some other condition... yikes! Show the 'set up encryption' toast: this is what we previously did
                 // in 'other' situations. Possibly we should consider prompting for a full reset in this case?
-                logger.warn("Couldn't match encryption state to a known case: showing 'setup encryption' prompt", {
+                logSpan.warn("Couldn't match encryption state to a known case: showing 'setup encryption' prompt", {
                     crossSigningReady,
                     secretStorageReady,
                     allCrossSigningSecretsCached,
@@ -345,6 +371,8 @@ export default class DeviceListener {
                 });
                 showSetupEncryptionToast(SetupKind.SET_UP_ENCRYPTION);
             }
+        } else {
+            logSpan.info("Not yet ready, but shouldShowSetupEncryptionToast==false");
         }
 
         // This needs to be done after awaiting on getUserDeviceInfo() above, so
@@ -377,9 +405,9 @@ export default class DeviceListener {
             }
         }
 
-        logger.debug("Old unverified sessions: " + Array.from(oldUnverifiedDeviceIds).join(","));
+        logSpan.debug("Old unverified sessions: " + Array.from(oldUnverifiedDeviceIds).join(","));
-        logger.debug("New unverified sessions: " + Array.from(newUnverifiedDeviceIds).join(","));
+        logSpan.debug("New unverified sessions: " + Array.from(newUnverifiedDeviceIds).join(","));
-        logger.debug("Currently showing toasts for: " + Array.from(this.displayingToastsForDeviceIds).join(","));
+        logSpan.debug("Currently showing toasts for: " + Array.from(this.displayingToastsForDeviceIds).join(","));
 
         const isBulkUnverifiedSessionsReminderSnoozed = isBulkUnverifiedDeviceReminderSnoozed();
 
@@ -404,7 +432,7 @@ export default class DeviceListener {
         // ...and hide any we don't need any more
         for (const deviceId of this.displayingToastsForDeviceIds) {
             if (!newUnverifiedDeviceIds.has(deviceId)) {
-                logger.debug("Hiding unverified session toast for " + deviceId);
+                logSpan.debug("Hiding unverified session toast for " + deviceId);
                 hideUnverifiedSessionsToast(deviceId);
             }
         }

test/unit-tests/DeviceListener-test.ts

@@ -7,7 +7,14 @@ Please see LICENSE files in the repository root for full details.
 */
 
 import { type Mocked, mocked } from "jest-mock";
-import { MatrixEvent, type Room, type MatrixClient, Device, ClientStoppedError } from "matrix-js-sdk/src/matrix";
+import {
+    MatrixEvent,
+    type Room,
+    type MatrixClient,
+    Device,
+    ClientStoppedError,
+    ClientEvent,
+} from "matrix-js-sdk/src/matrix";
 import {
     CryptoEvent,
     type CrossSigningStatus,
@@ -81,7 +88,6 @@ describe("DeviceListener", () => {
             getDeviceVerificationStatus: jest.fn().mockResolvedValue({
                 crossSigningVerified: false,
             }),
-            getCrossSigningKeyId: jest.fn(),
             getUserDeviceInfo: jest.fn().mockResolvedValue(new Map()),
             isCrossSigningReady: jest.fn().mockResolvedValue(true),
             isSecretStorageReady: jest.fn().mockResolvedValue(true),
@@ -328,26 +334,21 @@ describe("DeviceListener", () => {
                 expect(SetupEncryptionToast.showToast).not.toHaveBeenCalled();
             });
 
-            describe("when user does not have a cross signing id on this device", () => {
+            it("shows verify session toast when account has cross signing", async () => {
-                beforeEach(() => {
+                mockCrypto!.isCrossSigningReady.mockResolvedValue(true);
-                    mockCrypto!.getCrossSigningKeyId.mockResolvedValue(null);
+                await createAndStart();
-                });
 
-                it("shows verify session toast when account has cross signing", async () => {
+                expect(mockCrypto!.getUserDeviceInfo).toHaveBeenCalled();
-                    mockCrypto!.isCrossSigningReady.mockResolvedValue(true);
+                expect(SetupEncryptionToast.showToast).toHaveBeenCalledWith(
-                    await createAndStart();
+                    SetupEncryptionToast.Kind.VERIFY_THIS_SESSION,
-
+                );
-                    expect(mockCrypto!.getUserDeviceInfo).toHaveBeenCalled();
-                    expect(SetupEncryptionToast.showToast).toHaveBeenCalledWith(
-                        SetupEncryptionToast.Kind.VERIFY_THIS_SESSION,
-                    );
-                });
             });
 
-            describe("when user does have a cross signing id on this device", () => {
+            describe("when current device is verified", () => {
                 beforeEach(() => {
                     mockCrypto!.isCrossSigningReady.mockResolvedValue(true);
-                    mockCrypto!.getCrossSigningKeyId.mockResolvedValue("abc");
+
+                    // current device is verified
                     mockCrypto!.getDeviceVerificationStatus.mockResolvedValue(
                         new DeviceVerificationStatus({
                             trustCrossSignedDevices: true,
@@ -356,6 +357,60 @@ describe("DeviceListener", () => {
                     );
                 });
 
+                it("shows an out-of-sync toast when one of the secrets is missing", async () => {
+                    mockCrypto!.getCrossSigningStatus.mockResolvedValue({
+                        publicKeysOnDevice: true,
+                        privateKeysInSecretStorage: true,
+                        privateKeysCachedLocally: {
+                            masterKey: false,
+                            selfSigningKey: true,
+                            userSigningKey: true,
+                        },
+                    });
+
+                    await createAndStart();
+
+                    expect(SetupEncryptionToast.showToast).toHaveBeenCalledWith(
+                        SetupEncryptionToast.Kind.KEY_STORAGE_OUT_OF_SYNC,
+                    );
+                });
+
+                it("hides the out-of-sync toast when one of the secrets is missing", async () => {
+                    mockCrypto!.isSecretStorageReady.mockResolvedValue(true);
+
+                    // First show the toast
+                    mockCrypto!.getCrossSigningStatus.mockResolvedValue({
+                        publicKeysOnDevice: true,
+                        privateKeysInSecretStorage: true,
+                        privateKeysCachedLocally: {
+                            masterKey: false,
+                            selfSigningKey: true,
+                            userSigningKey: true,
+                        },
+                    });
+
+                    await createAndStart();
+
+                    expect(SetupEncryptionToast.showToast).toHaveBeenCalledWith(
+                        SetupEncryptionToast.Kind.KEY_STORAGE_OUT_OF_SYNC,
+                    );
+
+                    // Then, when we receive the secret, it should be hidden.
+                    mockCrypto!.getCrossSigningStatus.mockResolvedValue({
+                        publicKeysOnDevice: true,
+                        privateKeysInSecretStorage: true,
+                        privateKeysCachedLocally: {
+                            masterKey: true,
+                            selfSigningKey: true,
+                            userSigningKey: true,
+                        },
+                    });
+
+                    mockClient.emit(ClientEvent.ToDeviceEvent, new MatrixEvent({ type: "m.secret.send" }));
+                    await flushPromises();
+                    expect(SetupEncryptionToast.hideToast).toHaveBeenCalled();
+                });
+
                 it("shows set up recovery toast when user has a key backup available", async () => {
                     // non falsy response
                     mockCrypto.getKeyBackupInfo.mockResolvedValue({} as unknown as KeyBackupInfo);