WIP: core/chokidar: Prevent Pouch changes while flushing events

  - this should avoid conflicts from multiple remote updates on the same
    file while local events are flushed

core/local/chokidar/watcher.js

@@ -107,6 +107,7 @@ class LocalWatcher {
    * @see https://github.com/paulmillr/chokidar
    */
   start() {
+    console.log({ time: new Date() }, 'starting')
     log.debug('Starting...')
 
     this.watcher = chokidar.watch('.', {
@@ -165,7 +166,10 @@ class LocalWatcher {
       this.initialScan = {
         paths: [],
         emptyDirRetryCount: 3,
-        resolve,
+        resolve: () => {
+          console.log({ time: new Date() }, 'started')
+          resolve()
+        },
         flushed: false
       }
 
@@ -203,6 +207,7 @@ class LocalWatcher {
 
     if (this.initialScan) this.initialScan.flushed = true
     this.events.emit('buffering-end')
+    console.log({ time: new Date() }, 'buffering-end')
     syncDir.ensureExistsSync(this)
     this.events.emit('local-start')
 
@@ -214,6 +219,8 @@ class LocalWatcher {
       events,
       this
     )
+    this.events.emit('prepare-end')
+    console.log({ time: new Date() }, 'prepare-end')
     log.trace('Done with events preparation.')
 
     const changes /*: LocalChange[] */ = analysis(preparedEvents, this)
@@ -225,6 +232,7 @@ class LocalWatcher {
 
     // TODO: Don't even acquire lock changes list is empty
     // FIXME: Shouldn't we acquire the lock before preparing the events?
+    console.log({ time: new Date() }, 'acquiring lock')
     const release = await this.pouch.lock(this)
     let target = -1
     try {
@@ -234,6 +242,7 @@ class LocalWatcher {
     } finally {
       this.events.emit('sync-target', target)
       release()
+      console.log({ time: new Date() }, 'local-end')
       this.events.emit('local-end')
     }
     if (this.initialScan != null) {
@@ -243,6 +252,7 @@ class LocalWatcher {
   }
 
   async stop(force /*: ?bool */) {
+    console.log({ time: new Date() }, 'stopping')
     log.debug('Stopping watcher...')
     if (this.watcher) {
       // XXX manually fire events for added file, because chokidar will cancel
@@ -267,7 +277,10 @@ class LocalWatcher {
     if (force) return Promise.resolve()
     // Give some time for awaitWriteFinish events to be managed
     return new Promise(resolve => {
-      setTimeout(resolve, 1000)
+      setTimeout(() => {
+        console.log({ time: new Date() }, 'stopped')
+        resolve()
+      }, 1000)
     })
   }
 

core/utils/notes.js

@@ -23,14 +23,15 @@ type CozyNoteErrorCode = 'CozyDocumentMissingError' | 'UnreachableError'
 const isNote = (
   doc /*: { mime?: string, metadata?: Object } */
 ) /*: boolean %checks */ => {
-  return (
+  const isNote =
     doc.mime === NOTE_MIME_TYPE &&
     doc.metadata != null &&
     doc.metadata.content != null &&
     doc.metadata.schema != null &&
     doc.metadata.title != null &&
     doc.metadata.version != null
-  )
+  console.log({ isNote, doc })
+  return isNote
 }
 
 class CozyNoteError extends Error {

test/integration/update.js

@@ -15,6 +15,7 @@ const TestHelpers = require('../support/helpers')
 const configHelpers = require('../support/helpers/config')
 const cozyHelpers = require('../support/helpers/cozy')
 const pouchHelpers = require('../support/helpers/pouch')
+const { onPlatform } = require('../support/helpers/platform')
 
 const log = logger({ component: 'mocha' })
 
@@ -329,4 +330,77 @@ describe('Update file', () => {
       })
     })
   })
+
+  onPlatform('darwin', () => {
+    describe('multiple remote note updates with local buffering delay', () => {
+      it.only('does not generate a local conflict', async function() {
+        this.timeout(120000)
+        const filename = 'file.cozy-note'
+
+        const note = await builders
+          .remoteNote()
+          .name('file.cozy-note')
+          .data('initial content')
+          .create()
+        await helpers.pullAndSyncAll()
+        await helpers.flushLocalAndSyncAll()
+
+        console.log('starting watchers')
+        helpers._sync.start()
+        await helpers._sync.started()
+        //await helpers.local.start()
+        //await helpers.remote.start()
+
+        log.info('-------- First remote modification --------')
+        console.log({ time: new Date() }, 'merging 1st remote modification')
+        const firstUpdate = await builders
+          .remoteNote(note)
+          .data('first update')
+          .update()
+
+        log.info('-------- Local events buffering --------')
+        let fileList = []
+        for (let i = 0; i < 5000; i++) {
+          fileList.push(`whatever-${i}`)
+          helpers.local.syncDir.outputFile(`whatever-${i}`, 'local content')
+        }
+
+        // Wait for end of buffer timeout so local events are all flushed
+        // 2000 is the delay used for tests.
+        // See core/local/chokidar/watcher.js
+        await new Promise(resolve => {
+          helpers.local.side.events.once('prepare-end', async () => {
+            log.info('-------- Second remote modification --------')
+            console.log({ time: new Date() }, 'merging 2nd remote modification')
+            await builders
+              .remoteNote(firstUpdate)
+              .data('second update')
+              .update()
+            resolve()
+          })
+        })
+
+        await new Promise(resolve => {
+          let count = 0
+          helpers.local.side.events.on('local-end', async () => {
+            count++
+            if (count === 2) {
+              console.log({ time: new Date() }, 'stopping watchers')
+              //await helpers.local.stop()
+              //await helpers.remote.stop()
+              await helpers._sync.stop()
+              resolve()
+            }
+          })
+        })
+
+        await should(helpers.local.readFile(filename)).be.fulfilledWith(
+          'file\n\nsecond update'
+        )
+        await should(helpers.remote.readFile(filename)).be.fulfilledWith(
+          'file\n\nsecond update'
+        )
+      })
+    })
+  })
 })

test/support/builders/remote/note.js

@@ -149,6 +149,7 @@ module.exports = class RemoteNoteBuilder extends RemoteBaseBuilder /*:: <Metadat
   async update() /*: Promise<MetadataRemoteFile> */ {
     this._updateMetadata()
     this._updateExport()
+    console.log({ noteContent: this._data })
 
     const cozy = this._ensureCozy()
 
@@ -158,6 +159,7 @@ module.exports = class RemoteNoteBuilder extends RemoteBaseBuilder /*:: <Metadat
     const remoteFile /*: RemoteFile */ = _.clone(
       jsonApiToRemoteDoc(
         await cozy.files.updateById(this.remoteDoc._id, this._data, {
+          contentType: this.remoteDoc.mime,
           dirID: this.remoteDoc.dir_id,
           updatedAt: this.remoteDoc.updated_at,
           name: this.remoteDoc.name,

test/support/helpers/local.js

@@ -145,6 +145,14 @@ class LocalTestHelpers {
           .sort()
   }
 
+  async start() {
+    await this.side.watcher.start()
+  }
+
+  async stop() {
+    await this.side.watcher.stop()
+  }
+
   async scan() {
     await this.side.watcher.start()
     await this.side.watcher.stop()

test/support/helpers/remote.js

@@ -6,13 +6,15 @@ const path = require('path')
 
 const conflictHelpers = require('./conflict')
 const cozyHelpers = require('./cozy')
+const Builders = require('../builders')
 
 const { Remote, dirAndName } = require('../../../core/remote')
 const {
   ROOT_DIR_ID,
   TRASH_DIR_NAME
 } = require('../../../core/remote/constants')
 
+const builders = new Builders()
 /*::
 import type cozy from 'cozy-client-js'
 import type { Pouch } from '../../../core/pouch'
@@ -44,6 +46,13 @@ class RemoteTestHelpers {
     await this.pouch.setRemoteSeq(last_seq)
   }
 
+  async start() {
+    await this.side.watcher.start()
+  }
+
+  async stop() {
+    await this.side.watcher.stop()
+  }
   async pullChanges() {
     await this.side.watcher.watch()
   }
@@ -180,6 +189,29 @@ class RemoteTestHelpers {
     return resp.text()
   }
 
+  async outputFile(fpath /*: string */, content /*: string */) {
+    // TODO: handle files with same name but in different folders
+    const docs = await this.side.remoteCozy.search({
+      name: path.basename(fpath)
+    })
+    if (!docs || docs.length === 0)
+      throw new Error(`could not find remote documents with path ${fpath}`)
+    if (docs[0].type !== 'file')
+      throw new Error(`remote document with path ${fpath} is not a file`)
+
+    const file = docs[0]
+
+    return await this.side.remoteCozy.updateFileById(
+      file._id,
+      builders
+        .stream()
+        .push(content)
+        .build(),
+      // $FlowFixMe we don't care about the other parameters here
+      { updatedAt: new Date().toISOString(), noSanitize: true }
+    )
+  }
+
   async byId(id /*: string */) /*: Promise<MetadataRemoteInfo> */ {
     const remoteDoc = await this.cozy.files.statById(id)
     return await this.side.remoteCozy.toRemoteDoc(remoteDoc)