diff --git a/core/local/channel_watcher/add_checksum.js b/core/local/channel_watcher/add_checksum.js index 3e196813d..06c49eb74 100644 --- a/core/local/channel_watcher/add_checksum.js +++ b/core/local/channel_watcher/add_checksum.js @@ -18,6 +18,7 @@ const _ = require('lodash') const path = require('path') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const STEP_NAME = 'addChecksum' @@ -56,6 +57,8 @@ function loop( const syncPath = opts.config.syncPath return channel.asyncMap(async events => { + const stopMeasure = measureTime('LocalWatcher#addChecksumStep') + for (const event of events) { try { if (event.incomplete) { @@ -74,6 +77,8 @@ function loop( log.debug('Cannot compute checksum', { err, event }) } } + + stopMeasure() return events }, opts.fatal) } diff --git a/core/local/channel_watcher/add_infos.js b/core/local/channel_watcher/add_infos.js index b812182f4..6380f901f 100644 --- a/core/local/channel_watcher/add_infos.js +++ b/core/local/channel_watcher/add_infos.js @@ -13,6 +13,7 @@ const path = require('path') const { kind } = require('../../metadata') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const stater = require('../stater') const STEP_NAME = 'addInfos' @@ -47,6 +48,8 @@ function loop( const syncPath = opts.config.syncPath return channel.asyncMap(async events => { + const stopMeasure = measureTime('LocalWatcher#addInfosStep') + const batch = [] for (const event of events) { if (event.kind === 'symlink') { @@ -94,6 +97,8 @@ function loop( } batch.push(event) } + + stopMeasure() return batch }, opts.fatal) } diff --git a/core/local/channel_watcher/await_write_finish.js b/core/local/channel_watcher/await_write_finish.js index d0af0dde7..c09b89a52 100644 --- a/core/local/channel_watcher/await_write_finish.js +++ b/core/local/channel_watcher/await_write_finish.js @@ -12,6 +12,7 @@ const _ = require('lodash') const Channel = require('./channel') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const STEP_NAME = 'awaitWriteFinish' @@ -245,17 +246,21 @@ async function awaitWriteFinish(channel /*: Channel */, out /*: Channel */) { // eslint-disable-next-line no-constant-condition while (true) { - const events = aggregateBatch(await channel.pop()) - let nbCandidates = countFileWriteEvents(events) - debounce(waiting, events) + const events = await channel.pop() + const stopMeasure = measureTime('LocalWatcher#awaitWriteFinishStep') + + const aggregatedEvents = aggregateBatch(events) + let nbCandidates = countFileWriteEvents(aggregatedEvents) + debounce(waiting, aggregatedEvents) // Push the new batch of events in the queue const timeout = setTimeout(() => { out.push(waiting.shift().events) sendReadyBatches(waiting, out) }, DELAY) - waiting.push({ events, nbCandidates, timeout }) + waiting.push({ events: aggregatedEvents, nbCandidates, timeout }) + stopMeasure() // Look if some batches can be sent without waiting sendReadyBatches(waiting, out) } diff --git a/core/local/channel_watcher/dispatch.js b/core/local/channel_watcher/dispatch.js index d61cb3c32..a0b40a0cb 100644 --- a/core/local/channel_watcher/dispatch.js +++ b/core/local/channel_watcher/dispatch.js @@ -12,6 +12,7 @@ const _ = require('lodash') const { buildDir, buildFile } = require('../../metadata') const { WINDOWS_DATE_MIGRATION_FLAG } = require('../../config') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const STEP_NAME = 'dispatch' const component = `ChannelWatcher/${STEP_NAME}` @@ -79,6 +80,8 @@ function loop( function step(opts /*: DispatchOptions */) { return async (batch /*: ChannelBatch */) => { + const stopMeasure = measureTime('LocalWatcher#dispatchStep') + const { [STEP_NAME]: dispatchState } = opts.state clearTimeout(dispatchState.localEndTimeout) @@ -96,6 +99,7 @@ function step(opts /*: DispatchOptions */) { opts.events.emit('local-end') }, LOCAL_END_NOTIFICATION_DELAY) + stopMeasure() return batch } } diff --git a/core/local/channel_watcher/filter_ignored.js b/core/local/channel_watcher/filter_ignored.js index fe661a148..56431a0d2 100644 --- a/core/local/channel_watcher/filter_ignored.js +++ b/core/local/channel_watcher/filter_ignored.js @@ -12,6 +12,7 @@ const _ = require('lodash') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') /*:: import type Channel from './channel' @@ -41,6 +42,8 @@ function loop( }) return channel.map(events => { + const stopMeasure = measureTime('LocalWatcher#filterIgnoredStep') + const batch = [] for (const event of events) { @@ -53,6 +56,7 @@ function loop( } } + stopMeasure() return batch }, opts.fatal) } diff --git a/core/local/channel_watcher/incomplete_fixer.js b/core/local/channel_watcher/incomplete_fixer.js index cd1d840e2..893049d2d 100644 --- a/core/local/channel_watcher/incomplete_fixer.js +++ b/core/local/channel_watcher/incomplete_fixer.js @@ -17,6 +17,7 @@ const path = require('path') const stater = require('../stater') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const STEP_NAME = 'incompleteFixer' @@ -209,6 +210,8 @@ function step( opts /*: IncompleteFixerOptions */ ) { return async (events /*: ChannelBatch */) /*: Promise */ => { + const stopMeasure = measureTime('LocalWatcher#incompleteFixerStep') + const batch = new Set() // Filter incomplete events @@ -320,6 +323,7 @@ function step( state.incompletes.push(...incompletes) } + stopMeasure() return Array.from(batch) } } diff --git a/core/local/channel_watcher/initial_diff.js b/core/local/channel_watcher/initial_diff.js index e1ff1ba71..b0c6773ca 100644 --- a/core/local/channel_watcher/initial_diff.js +++ b/core/local/channel_watcher/initial_diff.js @@ -15,6 +15,7 @@ const path = require('path') const { WINDOWS_DATE_MIGRATION_FLAG } = require('../../config') const { kind } = require('../../metadata') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const Channel = require('./channel') /*:: @@ -82,6 +83,8 @@ function loop( async function initialState( opts /*: { pouch: Pouch } */ ) /*: Promise */ { + const stopMeasure = measureTime('LocalWatcher#initialDiffInitialState') + const waiting /*: WaitingItem[] */ = [] const renamedEvents /*: ChannelEvent[] */ = [] const scannedPaths /*: Set */ = new Set() @@ -98,6 +101,7 @@ async function initialState( } } + stopMeasure() return { [STEP_NAME]: { waiting, @@ -152,6 +156,8 @@ async function initialDiff( continue } + const stopMeasure = measureTime('LocalWatcher#initialDiffStep') + let nbCandidates = 0 debounce(waiting, events) @@ -247,6 +253,8 @@ async function initialDiff( clearState(state) } batch.push(event) + + stopMeasure() } // Push the new batch of events in the queue diff --git a/core/local/channel_watcher/overwrite.js b/core/local/channel_watcher/overwrite.js index 47497c8e0..16af1c2b2 100644 --- a/core/local/channel_watcher/overwrite.js +++ b/core/local/channel_watcher/overwrite.js @@ -8,6 +8,7 @@ const _ = require('lodash') const Channel = require('./channel') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') /*:: import type { ChannelEvent, ChannelBatch } from './event' @@ -161,6 +162,8 @@ const _loop = async (channel, out, opts) => { // eslint-disable-next-line no-constant-condition while (true) { const events = await channel.pop() + const stopMeasure = measureTime('LocalWatcher#overwriteStep') + const { state: { [STEP_NAME]: state } } = opts @@ -168,6 +171,7 @@ const _loop = async (channel, out, opts) => { await step(events, opts) rotateState(state, events, output) + stopMeasure() } } diff --git a/core/local/channel_watcher/parcel_producer.js b/core/local/channel_watcher/parcel_producer.js index 4584e2230..3af483c65 100644 --- a/core/local/channel_watcher/parcel_producer.js +++ b/core/local/channel_watcher/parcel_producer.js @@ -11,6 +11,7 @@ const parcel = require('@parcel/watcher') const Channel = require('./channel') const { INITIAL_SCAN_DONE } = require('./event') const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') /*:: import type { Config } from '../../config' @@ -98,6 +99,9 @@ class Producer { * events for its content in that case). */ async start() { + const stopParcelSubscribeMeasure = measureTime( + 'LocalWatcher#parcelSubscribe' + ) this.watcher = await parcel.subscribe( this.config.syncPath, async (err, events) => { @@ -106,6 +110,7 @@ class Producer { }, { backend } ) + stopParcelSubscribeMeasure() if (!this.watcher) throw new Error('Could not start @parcel/watcher') this.events.emit('buffering-start') @@ -120,11 +125,16 @@ class Producer { } async scan(relPath /*: string */) { + const stopParcelScanMeasure = measureTime('LocalWatcher#parcelScan') const scanEvents = await parcel.scan( path.join(this.config.syncPath, relPath), { backend } ) + stopParcelScanMeasure() + + const stopProcessEventsMeasure = measureTime('LocalWatcher#processEvents') await this.processEvents(scanEvents, { fromScan: true }) + stopProcessEventsMeasure() } async buildEvent( diff --git a/core/local/channel_watcher/scan_folder.js b/core/local/channel_watcher/scan_folder.js index d5d8c3f20..8304687fd 100644 --- a/core/local/channel_watcher/scan_folder.js +++ b/core/local/channel_watcher/scan_folder.js @@ -10,6 +10,7 @@ */ const { logger } = require('../../utils/logger') +const measureTime = require('../../utils/perfs') const STEP_NAME = 'scanFolder' @@ -31,6 +32,8 @@ function loop( opts /*: { scan: Scanner, fatal: Error => any } */ ) /*: Channel */ { return channel.asyncMap(async batch => { + const stopMeasure = measureTime('LocalWatcher#scanFolderStep') + for (const event of batch) { if (event.incomplete) { continue @@ -41,6 +44,8 @@ function loop( }) } } + + stopMeasure() return batch }, opts.fatal) } diff --git a/core/local/channel_watcher/win_identical_renaming.js b/core/local/channel_watcher/win_identical_renaming.js index d2e684f1c..e6817fbe2 100644 --- a/core/local/channel_watcher/win_identical_renaming.js +++ b/core/local/channel_watcher/win_identical_renaming.js @@ -15,6 +15,7 @@ const _ = require('lodash') const Channel = require('./channel') const { logger } = require('../../utils/logger') const metadata = require('../../metadata') +const measureTime = require('../../utils/perfs') /*:: import type { ChannelEvent, ChannelBatch } from './event' @@ -144,6 +145,8 @@ const _loop = async (channel, out, opts) => { // eslint-disable-next-line no-constant-condition while (true) { const events = await channel.pop() + const stopMeasure = measureTime('LocalWatcher#winIdenticalRenamingStep') + const { state: { [STEP_NAME]: state } } = opts @@ -163,6 +166,8 @@ const _loop = async (channel, out, opts) => { pending.timeout = setTimeout(() => { output(pending) }, DELAY) + + stopMeasure() } }