[PM-19469] Add logs for unlock time (#13972)

* Add logs for unlock time

* Undo local flag override

* Update message

* Update messages

* Fix build on chrome

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

@@ -858,6 +858,7 @@ export default class MainBackground {
       this.configService,
       this.stateProvider,
       this.accountService,
+      this.logService,
     );
     this.folderService = new FolderService(
       this.keyService,

apps/cli/src/service-container/service-container.ts

@@ -693,6 +693,7 @@ export class ServiceContainer {
       this.configService,
       this.stateProvider,
       this.accountService,
+      this.logService,
     );
 
     this.folderService = new FolderService(

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

@@ -505,6 +505,7 @@ const safeProviders: SafeProvider[] = [
       configService: ConfigService,
       stateProvider: StateProvider,
       accountService: AccountServiceAbstraction,
+      logService: LogService,
     ) =>
       new CipherService(
         keyService,
@@ -520,6 +521,7 @@ const safeProviders: SafeProvider[] = [
         configService,
         stateProvider,
         accountService,
+        logService,
       ),
     deps: [
       KeyService,
@@ -535,6 +537,7 @@ const safeProviders: SafeProvider[] = [
       ConfigService,
       StateProvider,
       AccountServiceAbstraction,
+      LogService,
     ],
   }),
   safeProvider({

libs/auth/src/common/services/pin/pin.service.implementation.ts

@@ -224,7 +224,10 @@ export class PinService implements PinServiceAbstraction {
   }
 
   async makePinKey(pin: string, salt: string, kdfConfig: KdfConfig): Promise<PinKey> {
+    const start = Date.now();
     const pinKey = await this.keyGenerationService.deriveKeyFromPassword(pin, salt, kdfConfig);
+    this.logService.info(`[Pin Service] deriving pin key took ${Date.now() - start}ms`);
+
     return (await this.keyGenerationService.stretchKey(pinKey)) as PinKey;
   }
 

libs/common/src/services/search.service.ts

@@ -147,6 +147,7 @@ export class SearchService implements SearchServiceAbstraction {
       return;
     }
 
+    const indexingStartTime = new Date().getTime();
     await this.setIsIndexing(userId, true);
     await this.setIndexedEntityIdForSearch(userId, indexedEntityId as IndexedEntityId);
     const builder = new lunr.Builder();
@@ -187,8 +188,11 @@ export class SearchService implements SearchServiceAbstraction {
     await this.setIndexForSearch(userId, index.toJSON() as SerializedLunrIndex);
 
     await this.setIsIndexing(userId, false);
-
-    this.logService.info("Finished search indexing");
+    this.logService.info(
+      `[SearchService] Building search index of ${ciphers.length} ciphers took ${
+        new Date().getTime() - indexingStartTime
+      }ms`,
+    );
   }
 
   async searchCiphers(

libs/common/src/vault/services/cipher.service.spec.ts

@@ -1,6 +1,7 @@
 import { mock } from "jest-mock-extended";
 import { BehaviorSubject, map, of } from "rxjs";
 
+import { LogService } from "@bitwarden/common/platform/abstractions/log.service";
 import { CipherDecryptionKeys, KeyService } from "@bitwarden/key-management";
 
 import { FakeAccountService, mockAccountServiceWith } from "../../../spec/fake-account-service";
@@ -121,6 +122,7 @@ describe("Cipher Service", () => {
   const bulkEncryptService = mock<BulkEncryptService>();
   const configService = mock<ConfigService>();
   accountService = mockAccountServiceWith(mockUserId);
+  const logService = mock<LogService>();
   const stateProvider = new FakeStateProvider(accountService);
 
   const userId = "TestUserId" as UserId;
@@ -148,6 +150,7 @@ describe("Cipher Service", () => {
       configService,
       stateProvider,
       accountService,
+      logService,
     );
 
     cipherObj = new Cipher(cipherData);

libs/common/src/vault/services/cipher.service.ts

@@ -14,6 +14,7 @@ import {
 } from "rxjs";
 import { SemVer } from "semver";
 
+import { LogService } from "@bitwarden/common/platform/abstractions/log.service";
 import { KeyService } from "@bitwarden/key-management";
 
 import { ApiService } from "../../abstractions/api.service";
@@ -110,6 +111,7 @@ export class CipherService implements CipherServiceAbstraction {
     private configService: ConfigService,
     private stateProvider: StateProvider,
     private accountService: AccountService,
+    private logService: LogService,
   ) {}
 
   localData$(userId: UserId): Observable<Record<CipherId, LocalData>> {
@@ -445,6 +447,7 @@ export class CipherService implements CipherServiceAbstraction {
       {} as Record<string, Cipher[]>,
     );
 
+    const decryptStartTime = new Date().getTime();
     const allCipherViews = (
       await Promise.all(
         Object.entries(grouped).map(async ([orgId, groupedCiphers]) => {
@@ -464,6 +467,9 @@ export class CipherService implements CipherServiceAbstraction {
     )
       .flat()
       .sort(this.getLocaleSortingFunction());
+    this.logService.info(
+      `[CipherService] Decrypting ${allCipherViews.length} ciphers took ${new Date().getTime() - decryptStartTime}ms`,
+    );
 
     // Split ciphers into two arrays, one for successfully decrypted ciphers and one for ciphers that failed to decrypt
     return allCipherViews.reduce(

libs/key-management-ui/src/lock/components/lock.component.ts

@@ -607,9 +607,17 @@ export class LockComponent implements OnInit, OnDestroy {
     }
 
     // Vault can be de-synced since notifications get ignored while locked. Need to check whether sync is required using the sync service.
+    const startSync = new Date().getTime();
+    // TODO: This should probably not be blocking
     await this.syncService.fullSync(false);
+    this.logService.info(`[LockComponent] Sync took ${new Date().getTime() - startSync}ms`);
 
+    const startRegeneration = new Date().getTime();
+    // TODO: This should probably not be blocking
     await this.userAsymmetricKeysRegenerationService.regenerateIfNeeded(this.activeAccount.id);
+    this.logService.info(
+      `[LockComponent] Private key regeneration took ${new Date().getTime() - startRegeneration}ms`,
+    );
 
     if (this.clientType === "browser") {
       const previousUrl = this.lockComponentService.getPreviousUrl();

libs/key-management/src/key.service.ts

@@ -306,11 +306,16 @@ export class DefaultKeyService implements KeyServiceAbstraction {
    * TODO: Move to MasterPasswordService
    */
   async makeMasterKey(password: string, email: string, KdfConfig: KdfConfig): Promise<MasterKey> {
-    return (await this.keyGenerationService.deriveKeyFromPassword(
+    const start = new Date().getTime();
+    const masterKey = (await this.keyGenerationService.deriveKeyFromPassword(
       password,
       email,
       KdfConfig,
     )) as MasterKey;
+    const end = new Date().getTime();
+    this.logService.info(`[KeyService] Deriving master key took ${end - start}ms`);
+
+    return masterKey;
   }
 
   async encryptUserKeyWithMasterKey(