Watchman kicks off event before uploading files are completed/closed

[Azureleung]

I'm using Node.js to start Watchman on Windows 2016 with a number of file type filters on a specific directory. This directory is being used for staging. Uploaded files will be routed to other folders depending on the filename.

The problem that I'm having is Watchman is picking up files that are being uploaded. It causes the moving processes to fail as it's locked. I'm thinking about using this package to check the file status (@ronomon/opened) before marking it as a candidate for moving. Is there a better way to do it?

C:\Windows\system32>watchman -v
4.9.1

C:\Windows\system32>npm -v
5.6.0

C:\Windows\system32>

C:\Windows\system32>node -v
v8.9.4

[wez]

Can you provide more information about what is doing the uploading, what is doing the moving, and exactly how watchman fits into this? Are you using watchman subscriptions and triggering something in node to do the move? Are the uploads also running through node (possibly in a different process)?

What error are you seeing exactly?

[Azureleung]

The Windows server is hosting a FTP server. I have a nodejs process that runs Watchman subscriptions and generate a message with the file information(path, size, type, etc) and dump it into a queue. I have another nodejs process(es) that reads off of this queue and moves the files based of a set of rules stored in a json file. This process works for small files, but would generate numerous errors if the file being uploaded is in the GB range. Watchman appears to treat it as a new file each time it checks and floods the message queue with the same file entry but with different file sizes.

I'll follow up with the exact error messages, but I found this stack article.

https://stackoverflow.com/questions/35906246/watchman-how-to-wait-until-file-has-copied-before-subscribe-event-emits

[wez]

Watchman is going to tell you about that file each time it is changed. If the file is being written to continuously by the uploader you will get a stream of notifications for each write to the file.

There isn't a great way to tell when the upload is finished in this situation, but what I'd do is use a simple heuristic: each time you get a notification from watchman, use setTimeout() or similar to schedule the move to happen after a reasonable time interval. I would pick 1 minute for this sort of thing as that is long enough that you're unlikely to hit a false positive and short enough that it doesn't make the system feel terribly laggy.

If you get another update for the same file, you'd cancel the prior timeout and schedule it again to happen 1 minute later.

Some pseudo code for this might look something like:

// holds timer handles for pending moves
moves = {}

function onFileChanged(path) {
    if (path in moves) {
       cancelTimeout(moves[path]);
    }
    moves[path] = setTimeout(60, doMove, path);
}

If you don't want to manage the timing for this for yourself, you can set https://facebook.github.io/watchman/docs/config.html#settle to ask watchman to defer notifying you until the files have stopped changing. This is a bit more opaque and harder to debug which is why I suggest handling this for yourself in code. To configure this, you would create a .watchmanconfig file in the upload directory with these contents:

{"settle": 60000}

the settle option is specified in milliseconds.

[wez]

(you'll need to restart the watch each time you add/change/remove the .watchmanconfig file)

[Azureleung]

Here are the log entries from the file moving Node process. Since the 2 GB file is still uploading, the file moving nodejs process would fail as there is a lock on the file.

Queue Name: globalfileq Queue Count: 15
Message: {"name":"msft/linuxx64_12201_grid_home.zip","size":2097152,"exists":true,"created":"Fri Jan 05 2018 01:27:21 GMT+0000 (Coordinated Universal Time)","type":"f"}
File move start here!
z:/destdir/folder1
{ Error: EBUSY: resource busy or locked, rename 'C:\ClusterStorage\Volume1\xxxxxx\xxxxxx\xxx\msft\linuxx64_12201_grid_home.zip' -> 'z:\destdir\folder1\linuxx64_12201_grid_home.zip'
errno: -4082,
code: 'EBUSY',
syscall: 'rename',
path: 'C:\ClusterStorage\Volume1\xxxxxx\xxxxxx\xxx\msft\linuxx64_12201_grid_home.zip',
dest: 'z:\destdir\folder1\linuxx64_12201_grid_home.zip' }
Queue Name: globalfileq Queue Count: 17
Message: {"name":"msft/linuxx64_12201_grid_home.zip","size":3342336,"exists":true,"created":"Fri Jan 05 2018 01:27:21 GMT+0000 (Coordinated Universal Time)","type":"f"}
File move start here!
z:/destdir/folder1
{ Error: EBUSY: resource busy or locked, rename 'C:\ClusterStorage\Volume1\xxxxx\xxxxxxx\xxx\msft\linuxx64_12201_grid_home.zip' -> 'z:\destdir\folder1\linuxx64_12201_grid_home.zip'
errno: -4082,
code: 'EBUSY',
syscall: 'rename',
path: 'C:\ClusterStorage\Volume1\EFTROOT\ALLSITES\USR\msft\linuxx64_12201_grid_home.zip',
dest: 'z:\destdir\folder1\linuxx64_12201_grid_home.zip' }

[Azureleung]

Thanks. I'll take a look at settle.