setProfileKey: Introduce 'reason' parameter for improved logging

Co-authored-by: Scott Nonnenberg <scott@signal.org>

ts/ConversationController.ts

@@ -1142,7 +1142,9 @@ export class ConversationController {
         const profileKey = obsolete.get('profileKey');
 
         if (profileKey) {
-          await current.setProfileKey(profileKey);
+          await current.setProfileKey(profileKey, {
+            reason: 'doCombineConversations ',
+          });
         }
       }
 

ts/background.ts

@@ -1744,7 +1744,9 @@ export async function startApp(): Promise<void> {
       if (firstRun && profileKey) {
         const me = window.ConversationController.getOurConversation();
         strictAssert(me !== undefined, "Didn't find newly created ourselves");
-        await me.setProfileKey(Bytes.toBase64(profileKey));
+        await me.setProfileKey(Bytes.toBase64(profileKey), {
+          reason: 'connect/firstRun',
+        });
       }
 
       if (isBackupEnabled()) {
@@ -2290,7 +2292,9 @@ export async function startApp(): Promise<void> {
 
     if (sender) {
       // Will do the save for us
-      await sender.setProfileKey(profileKey);
+      await sender.setProfileKey(profileKey, {
+        reason: 'handleMessageReceivedProfileUpdate',
+      });
     }
 
     return confirm();
@@ -2572,13 +2576,9 @@ export async function startApp(): Promise<void> {
       return;
     }
 
-    log.info(
+    const hasChanged = await conversation.setProfileKey(data.profileKey, {
-      `${logId}: updating profileKey for ${idForLogging}`,
+      reason: `onProfileKey/${reason}`,
-      data.sourceAci,
+    });
-      data.source
-    );
-
-    const hasChanged = await conversation.setProfileKey(data.profileKey);
 
     if (hasChanged) {
       drop(conversation.getProfiles());
@@ -2615,7 +2615,9 @@ export async function startApp(): Promise<void> {
     );
 
     // Will do the save for us if needed
-    await me.setProfileKey(profileKey);
+    await me.setProfileKey(profileKey, {
+      reason: 'handleMessageSentProfileUpdate',
+    });
 
     return confirm();
   }

ts/groups.ts

@@ -3191,7 +3191,7 @@ async function updateGroup(
       contact.get('profileKey') !== profileKey
     ) {
       contactsWithoutProfileKey.push(contact);
-      drop(contact.setProfileKey(profileKey));
+      drop(contact.setProfileKey(profileKey, { reason: 'updateGroup' }));
     }
   }
 

ts/models/conversations.ts

@@ -4913,8 +4913,12 @@ export class ConversationModel extends window.Backbone
 
   async setProfileKey(
     profileKey: string | undefined,
-    { viaStorageServiceSync = false } = {}
+    {
+      viaStorageServiceSync = false,
+      reason,
+    }: { viaStorageServiceSync?: boolean; reason: string }
   ): Promise<boolean> {
+    const logId = `setProfileKey(${this.idForLogging()}/${reason})`;
     const oldProfileKey = this.get('profileKey');
 
     // profileKey is a string so we can compare it directly
@@ -4922,9 +4926,7 @@ export class ConversationModel extends window.Backbone
       return false;
     }
 
-    log.info(
+    log.info(`${logId}: Profile key changed. Setting sealedSender to UNKNOWN`);
-      `Setting sealedSender to UNKNOWN for conversation ${this.idForLogging()}`
-    );
     this.set({
       profileKeyCredential: null,
       profileKeyCredentialExpiration: null,
@@ -4935,10 +4937,7 @@ export class ConversationModel extends window.Backbone
     // We messaged the contact when it had either phone number or username
     // title.
     if (this.get('needsTitleTransition')) {
-      log.info(
+      log.info(`${logId}: adding a title transition notification`);
-        `setProfileKey(${this.idForLogging()}): adding a ` +
-          'title transition notification'
-      );
 
       const { type, e164, username } = this.attributes;
 
@@ -5040,7 +5039,7 @@ export class ConversationModel extends window.Backbone
         'deriveProfileKeyVersion: Failed to derive profile key version, ' +
           'clearing profile key.'
       );
-      void this.setProfileKey(undefined);
+      void this.setProfileKey(undefined, { reason: 'deriveProfileKeyVersion' });
       return;
     }
 

ts/models/messages.ts

@@ -2008,14 +2008,22 @@ export class MessageModel extends window.Backbone.Model<MessageAttributesType> {
             ) {
               conversation.set({ profileSharing: true });
             } else if (isDirectConversation(conversation.attributes)) {
-              void conversation.setProfileKey(profileKey);
+              drop(
+                conversation.setProfileKey(profileKey, {
+                  reason: 'handleDataMessage',
+                })
+              );
             } else {
               const local = window.ConversationController.lookupOrCreate({
                 e164: source,
                 serviceId: sourceServiceId,
                 reason: 'handleDataMessage:setProfileKey',
               });
-              void local?.setProfileKey(profileKey);
+              drop(
+                local?.setProfileKey(profileKey, {
+                  reason: 'handleDataMessage',
+                })
+              );
             }
           }
 

ts/services/profiles.ts

@@ -329,7 +329,12 @@ async function doGetProfile(c: ConversationModel): Promise<void> {
             throw error;
           }
 
-          await c.setProfileKey(undefined);
+          log.warn(
+            `getProfile: Got 401/403 when using accessKey for ${idForLogging}, removing profileKey`
+          );
+          await c.setProfileKey(undefined, {
+            reason: 'doGetProfile/accessKey/401+403',
+          });
 
           // Retry fetch using last known profileKeyVersion or fetch
           // unversioned profile.
@@ -555,7 +560,9 @@ async function doGetProfile(c: ConversationModel): Promise<void> {
             `getProfile: Got 401/403 when using accessKey for ${idForLogging}, removing profileKey`
           );
           if (!isMe(c.attributes)) {
-            await c.setProfileKey(undefined);
+            await c.setProfileKey(undefined, {
+              reason: 'doGetProfile/accessKey/401+403',
+            });
           }
         }
         if (c.get('sealedSender') === SEALED_SENDER.UNKNOWN) {

ts/services/storageRecordOps.ts

@@ -1137,7 +1137,7 @@ export async function mergeContactRecord(
   if (contactRecord.profileKey && contactRecord.profileKey.length > 0) {
     needsProfileFetch = await conversation.setProfileKey(
       Bytes.toBase64(contactRecord.profileKey),
-      { viaStorageServiceSync: true }
+      { viaStorageServiceSync: true, reason: 'mergeContactRecord' }
     );
   }
 
@@ -1660,7 +1660,7 @@ export async function mergeAccountRecord(
   if (profileKey && profileKey.length > 0) {
     needsProfileFetch = await conversation.setProfileKey(
       Bytes.toBase64(profileKey),
-      { viaStorageServiceSync: true }
+      { viaStorageServiceSync: true, reason: 'mergeAccountRecord' }
     );
 
     const avatarUrl = dropNull(accountRecord.avatarUrl);

ts/util/handleMessageSend.ts

@@ -115,7 +115,9 @@ function processError(error: unknown): void {
           `handleMessageSend: Got 401/403 for ${conversation.idForLogging()}, removing profile key`
         );
 
-        void conversation.setProfileKey(undefined);
+        void conversation.setProfileKey(undefined, {
+          reason: 'handleMessageSend/processError',
+        });
       }
       if (conversation.get('sealedSender') === SEALED_SENDER.UNKNOWN) {
         log.warn(