Log conversation open time

.github/workflows/benchmark.yml

@@ -114,6 +114,20 @@ jobs:
         RUN_COUNT: 100
         ELECTRON_ENABLE_STACK_DUMPING: on
 
+    - name: Run conversation open benchmarks
+      run: |
+        set -o pipefail
+        rm -rf /tmp/mock
+        xvfb-run --auto-servernum ts-node \
+          Mock-Server/scripts/convo-open-test.ts \
+          ./node_modules/.bin/electron . | tee benchmark-convo-open.log || \
+          (cat /tmp/mock/logs/{app,main}.log && exit 1)
+      timeout-minutes: 10
+      env:
+        NODE_ENV: production
+        RUN_COUNT: 100
+        ELECTRON_ENABLE_STACK_DUMPING: on
+
     - name: Clone benchmark repo
       uses: actions/checkout@v2
       with:
@@ -128,6 +142,7 @@ jobs:
         node ./bin/collect.js ../benchmark-startup.log data/startup.json
         node ./bin/collect.js ../benchmark-send.log data/send.json
         node ./bin/collect.js ../benchmark-group-send.log data/group-send.json
+        node ./bin/collect.js ../benchmark-convo-open.log data/convo-open.json
         npm run build
         git config --global user.email "no-reply@signal.org"
         git config --global user.name "Signal Bot"

ts/ConversationController.ts

@@ -119,6 +119,8 @@ export class ConversationController {
 
   private _initialPromise: undefined | Promise<void>;
 
+  private _conversationOpenStart = new Map<string, number>();
+
   constructor(private _conversations: ConversationModelCollectionType) {}
 
   get(id?: string | null): ConversationModel | undefined {
@@ -754,6 +756,20 @@ export class ConversationController {
     return this._initialPromise;
   }
 
+  onConvoOpenStart(conversationId: string): void {
+    this._conversationOpenStart.set(conversationId, Date.now());
+  }
+
+  onConvoMessageMount(conversationId: string): void {
+    const loadStart = this._conversationOpenStart.get(conversationId);
+    if (loadStart === undefined) {
+      return;
+    }
+
+    this._conversationOpenStart.delete(conversationId);
+    this.get(conversationId)?.onOpenComplete(loadStart);
+  }
+
   private async doLoad(): Promise<void> {
     log.info('ConversationController: starting initial fetch');
 

ts/components/conversation/Message.tsx

@@ -420,6 +420,9 @@ export class Message extends React.PureComponent<Props, State> {
   };
 
   public override componentDidMount(): void {
+    const { conversationId } = this.props;
+    window.ConversationController.onConvoMessageMount(conversationId);
+
     this.startSelectedTimer();
     this.startDeleteForEveryoneTimerIfApplicable();
 

ts/models/conversations.ts

@@ -1456,15 +1456,15 @@ export class ConversationModel extends window.Backbone
       //   reducer to trust the message set we just fetched for determining if we have
       //   the newest message loaded.
       const unboundedFetch = true;
-      messagesReset(
+      messagesReset({
         conversationId,
-        cleaned.map((messageModel: MessageModel) => ({
+        messages: cleaned.map((messageModel: MessageModel) => ({
           ...messageModel.attributes,
         })),
         metrics,
         scrollToMessageId,
-        unboundedFetch
-      );
+        unboundedFetch,
+      });
     } catch (error) {
       setMessagesLoading(conversationId, false);
       throw error;
@@ -1604,14 +1604,14 @@ export class ConversationModel extends window.Backbone
       const scrollToMessageId =
         options && options.disableScroll ? undefined : messageId;
 
-      messagesReset(
+      messagesReset({
         conversationId,
-        cleaned.map((messageModel: MessageModel) => ({
+        messages: cleaned.map((messageModel: MessageModel) => ({
           ...messageModel.attributes,
         })),
         metrics,
-        scrollToMessageId
-      );
+        scrollToMessageId,
+      });
     } catch (error) {
       setMessagesLoading(conversationId, false);
       throw error;
@@ -5281,6 +5281,19 @@ export class ConversationModel extends window.Backbone
     this.set('acknowledgedGroupNameCollisions', groupNameCollisions);
     window.Signal.Data.updateConversation(this.attributes);
   }
+
+  onOpenStart(): void {
+    log.info(`conversation ${this.idForLogging()} open start`);
+    window.ConversationController.onConvoOpenStart(this.id);
+  }
+
+  onOpenComplete(startedAt: number): void {
+    const now = Date.now();
+    const delta = now - startedAt;
+
+    log.info(`conversation ${this.idForLogging()} open took ${delta}ms`);
+    window.CI?.handleEvent('conversation:open', { delta });
+  }
 }
 
 window.Whisper.Conversation = ConversationModel;

ts/state/ducks/conversations.ts

@@ -1613,13 +1613,21 @@ function reviewMessageRequestNameCollision(
   return { type: 'REVIEW_MESSAGE_REQUEST_NAME_COLLISION', payload };
 }
 
-function messagesReset(
-  conversationId: string,
-  messages: Array<MessageAttributesType>,
-  metrics: MessageMetricsType,
-  scrollToMessageId?: string,
-  unboundedFetch?: boolean
-): MessagesResetActionType {
+export type MessageResetOptionsType = Readonly<{
+  conversationId: string;
+  messages: Array<MessageAttributesType>;
+  metrics: MessageMetricsType;
+  scrollToMessageId?: string;
+  unboundedFetch?: boolean;
+}>;
+
+function messagesReset({
+  conversationId,
+  messages,
+  metrics,
+  scrollToMessageId,
+  unboundedFetch,
+}: MessageResetOptionsType): MessagesResetActionType {
   return {
     type: 'MESSAGES_RESET',
     payload: {

ts/views/conversation_view.ts

@@ -1192,6 +1192,8 @@ export class ConversationView extends window.Backbone.View<ConversationModel> {
   }
 
   async onOpened(messageId: string): Promise<void> {
+    this.model.onOpenStart();
+
     if (messageId) {
       const message = await getMessageById(messageId);