Node-fs-extra: fs.copy silently fails on windows

[aeneasr]

This is an upstream issue report from electron-packager#544 and in particular this comment. The issue exists in both 1.0 and 2.0 versions.

electron-packager is a cli helper that packages an electron app. It does so by copying a node app (including node_modules) to the temp directory. This step uses fs.copy which silently fails. Neither the callback is called, nor an error is thrown.

This is the line which fails silently

fs.copy(opts.dir, appPath, {filter: ignore.userIgnoreFilter(opts), dereference: shouldDeref}, cb)

I'd be glad to help you identify root cause of this issue. My current guess that it's combination of filter/dereference and maybe (?) long paths?

Note that this only happens on windows. On OSX, packaging the project works fine.

[jprichardson]

@arekkas thank you for your report and offer to help.

It seems that fs.copy() all of a sudden is failing for a large swath of people. See in particular:

• https://github.com/jprichardson/node-fs-extra/issues/357
• https://github.com/jprichardson/node-fs-extra/issues/326
• https://github.com/jprichardson/node-fs-extra/issues/351#issuecomment-278752763

Let's start with this... which version of Node are you using? Does changing the version of Node to a previous version (in particular, older major), still cause the issue?

[aeneasr]

Thanks for your swift reply. I'm currently using node 6.6.0. Unfortunately, there is no nvm I am aware of that works on windows. So up-/downgrading is a bit of a pain. I'd do it however if you're confident that that might be the issue.

[jdalton]

Unfortunately, there is no nvm I am aware of that works on windows

btw I use nvm with BashOnWindows in Windows 10.

[jprichardson]

@arekkas https://github.com/coreybutler/nvm-windows However, please only switch nvm windows if you think you'll get personal value out of it. Thanks for your willingness to help here.

[aeneasr]

Ok, installed. Tried majors 4, 5, 6. All of them have (apparently) the same issue.

[aeneasr]

I did some good old console.log debugging. @jprichardson it looks like the culprit is the counter in ncp.js:

  function doneOne (skipped) {
    console.log('doneOne 1', skipped)
    if (!skipped) running--
    console.log('doneOne 2', skipped)
    finished++
    if ((started === finished) && (running === 0)) {
      console.log('doneOne 3', skipped)
      if (callback !== undefined) {
        console.log('doneOne 4', skipped)
        return callback(null)
      }
    }
    console.log('doneOne 5', skipped, started, finished, running)
  }

The last logs before the task quits are:

...
doneOne 5 undefined 40369 24699 15670
doneOne 1 undefined
doneOne 2 undefined
doneOne 5 undefined 40369 24700 15669
doneOne 1 undefined
doneOne 2 undefined
doneOne 5 undefined 40369 24701 15668
doneOne 1 undefined
doneOne 2 undefined
doneOne 5 undefined 40369 24702 15667
doneOne 1 undefined
doneOne 2 undefined
doneOne 5 undefined 40369 24703 15666
doneOne 1 undefined
doneOne 2 undefined
doneOne 5 undefined 40369 24704 15665
doneOne 1 undefined
doneOne 2 undefined
doneOne 5 undefined 40369 24705 15664

[aeneasr]

Ok, further debugged it. Apparently the last operation that is happening is copyFile. It always stops at the same file:

copyFile { name: 'C:\\workspace\\js\\sites-app\\node_modules\\browser-resolve\\node_modules\\resolve\\test\\subdirs\\node_modules\\a\\b\\c\\x.json',
  mode: 33206,
  mtime: 2017-02-16T20:11:38.580Z,
  atime: 2017-02-16T20:11:38.574Z,
  stats:
   { dev: -325773423,
     mode: 33206,
     nlink: 1,
     uid: 0,
     gid: 0,
     rdev: 0,
     blksize: undefined,
     ino: 3940649675519715,
     size: 8,
     blocks: undefined,
     atime: 2017-02-16T20:11:38.574Z,
     mtime: 2017-02-16T20:11:38.580Z,
     ctime: 2017-02-16T20:11:38.580Z,
     birthtime: 2017-02-16T20:11:38.574Z } } D:\Temp\electron-packager\linux-ia32\ORY Sites App-linux-ia32\resources\app\node_modules\browser-resolve\node_modules\resolve\test\subdirs\node_modules\a\b\c\x.json

[aeneasr]

On a side note: it would help so much if there was debugging information available from node-fs-extra using an env var or something :D

[aeneasr]

@jprichardson is it possible that this is caused by the stat part? From looking over the code it seems like the only place where it could happen that the counter gets increased without a chance of being decreased if stat isn't calling the callback:

stat(source, function (err, stats) {

I fucking hate windows.

[RyanZim]

@jprichardson Sometimes I wonder if we shouldn't just escalate https://github.com/jprichardson/node-fs-extra/issues/292.

With native promise support in node 4+, messing with these counters just seems so wrong.

[aeneasr]

So I'm not really sure where the culprit is now, if it's node-fs-extra or node-graceful-fs. Anyone any ideas? Unfortunately it's a blocking issue for me :(

[jprichardson]

So I'm not really sure where the culprit is now, if it's node-fs-extra or node-graceful-fs. Anyone any ideas? Unfortunately it's a blocking issue for me :(

Not yet, but we're digging! Hopefully can get a resolution early this week.

[aeneasr]

The issue does apparently no longer occur on node 7.6.0

[manidlou]

@arekkas are you still experiencing the issue?

[aeneasr]

Not with node 7.6.0 :)

[jprichardson]

@arekkas since Node v7.6.0 fixes things, perhaps it was a libuv issue? Are you comfortable with us closing this issue?

[aeneasr]

Maybe it could be pointed out in the readme! Otherwise good to close for me.

[RyanZim]

SGTM, @arekkas care to submit a PR?

[jrobeson]

is there a specific change in node 7.6.0 that fixed it? If so, then shouldn't the node folks be backporting it to the LTS release?

[RyanZim]

@jrobeson We're not quite sure what the root of the issue is here. It may be an issue with Node, or it may be an issue with the way graceful-fs works on Node

[nabito]

I'm experiencing fse silently failed too, but my settings is different.

Everything is running on Linux with no problem, until I switch my working terminal to be Windows (node is still running on Linux server), update a few files using local editor, and boom! fse.copy() doesn't work anymore.

Note that it's fse.copy() on Node v8.0.0 on Ubuntu.

Trial and errors resolved the problem, the suspect was line ending characters on Windows has creep into some files I edited locally. After removing them, fse.copy() work partially.

I'm using pm2-dev cmd to start my node app, and the problem only appear when invoking pm2-dev not normal production pm2.

Not sure yet what causes the problem but giving you guys my 2 hints.

[rikumi]

I got the same error on macOS now. After called by Electron-packager and copied part of the files, fs-extra silently quitted without calling the callback. Also, the last copied file varies and doesn't seem to be the cause.

[RyanZim]

We're now on v5, and copy has changed a lot since then. Assuming this is fixed and closing.

[girlzap]

Can confirm this issue seems to have been fixed with v5 of fs-extra.