From b4e165ed6e157ac536af5f43b9d4aa8d054f9451 Mon Sep 17 00:00:00 2001 From: Richard van der Hoff Date: Mon, 10 Feb 2025 21:22:05 +0000 Subject: [PATCH] Log when we show, and hide, encryption setup toasts It's currently hard to debug when someone sees or hides one of these toasts. Lets's add some logging. --- src/DeviceListener.ts | 10 ++++++++-- src/stores/ToastStore.ts | 4 ++++ test/unit-tests/DeviceListener-test.ts | 21 +++++++++++++-------- 3 files changed, 25 insertions(+), 10 deletions(-) diff --git a/src/DeviceListener.ts b/src/DeviceListener.ts index d4d40a9124e..b779952a861 100644 --- a/src/DeviceListener.ts +++ b/src/DeviceListener.ts @@ -15,7 +15,7 @@ import { type SyncState, ClientStoppedError, } from "matrix-js-sdk/src/matrix"; -import { logger } from "matrix-js-sdk/src/logger"; +import { logger as baseLogger } 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"; @@ -48,6 +48,8 @@ import { asyncSomeParallel } from "./utils/arrays.ts"; const KEY_BACKUP_POLL_INTERVAL = 5 * 60 * 1000; +const logger = baseLogger.getChild("DeviceListener:"); + export default class DeviceListener { private dispatcherRef?: string; // device IDs for which the user has dismissed the verify toast ('Later') @@ -131,7 +133,7 @@ export default class DeviceListener { * @param {String[]} deviceIds List of device IDs to dismiss notifications for */ public async dismissUnverifiedSessions(deviceIds: Iterable): Promise { - logger.log("Dismissing unverified sessions: " + Array.from(deviceIds).join(",")); + logger.debug("Dismissing unverified sessions: " + Array.from(deviceIds).join(",")); for (const d of deviceIds) { this.dismissed.add(d); } @@ -309,16 +311,20 @@ 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"); 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"); 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"); 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 + logger.info("No default 4S key: showing SET_UP_RECOVERY toast"); showSetupEncryptionToast(SetupKind.SET_UP_RECOVERY); } else { // some other condition... yikes! Show the 'set up encryption' toast: this is what we previously did diff --git a/src/stores/ToastStore.ts b/src/stores/ToastStore.ts index 8fe1fa82469..7cb9d60925b 100644 --- a/src/stores/ToastStore.ts +++ b/src/stores/ToastStore.ts @@ -7,6 +7,7 @@ Please see LICENSE files in the repository root for full details. */ import EventEmitter from "events"; +import { logger } from "matrix-js-sdk/src/logger"; import type React from "react"; import { type ComponentClass } from "../@types/common"; @@ -54,10 +55,12 @@ export default class ToastStore extends EventEmitter { public addOrReplaceToast(newToast: IToast): void { const oldIndex = this.toasts.findIndex((t) => t.key === newToast.key); if (oldIndex === -1) { + logger.info(`Opening toast with key '${newToast.key}': title '${newToast.title}'`); let newIndex = this.toasts.length; while (newIndex > 0 && this.toasts[newIndex - 1].priority < newToast.priority) --newIndex; this.toasts.splice(newIndex, 0, newToast); } else { + logger.info(`Replacing existing toast with key '${newToast.key}': title now '${newToast.title}'`); this.toasts[oldIndex] = newToast; } this.emit("update"); @@ -71,6 +74,7 @@ export default class ToastStore extends EventEmitter { const length = this.toasts.length; this.toasts = this.toasts.filter((t) => t.key !== key); if (length !== this.toasts.length) { + logger.info(`Removed toast with key '${key}'`); if (this.toasts.length === 0) { this.countSeen = 0; } diff --git a/test/unit-tests/DeviceListener-test.ts b/test/unit-tests/DeviceListener-test.ts index 635e252759a..0bb6fc00c0f 100644 --- a/test/unit-tests/DeviceListener-test.ts +++ b/test/unit-tests/DeviceListener-test.ts @@ -8,7 +8,6 @@ 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 { logger } from "matrix-js-sdk/src/logger"; import { CryptoEvent, type CrossSigningStatus, @@ -33,9 +32,6 @@ import { UIFeature } from "../../src/settings/UIFeature"; import { isBulkUnverifiedDeviceReminderSnoozed } from "../../src/utils/device/snoozeBulkUnverifiedDeviceReminder"; import { PosthogAnalytics } from "../../src/PosthogAnalytics"; -// don't litter test console with logs -jest.mock("matrix-js-sdk/src/logger"); - jest.mock("../../src/dispatcher/dispatcher", () => ({ dispatch: jest.fn(), register: jest.fn(), @@ -63,6 +59,12 @@ describe("DeviceListener", () => { beforeEach(() => { jest.resetAllMocks(); + // don't litter the console with logs + jest.spyOn(console, "debug").mockImplementation(() => {}); + jest.spyOn(console, "info").mockImplementation(() => {}); + jest.spyOn(console, "warn").mockImplementation(() => {}); + jest.spyOn(console, "error").mockImplementation(() => {}); + // spy on various toasts' hide and show functions // easier than mocking jest.spyOn(SetupEncryptionToast, "showToast").mockReturnValue(undefined); @@ -158,14 +160,17 @@ describe("DeviceListener", () => { }); it("catches error and logs when saving client information fails", async () => { - const errorLogSpy = jest.spyOn(logger, "error"); const error = new Error("oups"); mockClient!.setAccountData.mockRejectedValue(error); // doesn't throw await createAndStart(); - expect(errorLogSpy).toHaveBeenCalledWith("Failed to update client information", error); + expect(console.error).toHaveBeenCalledWith( + "DeviceListener:", + "Failed to update client information", + error, + ); }); it("saves client information on logged in action", async () => { @@ -275,14 +280,14 @@ describe("DeviceListener", () => { throw new ClientStoppedError(); }); await createAndStart(); - expect(logger.error).not.toHaveBeenCalled(); + expect(console.error).not.toHaveBeenCalled(); }); it("correctly handles other errors", async () => { mockCrypto!.isCrossSigningReady.mockImplementation(() => { throw new Error("blah"); }); await createAndStart(); - expect(logger.error).toHaveBeenCalledTimes(1); + expect(console.error).toHaveBeenCalledTimes(1); }); describe("set up encryption", () => {