feat: Add more chokidar watcher perf measures

core/local/chokidar/analysis.js

@@ -101,6 +101,10 @@ class LocalChangeMap {
   }
 
   put(c /*: LocalChange */, updated /*: ?boolean */) {
+    const stopMeasure = measureTime(
+      `LocalWatcher::LocalChangeMap#put(${updated ? 'updated' : 'new'})`
+    )
+
     if (updated) {
       for (const [k, v] of this.changesByPath) {
         if (v == c) {
@@ -112,12 +116,16 @@ class LocalChangeMap {
     this.changesByPath.set(c.path.normalize(), c)
     if (typeof c.ino === 'number') this.changesByInode.set(c.ino, c)
     else this.changes.push(c)
+
+    stopMeasure()
   }
 
   flush() /*: LocalChange[] */ {
+    const stopMeasure = measureTime(`LocalWatcher::LocalChangeMap#flush`)
     const changes = this.changes
     for (let a of this.changesByInode.values()) changes.push(a)
     this._clear()
+    stopMeasure()
     return changes
   }
 }
@@ -264,6 +272,7 @@ function analyseEvent(
 
 function fixUnsyncedMoves(changes /*: LocalChange[] */) {
   log.trace('Transform unsynced moves into additions...')
+  const stopMeasure = measureTime('LocalWatcher#fixUnsyncedMoves')
   changes.forEach(change => {
     if (change.type === 'FileMove' && !change.old) {
       // $FlowFixMe deliberate type change
@@ -286,6 +295,7 @@ function fixUnsyncedMoves(changes /*: LocalChange[] */) {
       })
     }
   })
+  stopMeasure()
 }
 
 /** First sort to make moves squashing easier.
@@ -383,6 +393,7 @@ function separatePendingChanges(
   pendingChanges /*: LocalChange[] */
 ) /*: LocalChange[] */ {
   log.trace('Reserve changes in progress for next flush...')
+  const stopMeasure = measureTime('LocalWatcher#separatePendingChanges')
 
   for (let i = 0; i < changes.length; i++) {
     const change = changes[i]
@@ -404,10 +415,12 @@ function separatePendingChanges(
     } else {
       log.debug(`Identified ${changes.length} change(s).`)
       log.debug(`${pendingChanges.length} of them are still pending.`)
+      stopMeasure()
       return changes.slice(i)
     }
   }
   // All actions are WIP
+  stopMeasure()
   return []
 }
 

core/local/chokidar/watcher.js

@@ -32,6 +32,7 @@ const sendToPrep = require('./send_to_prep')
 const stater = require('../stater')
 const syncDir = require('../sync_dir')
 const { logger } = require('../../utils/logger')
+const measureTime = require('../../utils/perfs')
 
 const { LOCAL_WATCHER_FATAL_EVENT } = require('../constants')
 
@@ -127,6 +128,9 @@ class LocalWatcher {
 
     this.resetInitialScanParams()
 
+    const stopChokidarScanMeasure = measureTime('LocalWatcher#chokidarScan')
+    const stopInitialScanMeasure = measureTime('LocalWatcher#initialScan')
+
     this.watcher = chokidar.watch('.', {
       // Let paths in events be relative to this base path
       cwd: this.syncPath,
@@ -152,7 +156,10 @@ class LocalWatcher {
     })
 
     const started = new Promise(resolve => {
-      this.initialScanParams.resolve = resolve
+      this.initialScanParams.resolve = () => {
+        stopInitialScanMeasure()
+        resolve()
+      }
 
       for (let eventType of [
         'add',
@@ -180,7 +187,10 @@ class LocalWatcher {
       }
 
       this.watcher
-        .on('ready', () => this.buffer.switchMode('timeout'))
+        .on('ready', () => {
+          stopChokidarScanMeasure()
+          this.buffer.switchMode('timeout')
+        })
         .on('raw', async (event, path, details) => {
           log.chokidar.debug('raw', { event, path, details })
 
@@ -234,25 +244,33 @@ class LocalWatcher {
     }
 
     log.trace('Prepare events...')
+    const stopPrepareEventsMeasure = measureTime('LocalWatcher#prepareEvents')
     const preparedEvents /*: LocalEvent[] */ = await prepareEvents.step(
       events,
       this
     )
+    stopPrepareEventsMeasure()
     log.trace('Done with events preparation.')
 
+    const stopAnalysisMeasure = measureTime('LocalWatcher#analysis')
     const changes /*: LocalChange[] */ = analysis(preparedEvents, this)
+    stopAnalysisMeasure()
 
+    const stopNormalizePathsMeasure = measureTime('LocalWatcher#normalizePaths')
     const normalizedChanges /*: LocalChange[] */ = await normalizePaths.step(
       changes,
       this
     )
+    stopNormalizePathsMeasure()
 
     // TODO: Don't even acquire lock changes list is empty
     // FIXME: Shouldn't we acquire the lock before preparing the events?
     const release = await this.pouch.lock(this)
     let target = -1
     try {
+      const stopPrepAndMergeMeasure = measureTime('LocalWatcher#sendToPrep')
       await sendToPrep.step(normalizedChanges, this)
+      stopPrepAndMergeMeasure()
       target = (await this.pouch.db.changes({ limit: 1, descending: true }))
         .last_seq
     } finally {