Unknown error when copying files > 2GB using fs

[mklnz]

• Version: 10 through 13
• Platform: Darwin Michaels-Mac-mini.local 19.0.0 Darwin Kernel Version 19.0.0: Wed Sep 25 20:18:50 PDT 2019; root:xnu-6153.11.26~2/RELEASE_X86_64 x86_64
• Subsystem: fs
• OS: macOS 10.15 Catalina

I'm having a very strange error on my Mac mini when using fs (both sync and async) copyFile to copy a file larger than 2GB. What's weird is on my MacBook Air with the same software setup there isn't any issues.

I created 2 files for testing using mkfile -n 1999m and mkfile -n 2g, then tried to copy them using node. the 1.999GB file worked fine and the 2GB file failed with unknown error. So there is a clear limit of 2GB here for some reason.

If this isn't a bug, how would one start to diagnose this further? The vague error certainly doesn't help. I've ruled out permission and drive space problems already, even reinstalled macOS from scratch but didn't help.

const fs = require('fs');
fs.copyFileSync('/Users/michael/Movies/wamp/1.mp4', '/Users/michael/Desktop/1.mp4');

internal/fs/utils.js:220
    throw err;
    ^

Error: UNKNOWN: unknown error, copyfile '/Users/michael/Movies/wamp/1.mp4' -> '/Users/michael/Desktop/1.mp4'
    at Object.copyFileSync (fs.js:1790:3)
    at Object.<anonymous> (/Users/michael/Development/homelab/meiti/copy-test.js:3:4)
    at Module._compile (internal/modules/cjs/loader.js:956:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:973:10)
    at Module.load (internal/modules/cjs/loader.js:812:32)
    at Function.Module._load (internal/modules/cjs/loader.js:724:14)
    at Function.Module.runMain (internal/modules/cjs/loader.js:1025:10)
    at internal/main/run_main_module.js:17:11 {   errno: -1429910540,   syscall: 'copyfile',   code: 'UNKNOWN',   path: '/Users/michael/Movies/wamp/1.mp4',   dest: '/Users/michael/Desktop/1.mp4' }

More info on Stackoverflow:
https://stackoverflow.com/questions/58500025/node-unknown-system-error-when-copying-large-files-over-2gb

[aduh95]

I am not able to reproduce the issue on Windows; maybe this is specific to macOS or AppleFS. What happens if you try to copy the file using cp command on the Terminal?

Also, does this issue happen only with copyFileSync or also with the other methods?

const fs = require("fs");

fs.copyFileSync("./2GB.bin", "./2GB-copySync.bin");

fs.copyFile(
  "./2GB.bin",
  "./2GB-copyASync.bin",
  console.log
);

fs.promises
  .copyFile("./2GB.bin", "./2GB-copyPromise.bin")
  .then(console.log, console.error);

[cjihrig]

This sounds like a bug in libuv. Quick experiment... can you try with Node 10.0.0. That version still had a macOS specific implementation, so I'd be curious to see if that version works.

[mklnz]

This sounds like a bug in libuv. Quick experiment... can you try with Node 10.0.0. That version still had a macOS specific implementation, so I'd be curious to see if that version works.

Good test, yes using v10.0.0 works without any problems. So Node moved to libuv after 10.0.0? I wonder why it's fine on my laptop.

➜  test nvm use 10.0.0
Now using node v10.0.0 (npm v5.6.0)
➜  test node test.js
➜  test ls
2GB-copySync.bin 2GB.bin          test.js
➜  test

Now using node v13.0.1 (npm v6.12.0)
node test.js
internal/fs/utils.js:220
    throw err;
    ^

Error: UNKNOWN: unknown error, copyfile './2GB.bin' -> './2GB-copySync.bin'
    at Object.copyFileSync (fs.js:1806:3)
    at Object.<anonymous> (/Users/michael/Desktop/test/test.js:3:4)
    at Module._compile (internal/modules/cjs/loader.js:971:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1011:10)
    at Module.load (internal/modules/cjs/loader.js:822:32)
    at Function.Module._load (internal/modules/cjs/loader.js:730:14)
    at Function.Module.runMain (internal/modules/cjs/loader.js:1051:12)
    at internal/main/run_main_module.js:16:11 {
  errno: -2147483648,
  syscall: 'copyfile',
  code: 'UNKNOWN',
  path: './2GB.bin',
  dest: './2GB-copySync.bin'
}

[cjihrig]

