Log query stats during backup import

app/main.ts

@@ -1066,6 +1066,14 @@ ipc.on('show-window', () => {
   showWindow();
 });
 
+ipc.on('start-tracking-query-stats', () => {
+  sql.startTrackingQueryStats();
+});
+
+ipc.on('stop-tracking-query-stats', (_event, options) => {
+  sql.stopTrackingQueryStats(options);
+});
+
 ipc.on('title-bar-double-click', () => {
   if (!mainWindow) {
     return;
@@ -2109,7 +2117,7 @@ app.on('ready', async () => {
     innerLogger.info('Processed count:', processedCount);
     innerLogger.info('Messages per second:', messagesPerSec);
 
-    sql.stopTrackingQueryStats();
+    sql.stopTrackingQueryStats({ epochName: 'App Load' });
 
     event.sender.send('ci:event', 'app-loaded', {
       loadTime,

ts/services/backups/index.ts

@@ -268,6 +268,8 @@ export class BackupsService {
   ): Promise<void> {
     strictAssert(!this.isRunning, 'BackupService is already running');
 
+    window.IPC.startTrackingQueryStats();
+
     log.info(`importBackup: starting ${backupType}...`);
     this.isRunning = true;
 
@@ -354,7 +356,7 @@ export class BackupsService {
       throw error;
     } finally {
       this.isRunning = false;
-
+      window.IPC.stopTrackingQueryStats({ epochName: 'Backup Import' });
       if (window.SignalCI) {
         window.SignalCI.handleEvent('backupImportComplete', null);
       }

ts/sql/main.ts

@@ -110,6 +110,11 @@ type QueryStatsType = {
   max: number;
 };
 
+export type QueryStatsOptions = {
+  maxQueriesToLog?: number;
+  epochName?: string;
+};
+
 export class MainSQL {
   private readonly pool = new Array<PoolEntry>();
 
@@ -302,15 +307,16 @@ export class MainSQL {
 
   public startTrackingQueryStats(): void {
     if (this.shouldTrackQueryStats) {
-      this.logQueryStats();
+      this.logQueryStats({});
+      this.logger?.info('Resetting query stats');
     }
     this.resetQueryStats();
     this.shouldTrackQueryStats = true;
   }
 
-  public stopTrackingQueryStats(): void {
+  public stopTrackingQueryStats(options: QueryStatsOptions): void {
     if (this.shouldTrackQueryStats) {
-      this.logQueryStats();
+      this.logQueryStats(options);
     }
     this.queryStats = undefined;
     this.shouldTrackQueryStats = false;
@@ -391,18 +397,26 @@ export class MainSQL {
     return Math.round(100 * duration) / 100;
   }
 
-  private logQueryStats(numberToLog: number = 10) {
+  private logQueryStats({
+    maxQueriesToLog = 10,
+    epochName,
+  }: QueryStatsOptions) {
     if (!this.queryStats) {
       return;
     }
-    const duration = Date.now() - this.queryStats.start;
+    const epochDuration = Date.now() - this.queryStats.start;
     const sortedByCumulativeDuration = [
       ...this.queryStats.statsByQuery.values(),
     ].sort((a, b) => (b.cumulative ?? 0) - (a.cumulative ?? 0));
+    const cumulativeDuration = sortedByCumulativeDuration.reduce(
+      (sum, stats) => sum + stats.cumulative,
+      0
+    );
     this.logger?.info(
-      `Top ${numberToLog} queries by cumulative duration (ms) over last ${duration}ms: ` +
+      `Top ${maxQueriesToLog} queries by cumulative duration (ms) over last ${epochDuration}ms` +
+        `${epochName ? ` during '${epochName}'` : ''}: ` +
         `${sortedByCumulativeDuration
-          .slice(0, numberToLog)
+          .slice(0, maxQueriesToLog)
           .map(stats => {
             return (
               `${stats.queryName}: cumulative ${this.roundDuration(stats.cumulative)} | ` +
@@ -411,7 +425,8 @@ export class MainSQL {
               `count: ${stats.count}`
             );
           })
-          .join(' ||| ')}`
+          .join(' ||| ')}` +
+        `; Total cumulative duration of all SQL queries during this epoch: ${this.roundDuration(cumulativeDuration)}ms`
     );
   }
 

ts/window.d.ts

@@ -52,6 +52,7 @@ import type { initializeMigrations } from './signal';
 import type { RetryPlaceholders } from './util/retryPlaceholders';
 import type { PropsPreloadType as PreferencesPropsType } from './components/Preferences';
 import type { WindowsNotificationData } from './services/notifications';
+import type { QueryStatsOptions } from './sql/main';
 
 export { Long } from 'long';
 
@@ -87,6 +88,8 @@ export type IPCType = {
   showWindow: () => void;
   showWindowsNotification: (data: WindowsNotificationData) => Promise<void>;
   shutdown: () => void;
+  startTrackingQueryStats: () => void;
+  stopTrackingQueryStats: (options?: QueryStatsOptions) => void;
   titleBarDoubleClick: () => void;
   updateTrayIcon: (count: number) => void;
 };

ts/windows/main/phase1-ipc.ts

@@ -126,6 +126,12 @@ const IPC: IPCType = {
     log.info('shutdown');
     ipc.send('shutdown');
   },
+  startTrackingQueryStats: () => {
+    ipc.send('start-tracking-query-stats');
+  },
+  stopTrackingQueryStats: options => {
+    ipc.send('stop-tracking-query-stats', options);
+  },
   titleBarDoubleClick: () => {
     ipc.send('title-bar-double-click');
   },