[PM-9978] Add State Logging Options (#10251)

* Add `DebugOptions` to Definitions

* Respect Debug Options

* Configure DI

apps/browser/src/background/main.background.ts

@@ -482,7 +482,10 @@ export default class MainBackground {
       this.largeObjectMemoryStorageForStateProviders,
     );
 
-    this.globalStateProvider = new DefaultGlobalStateProvider(storageServiceProvider);
+    this.globalStateProvider = new DefaultGlobalStateProvider(
+      storageServiceProvider,
+      this.logService,
+    );
 
     const stateEventRegistrarService = new StateEventRegistrarService(
       this.globalStateProvider,
@@ -505,6 +508,7 @@ export default class MainBackground {
     this.singleUserStateProvider = new DefaultSingleUserStateProvider(
       storageServiceProvider,
       stateEventRegistrarService,
+      this.logService,
     );
     this.accountService = new AccountServiceImplementation(
       this.messagingService,

apps/cli/src/service-container.ts

@@ -291,7 +291,10 @@ export class ServiceContainer {
       this.memoryStorageForStateProviders,
     );
 
-    this.globalStateProvider = new DefaultGlobalStateProvider(storageServiceProvider);
+    this.globalStateProvider = new DefaultGlobalStateProvider(
+      storageServiceProvider,
+      this.logService,
+    );
 
     const stateEventRegistrarService = new StateEventRegistrarService(
       this.globalStateProvider,
@@ -308,6 +311,7 @@ export class ServiceContainer {
     this.singleUserStateProvider = new DefaultSingleUserStateProvider(
       storageServiceProvider,
       stateEventRegistrarService,
+      this.logService,
     );
 
     this.messagingService = MessageSender.EMPTY;

apps/desktop/src/main.ts

@@ -109,7 +109,10 @@ export class Main {
       this.storageService,
       this.memoryStorageForStateProviders,
     );
-    const globalStateProvider = new DefaultGlobalStateProvider(storageServiceProvider);
+    const globalStateProvider = new DefaultGlobalStateProvider(
+      storageServiceProvider,
+      this.logService,
+    );
 
     this.i18nService = new I18nMainService("en", "./locales/", globalStateProvider);
 
@@ -130,6 +133,7 @@ export class Main {
     const singleUserStateProvider = new DefaultSingleUserStateProvider(
       storageServiceProvider,
       stateEventRegistrarService,
+      this.logService,
     );
 
     const activeUserStateProvider = new DefaultActiveUserStateProvider(

libs/angular/src/services/jslib-services.module.ts

@@ -1119,7 +1119,7 @@ const safeProviders: SafeProvider[] = [
   safeProvider({
     provide: GlobalStateProvider,
     useClass: DefaultGlobalStateProvider,
-    deps: [StorageServiceProvider],
+    deps: [StorageServiceProvider, LogService],
   }),
   safeProvider({
     provide: ActiveUserStateProvider,
@@ -1129,7 +1129,7 @@ const safeProviders: SafeProvider[] = [
   safeProvider({
     provide: SingleUserStateProvider,
     useClass: DefaultSingleUserStateProvider,
-    deps: [StorageServiceProvider, StateEventRegistrarService],
+    deps: [StorageServiceProvider, StateEventRegistrarService, LogService],
   }),
   safeProvider({
     provide: DerivedStateProvider,

libs/common/src/platform/state/implementations/default-active-user-state.spec.ts

@@ -10,6 +10,7 @@ import { awaitAsync, trackEmissions } from "../../../../spec";
 import { FakeStorageService } from "../../../../spec/fake-storage.service";
 import { AccountInfo } from "../../../auth/abstractions/account.service";
 import { UserId } from "../../../types/guid";
+import { LogService } from "../../abstractions/log.service";
 import { StorageServiceProvider } from "../../services/storage-service.provider";
 import { StateDefinition } from "../state-definition";
 import { StateEventRegistrarService } from "../state-event-registrar.service";
@@ -45,6 +46,7 @@ describe("DefaultActiveUserState", () => {
   let diskStorageService: FakeStorageService;
   const storageServiceProvider = mock<StorageServiceProvider>();
   const stateEventRegistrarService = mock<StateEventRegistrarService>();
+  const logService = mock<LogService>();
   let activeAccountSubject: BehaviorSubject<{ id: UserId } & AccountInfo>;
 
   let singleUserStateProvider: DefaultSingleUserStateProvider;
@@ -58,6 +60,7 @@ describe("DefaultActiveUserState", () => {
     singleUserStateProvider = new DefaultSingleUserStateProvider(
       storageServiceProvider,
       stateEventRegistrarService,
+      logService,
     );
 
     activeAccountSubject = new BehaviorSubject<{ id: UserId } & AccountInfo>(undefined);

libs/common/src/platform/state/implementations/default-global-state.provider.ts

@@ -1,3 +1,4 @@
+import { LogService } from "../../abstractions/log.service";
 import { StorageServiceProvider } from "../../services/storage-service.provider";
 import { GlobalState } from "../global-state";
 import { GlobalStateProvider } from "../global-state.provider";
@@ -8,7 +9,10 @@ import { DefaultGlobalState } from "./default-global-state";
 export class DefaultGlobalStateProvider implements GlobalStateProvider {
   private globalStateCache: Record<string, GlobalState<unknown>> = {};
 
-  constructor(private storageServiceProvider: StorageServiceProvider) {}
+  constructor(
+    private storageServiceProvider: StorageServiceProvider,
+    private readonly logService: LogService,
+  ) {}
 
   get<T>(keyDefinition: KeyDefinition<T>): GlobalState<T> {
     const [location, storageService] = this.storageServiceProvider.get(
@@ -23,7 +27,11 @@ export class DefaultGlobalStateProvider implements GlobalStateProvider {
       return existingGlobalState as DefaultGlobalState<T>;
     }
 
-    const newGlobalState = new DefaultGlobalState<T>(keyDefinition, storageService);
+    const newGlobalState = new DefaultGlobalState<T>(
+      keyDefinition,
+      storageService,
+      this.logService,
+    );
 
     this.globalStateCache[cacheKey] = newGlobalState;
     return newGlobalState;

libs/common/src/platform/state/implementations/default-global-state.spec.ts

@@ -3,11 +3,13 @@
  * @jest-environment ../shared/test.environment.ts
  */
 
+import { mock } from "jest-mock-extended";
 import { firstValueFrom, of } from "rxjs";
 import { Jsonify } from "type-fest";
 
 import { trackEmissions, awaitAsync } from "../../../../spec";
 import { FakeStorageService } from "../../../../spec/fake-storage.service";
+import { LogService } from "../../abstractions/log.service";
 import { KeyDefinition, globalKeyBuilder } from "../key-definition";
 import { StateDefinition } from "../state-definition";
 
@@ -38,11 +40,12 @@ const globalKey = globalKeyBuilder(testKeyDefinition);
 describe("DefaultGlobalState", () => {
   let diskStorageService: FakeStorageService;
   let globalState: DefaultGlobalState<TestState>;
+  const logService = mock<LogService>();
   const newData = { date: new Date() };
 
   beforeEach(() => {
     diskStorageService = new FakeStorageService();
-    globalState = new DefaultGlobalState(testKeyDefinition, diskStorageService);
+    globalState = new DefaultGlobalState(testKeyDefinition, diskStorageService, logService);
   });
 
   afterEach(() => {

libs/common/src/platform/state/implementations/default-global-state.ts

@@ -1,3 +1,4 @@
+import { LogService } from "../../abstractions/log.service";
 import {
   AbstractStorageService,
   ObservableStorageService,
@@ -14,7 +15,8 @@ export class DefaultGlobalState<T>
   constructor(
     keyDefinition: KeyDefinition<T>,
     chosenLocation: AbstractStorageService & ObservableStorageService,
+    logService: LogService,
   ) {
-    super(globalKeyBuilder(keyDefinition), chosenLocation, keyDefinition);
+    super(globalKeyBuilder(keyDefinition), chosenLocation, keyDefinition, logService);
   }
 }

libs/common/src/platform/state/implementations/default-single-user-state.provider.ts

@@ -1,4 +1,5 @@
 import { UserId } from "../../../types/guid";
+import { LogService } from "../../abstractions/log.service";
 import { StorageServiceProvider } from "../../services/storage-service.provider";
 import { StateEventRegistrarService } from "../state-event-registrar.service";
 import { UserKeyDefinition } from "../user-key-definition";
@@ -13,6 +14,7 @@ export class DefaultSingleUserStateProvider implements SingleUserStateProvider {
   constructor(
     private readonly storageServiceProvider: StorageServiceProvider,
     private readonly stateEventRegistrarService: StateEventRegistrarService,
+    private readonly logService: LogService,
   ) {}
 
   get<T>(userId: UserId, keyDefinition: UserKeyDefinition<T>): SingleUserState<T> {
@@ -33,6 +35,7 @@ export class DefaultSingleUserStateProvider implements SingleUserStateProvider {
       keyDefinition,
       storageService,
       this.stateEventRegistrarService,
+      this.logService,
     );
     this.cache[cacheKey] = newUserState;
     return newUserState;

libs/common/src/platform/state/implementations/default-single-user-state.spec.ts

@@ -10,6 +10,7 @@ import { Jsonify } from "type-fest";
 import { trackEmissions, awaitAsync } from "../../../../spec";
 import { FakeStorageService } from "../../../../spec/fake-storage.service";
 import { UserId } from "../../../types/guid";
+import { LogService } from "../../abstractions/log.service";
 import { Utils } from "../../misc/utils";
 import { StateDefinition } from "../state-definition";
 import { StateEventRegistrarService } from "../state-event-registrar.service";
@@ -45,6 +46,7 @@ describe("DefaultSingleUserState", () => {
   let diskStorageService: FakeStorageService;
   let userState: DefaultSingleUserState<TestState>;
   const stateEventRegistrarService = mock<StateEventRegistrarService>();
+  const logService = mock<LogService>();
   const newData = { date: new Date() };
 
   beforeEach(() => {
@@ -54,6 +56,7 @@ describe("DefaultSingleUserState", () => {
       testKeyDefinition,
       diskStorageService,
       stateEventRegistrarService,
+      logService,
     );
   });
 
@@ -108,15 +111,23 @@ describe("DefaultSingleUserState", () => {
           cleanupDelayMs: 0,
           deserializer: TestState.fromJSON,
           clearOn: [],
+          debug: {
+            enableRetrievalLogging: true,
+          },
         }),
         diskStorageService,
         stateEventRegistrarService,
+        logService,
       );
 
       await firstValueFrom(state.state$);
       await firstValueFrom(state.state$);
 
       expect(diskStorageService.mock.get).toHaveBeenCalledTimes(2);
+      expect(logService.info).toHaveBeenCalledTimes(2);
+      expect(logService.info).toHaveBeenCalledWith(
+        `Retrieving 'user_${userId}_fake_test' from storage, value is null`,
+      );
     });
   });
 
@@ -324,6 +335,57 @@ describe("DefaultSingleUserState", () => {
         expect(stateEventRegistrarService.registerEvents).not.toHaveBeenCalled();
       },
     );
+
+    const logCases: { startingValue: TestState; updateValue: TestState; phrase: string }[] = [
+      {
+        startingValue: null,
+        updateValue: null,
+        phrase: "null to null",
+      },
+      {
+        startingValue: null,
+        updateValue: new TestState(),
+        phrase: "null to non-null",
+      },
+      {
+        startingValue: new TestState(),
+        updateValue: null,
+        phrase: "non-null to null",
+      },
+      {
+        startingValue: new TestState(),
+        updateValue: new TestState(),
+        phrase: "non-null to non-null",
+      },
+    ];
+
+    it.each(logCases)(
+      "should log meta info about the update",
+      async ({ startingValue, updateValue, phrase }) => {
+        diskStorageService.internalUpdateStore({
+          [`user_${userId}_fake_fake`]: startingValue,
+        });
+        const state = new DefaultSingleUserState(
+          userId,
+          new UserKeyDefinition<TestState>(testStateDefinition, "fake", {
+            deserializer: TestState.fromJSON,
+            clearOn: [],
+            debug: {
+              enableUpdateLogging: true,
+            },
+          }),
+          diskStorageService,
+          stateEventRegistrarService,
+          logService,
+        );
+
+        await state.update(() => updateValue);
+
+        expect(logService.info).toHaveBeenCalledWith(
+          `Updating 'user_${userId}_fake_fake' from ${phrase}`,
+        );
+      },
+    );
   });
 
   describe("update races", () => {

libs/common/src/platform/state/implementations/default-single-user-state.ts

@@ -1,6 +1,7 @@
 import { Observable, combineLatest, of } from "rxjs";
 
 import { UserId } from "../../../types/guid";
+import { LogService } from "../../abstractions/log.service";
 import {
   AbstractStorageService,
   ObservableStorageService,
@@ -22,8 +23,9 @@ export class DefaultSingleUserState<T>
     keyDefinition: UserKeyDefinition<T>,
     chosenLocation: AbstractStorageService & ObservableStorageService,
     private stateEventRegistrarService: StateEventRegistrarService,
+    logService: LogService,
   ) {
-    super(keyDefinition.buildKey(userId), chosenLocation, keyDefinition);
+    super(keyDefinition.buildKey(userId), chosenLocation, keyDefinition, logService);
     this.combinedState$ = combineLatest([of(userId), this.state$]);
   }
 

libs/common/src/platform/state/implementations/specific-state.provider.spec.ts

@@ -3,6 +3,7 @@ import { mock } from "jest-mock-extended";
 import { mockAccountServiceWith } from "../../../../spec/fake-account-service";
 import { FakeStorageService } from "../../../../spec/fake-storage.service";
 import { UserId } from "../../../types/guid";
+import { LogService } from "../../abstractions/log.service";
 import { StorageServiceProvider } from "../../services/storage-service.provider";
 import { KeyDefinition } from "../key-definition";
 import { StateDefinition } from "../state-definition";
@@ -19,6 +20,7 @@ import { DefaultSingleUserStateProvider } from "./default-single-user-state.prov
 describe("Specific State Providers", () => {
   const storageServiceProvider = mock<StorageServiceProvider>();
   const stateEventRegistrarService = mock<StateEventRegistrarService>();
+  const logService = mock<LogService>();
 
   let singleSut: DefaultSingleUserStateProvider;
   let activeSut: DefaultActiveUserStateProvider;
@@ -34,9 +36,10 @@ describe("Specific State Providers", () => {
     singleSut = new DefaultSingleUserStateProvider(
       storageServiceProvider,
       stateEventRegistrarService,
+      logService,
     );
     activeSut = new DefaultActiveUserStateProvider(mockAccountServiceWith(null), singleSut);
-    globalSut = new DefaultGlobalStateProvider(storageServiceProvider);
+    globalSut = new DefaultGlobalStateProvider(storageServiceProvider, logService);
   });
 
   const fakeDiskStateDefinition = new StateDefinition("fake", "disk");

libs/common/src/platform/state/implementations/state-base.ts

@@ -7,16 +7,19 @@ import {
   merge,
   share,
   switchMap,
+  tap,
   timeout,
   timer,
 } from "rxjs";
 import { Jsonify } from "type-fest";
 
 import { StorageKey } from "../../../types/state";
+import { LogService } from "../../abstractions/log.service";
 import {
   AbstractStorageService,
   ObservableStorageService,
 } from "../../abstractions/storage.service";
+import { DebugOptions } from "../key-definition";
 import { StateUpdateOptions, populateOptionsWithDefault } from "../state-update-options";
 
 import { getStoredValue } from "./util";
@@ -25,6 +28,7 @@ import { getStoredValue } from "./util";
 type KeyDefinitionRequirements<T> = {
   deserializer: (jsonState: Jsonify<T>) => T;
   cleanupDelayMs: number;
+  debug: Required<DebugOptions>;
 };
 
 export abstract class StateBase<T, KeyDef extends KeyDefinitionRequirements<T>> {
@@ -36,6 +40,7 @@ export abstract class StateBase<T, KeyDef extends KeyDefinitionRequirements<T>>
     protected readonly key: StorageKey,
     protected readonly storageService: AbstractStorageService & ObservableStorageService,
     protected readonly keyDefinition: KeyDef,
+    protected readonly logService: LogService,
   ) {
     const storageUpdate$ = storageService.updates$.pipe(
       filter((storageUpdate) => storageUpdate.key === key),
@@ -53,6 +58,18 @@ export abstract class StateBase<T, KeyDef extends KeyDefinitionRequirements<T>>
       storageUpdate$,
     );
 
+    if (keyDefinition.debug.enableRetrievalLogging) {
+      state$ = state$.pipe(
+        tap({
+          next: (v) => {
+            this.logService.info(
+              `Retrieving '${key}' from storage, value is ${v == null ? "null" : "non-null"}`,
+            );
+          },
+        }),
+      );
+    }
+
     // If 0 cleanup is chosen, treat this as absolutely no cache
     if (keyDefinition.cleanupDelayMs !== 0) {
       state$ = state$.pipe(
@@ -104,6 +121,11 @@ export abstract class StateBase<T, KeyDef extends KeyDefinitionRequirements<T>>
   }
 
   protected async doStorageSave(newState: T, oldState: T) {
+    if (this.keyDefinition.debug.enableUpdateLogging) {
+      this.logService.info(
+        `Updating '${this.key}' from ${oldState == null ? "null" : "non-null"} to ${newState == null ? "null" : "non-null"}`,
+      );
+    }
     await this.storageService.save(this.key, newState);
   }
 

libs/common/src/platform/state/key-definition.spec.ts

@@ -1,6 +1,6 @@
 import { Opaque } from "type-fest";
 
-import { KeyDefinition } from "./key-definition";
+import { DebugOptions, KeyDefinition } from "./key-definition";
 import { StateDefinition } from "./state-definition";
 
 const fakeStateDefinition = new StateDefinition("fake", "disk");
@@ -16,6 +16,97 @@ describe("KeyDefinition", () => {
         });
       });
     });
+
+    it("normalizes debug options set to undefined", () => {
+      const keyDefinition = new KeyDefinition(fakeStateDefinition, "fake", {
+        deserializer: (v) => v,
+        debug: undefined,
+      });
+
+      expect(keyDefinition.debug.enableUpdateLogging).toBe(false);
+    });
+
+    it("normalizes no debug options", () => {
+      const keyDefinition = new KeyDefinition(fakeStateDefinition, "fake", {
+        deserializer: (v) => v,
+      });
+
+      expect(keyDefinition.debug.enableUpdateLogging).toBe(false);
+    });
+
+    const cases: {
+      debug: DebugOptions | undefined;
+      expectedEnableUpdateLogging: boolean;
+      expectedEnableRetrievalLogging: boolean;
+    }[] = [
+      {
+        debug: undefined,
+        expectedEnableUpdateLogging: false,
+        expectedEnableRetrievalLogging: false,
+      },
+      {
+        debug: {},
+        expectedEnableUpdateLogging: false,
+        expectedEnableRetrievalLogging: false,
+      },
+      {
+        debug: {
+          enableUpdateLogging: false,
+        },
+        expectedEnableUpdateLogging: false,
+        expectedEnableRetrievalLogging: false,
+      },
+      {
+        debug: {
+          enableRetrievalLogging: false,
+        },
+        expectedEnableUpdateLogging: false,
+        expectedEnableRetrievalLogging: false,
+      },
+      {
+        debug: {
+          enableUpdateLogging: true,
+        },
+        expectedEnableUpdateLogging: true,
+        expectedEnableRetrievalLogging: false,
+      },
+      {
+        debug: {
+          enableRetrievalLogging: true,
+        },
+        expectedEnableUpdateLogging: false,
+        expectedEnableRetrievalLogging: true,
+      },
+      {
+        debug: {
+          enableRetrievalLogging: false,
+          enableUpdateLogging: false,
+        },
+        expectedEnableUpdateLogging: false,
+        expectedEnableRetrievalLogging: false,
+      },
+      {
+        debug: {
+          enableRetrievalLogging: true,
+          enableUpdateLogging: true,
+        },
+        expectedEnableUpdateLogging: true,
+        expectedEnableRetrievalLogging: true,
+      },
+    ];
+
+    it.each(cases)(
+      "normalizes debug options to correct values when given $debug",
+      ({ debug, expectedEnableUpdateLogging, expectedEnableRetrievalLogging }) => {
+        const keyDefinition = new KeyDefinition(fakeStateDefinition, "fake", {
+          deserializer: (v) => v,
+          debug: debug,
+        });
+
+        expect(keyDefinition.debug.enableUpdateLogging).toBe(expectedEnableUpdateLogging);
+        expect(keyDefinition.debug.enableRetrievalLogging).toBe(expectedEnableRetrievalLogging);
+      },
+    );
   });
 
   describe("cleanupDelayMs", () => {

libs/common/src/platform/state/key-definition.ts

@@ -5,6 +5,28 @@ import { StorageKey } from "../../types/state";
 import { array, record } from "./deserialization-helpers";
 import { StateDefinition } from "./state-definition";
 
+export type DebugOptions = {
+  /**
+   * When true, logs will be written that look like the following:
+   *
+   * ```
+   * "Updating 'global_myState_myKey' from null to non-null"
+   * "Updating 'user_32265eda-62ff-4797-9ead-22214772f888_myState_myKey' from non-null to null."
+   * ```
+   *
+   * It does not include the value of the data, only whether it is null or non-null.
+   */
+  enableUpdateLogging?: boolean;
+
+  /**
+   * When true, logs will be written that look like the following everytime a value is retrieved from storage.
+   *
+   * "Retrieving 'global_myState_myKey' from storage, value is null."
+   * "Retrieving 'user_32265eda-62ff-4797-9ead-22214772f888_myState_myKey' from storage, value is non-null."
+   */
+  enableRetrievalLogging?: boolean;
+};
+
 /**
  * A set of options for customizing the behavior of a {@link KeyDefinition}
  */
@@ -24,6 +46,11 @@ export type KeyDefinitionOptions<T> = {
    * Defaults to 1000ms.
    */
   readonly cleanupDelayMs?: number;
+
+  /**
+   * Options for configuring the debugging behavior, see individual options for more info.
+   */
+  readonly debug?: DebugOptions;
 };
 
 /**
@@ -32,6 +59,8 @@ export type KeyDefinitionOptions<T> = {
  * sub-divides that domain into specific keys.
  */
 export class KeyDefinition<T> {
+  readonly debug: Required<DebugOptions>;
+
   /**
    * Creates a new instance of a KeyDefinition
    * @param stateDefinition The state definition for which this key belongs to.
@@ -55,6 +84,13 @@ export class KeyDefinition<T> {
         `'cleanupDelayMs' must be greater than or equal to 0. Value of ${options.cleanupDelayMs} passed to key ${this.errorKeyName} `,
       );
     }
+
+    // Normalize optional debug options
+    const { enableUpdateLogging = false, enableRetrievalLogging = false } = options.debug ?? {};
+    this.debug = {
+      enableUpdateLogging,
+      enableRetrievalLogging,
+    };
   }
 
   /**

libs/common/src/platform/state/user-key-definition.ts

@@ -3,7 +3,7 @@ import { StorageKey } from "../../types/state";
 import { Utils } from "../misc/utils";
 
 import { array, record } from "./deserialization-helpers";
-import { KeyDefinitionOptions } from "./key-definition";
+import { DebugOptions, KeyDefinitionOptions } from "./key-definition";
 import { StateDefinition } from "./state-definition";
 
 export type ClearEvent = "lock" | "logout";
@@ -21,6 +21,11 @@ export class UserKeyDefinition<T> {
    */
   readonly clearOn: ClearEvent[];
 
+  /**
+   * Normalized options used for debugging purposes.
+   */
+  readonly debug: Required<DebugOptions>;
+
   constructor(
     readonly stateDefinition: StateDefinition,
     readonly key: string,
@@ -38,6 +43,13 @@ export class UserKeyDefinition<T> {
 
     // Filter out repeat values
     this.clearOn = Array.from(new Set(options.clearOn));
+
+    // Normalize optional debug options
+    const { enableUpdateLogging = false, enableRetrievalLogging = false } = options.debug ?? {};
+    this.debug = {
+      enableUpdateLogging,
+      enableRetrievalLogging,
+    };
   }
 
   /**