So Node moved to libuv after 10.0.0?

Not quite. Node has been using libuv for years. The underlying implementation of fs.copyFile() is in libuv. The function uv_fs_copyfile() used to have a macOS specific implementation, but Apple had some bugs in it that we just couldn't tolerate. So now, macOS and all Unix platforms share an implementation.

I wonder why it's fine on my laptop.

My first guess is that the two machines use a different number of bits to represent the file size, or something, but it's just a guess.

[mklnz]

I wonder why it's fine on my laptop.

My first guess is that the two machines use a different number of bits to represent the file size, or something, but it's just a guess.

Can I run any tests to verify this? I understand this problem might be hard to reproduce, if I can help in any way please let me know. Should I post this bug on the libuv repo also?

[cjihrig]

If you're comfortable with recompiling Node from source, I think it would be good to log the value here. That would tell us how many bytes libuv is trying to copy. If things were working properly, it should be the same as your file's size.

[mklnz]

I put in a printf("%zu\n", bytes_to_send); in the source code and compiled Node. Using the built version I ran my test.js, this is the output (v13.01):

It does seem like it is the correct output, as that number is the exact bytes of the 2GB.bin
Though the strange thing here to note is the errno is just the negative of the bytes.

bytes_to_send: 2147483648

internal/fs/utils.js:220
    throw err;
    ^

Error: UNKNOWN: unknown error, copyfile './2GB.bin' -> './2GB-copySync.bin'
    at Object.copyFileSync (fs.js:1806:3)
    at Object.<anonymous> (/Users/michael/Desktop/test/test.js:3:4)
    at Module._compile (internal/modules/cjs/loader.js:971:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1011:10)
    at Module.load (internal/modules/cjs/loader.js:822:32)
    at Function.Module._load (internal/modules/cjs/loader.js:730:14)
    at Function.Module.runMain (internal/modules/cjs/loader.js:1051:12)
    at internal/main/run_main_module.js:16:11 {
  errno: -2147483648,
  syscall: 'copyfile',
  code: 'UNKNOWN',
  path: './2GB.bin',
  dest: './2GB-copySync.bin'
}

[cjihrig]

I think the next thing to check would be the values of r and errno after this line.

Out of curiosity - you mentioned that the code is working fine on your laptop. Is your laptop also running Catalina?

[mklnz]

r: -1
errno: 38

errno 38 means ENOSYS, Function not implemented correct? Yes what's strange is my laptop has the exact same software environment. At this point I'm thinking it could be hardware related perhaps, but all other functions seem to work fine. I tried copying the same file using Ruby and it worked without issues.

[cjihrig]

errno 38 means ENOSYS

I believe 38 is ENOTSOCK on my machine. If that's the case on your machine, then execution would move to uv__fs_sendfile_emul() in that same file (that wouldn't happen if the error was ENOSYS). Can you confirm that you're ending up in uv__fs_sendfile_emul()? If so, I think this would be the place to debug.

[mklnz]

Yes you're right, the error code is indeed ENOTSOCK and does hit uv__fs_sendfile_emul().
I placed a few printf after this line:

do
  n = write(out_fd, buf + nwritten, nread - nwritten);
while (n == -1 && errno == EINTR);
printf("EMUL n: %zd\n", n);
printf("EMUL errno: %d\n", errno);
if (n != -1) {
  nwritten += n;
  printf("EMUL nwritten: %zd\n", nwritten);
  continue;
}
printf("hit");

The last output before the Node error output in the console is:

EMUL n: 8192
EMUL errno: 0
EMUL nwritten: 8192
internal/fs/utils.js:220
    throw err;
    ^

Is it normal for nwritten to not be incremented?
Also it looks like the file has been written as I can see it in Finder, but disappears immediately after error output.

[cjihrig]

It seems like the file has been written as I can see it in Finder, but disappears immediately after error output.

When uv_fs_copyfile() encounters (or thinks it encounters) an error, it removes the destination file here. You should be able to comment out that block of code and see what the resulting file looks like.

[mklnz]

Thanks for the help and quick response. I commented out that code block and checked the checksum of the original and destination files and they do seem to match:

➜  test openssl md5 2GB.bin
MD5(2GB.bin)= a981130cf2b7e09f4686dc273cf7187e
➜  test openssl md5 2GB-copySync.bin
MD5(2GB-copySync.bin)= a981130cf2b7e09f4686dc273cf7187e

The err in the out: label is -2147483648 which is again the size of the file.