node-pre-gyp Appveyor build failing for Windows x86 using Node 4.4.3

[deadprogram]

I was having trouble building for Windows x86 using Node.js 4.4.3, when I noticed that the Appveyor build for node-pre-gyp itself is failing for the same reason:

ENOENT: no such file or directory in readCAFile

The failed build can be seen here:

https://ci.appveyor.com/project/Mapbox/node-pre-gyp/build/1.0.373/job/h12w3ymhbyg6ltq6#L481

The build for Windows x64 using Node 4.4.3 succeeds, however.

I see that the node-gyp command is failing, but I thought perhaps node-pre-gyp might be missing something for the setup for the 4.4.3 release.

Any thoughts as to what is missing here? Now that 4.4.3 is the LTS version, it would be great to be able to have nice precompiled binaries for it.

Thank you!

[springmeyer]

This looks like something broken in node-gyp. node-gyp is failing in readCAFIle which recently was added in nodejs/node-gyp#837 /cc @bnoordhuis

[bnoordhuis]

It looks like something (.npmrc? something in the environment?) is setting npm_config_cafile to the string 'undefined'.

[reconbot]

Should this be filed on node-gyp itself?

[reconbot]

I've got a two step work around and I filed a bug with node-gyp.

The error we see is that the string undefined isn't a file. I'm only seeing this on 32bit windows machines with node 4.3 and 4.4. I haven't checked others.

The work around is to set the cafile option to a real file, I chose package.json. Then we get a second bug where even though it hasn't found a cert in package.json it still tries to use one. So you have to disable strict-ssl. We get some warnings but it works and doesn't seem to affect other node versions.

I added these to install phase in appveyor.yml

  # work around an issue with node-gyp v3.3.1 and node 4x
  # package.json has no certificates in it so we're cool
  # https://github.com/nodejs/node-gyp/issues/921
  - cmd: npm config set -g cafile=package.json
  - cmd: npm config set -g strict-ssl=false

[reconbot]

I haven't tracked it down completely, but I can confirm this issue while erroring in node-gyp is caused by node-pre-gyp being in the chain. I'm looking at the options munging that goes on in handle_gyp_opts.js

[springmeyer]

@BergWerkGIS 68301ce looks like a workaround and not a fix for the underlying problem. Correct? If so, do you have any hunches on the underlying problem (that would allow us to remove that workaround)?

[wilhelmberg]

@springmeyer
Using same versions locally as on AppVeyor

• node@4.4.7
• npm@2.15.9
• node-gyp@3.4.0

I'm able to confirm that this error occurs with x86 only and not with x64.

Another workaround is used in node-gdal: downgrading node-gyp to 3.2.1.

Investigating ...

[reconbot]

Thank you @BergWerkGIS I'm glad someone else is also taking a look

[wilhelmberg]

Progress update

Downgrading to node-gyp@3.2.1 is not feasible as it fails with this error when building with VS 2015 Update 3 (fixed in node-gyp@3.4.0):

node-gyp\src\win_delay_load_hook.c(34): 
error C2373: '__pfnDliNotifyHook2': redefinition; different type modifiers

If this error still occurs after npm install -g node-gyp@3.4.0 a workaround might be to manually upgrade node-gyp within npm.

---

Still searching where undefined is coming from ....

[wilhelmberg]

Hm, this is getting stranger.

The error is intermittent, sometimes it occurs and sometimes it does not.

I've only been able to reproduce it with npm test which sometimes errors like on AppVeyor (sometimes not):

Error: Command failed: C:\WINDOWS\system32\cmd.exe /s /c 
"node-pre-gyp rebuild -C c:\mb\node-pre-gyp\test\app2 --clang=1 --msvs_version=2015  --custom_include_path=../include --toolset=cpp11 --loglevel=error"
gyp ERR! configure error 
gyp ERR! stack Error: ENOENT: no such file or directory, open 'c:\mb\node-pre-gyp\test\app2\undefined'
gyp ERR! stack     at Error (native)
gyp ERR! stack     at Object.fs.openSync (fs.js:549:18)
gyp ERR! stack     at Object.fs.readFileSync (fs.js:397:15)
gyp ERR! stack     at readCAFile (C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\lib\install.js:466:15)
gyp ERR! stack     at download (C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\lib\install.js:438:22)
gyp ERR! stack     at C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\lib\install.js:185:19
gyp ERR! stack     at C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\mkdirp\index.js:48:26
gyp ERR! stack     at FSReqWrap.oncomplete (fs.js:82:15)
gyp ERR! System Windows_NT 10.0.14905

If I run the same command

node bin\node-pre-gyp rebuild -C c:\mb\node-pre-gyp\test\app2 --clang=1 --msvs_version=2015  --custom_include_path=../include --toolset=cpp11 --loglevel=error

directly from the command line it always succeeds:

[node-pre-gyp-test-app2] Removing "c:\mb\node-pre-gyp\test\app2\lib\binding\Release\node-pre-gyp-test-app2"
gyp info it worked if it ends with ok
gyp info using node-gyp@3.4.0
gyp info using node@4.4.7 | win32 | ia32
gyp info ok
Building the projects in this solution one at a time. To enable parallel build, please add the "/m" switch.
  app2.cc
  win_delay_load_hook.cc
     Creating library c:\mb\node-pre-gyp\test\app2\build\Release\app2.lib and object c:\mb\node-pre-gyp\test\app2\build\Release\app2.exp
  Generating code
  Finished generating code
  app2.vcxproj -> c:\mb\node-pre-gyp\test\app2\build\Release\\app2.node
  app2.vcxproj -> c:\mb\node-pre-gyp\test\app2\build\Release\app2.pdb (Full PDB)
  Copying c:\mb\node-pre-gyp\test\app2\build\Release\/app2.node to c:/mb/node-pre-gyp/test/app2/lib/binding/Release/node-pre-gyp-test-app2/app2.node
          1 file(s) copied.

---

My current hunch is that the problem just occurs with the tests and not with node-pre-gyp/node-gyp/gyp per se, as mocha shells out to node-pre-gyp which shells out to pre-gyp which shells out to gyp.

I think somewhere on the way the environment gets screwed (sometimes, don't know yet when and why) and thus results in failures.

This shelling-out structure also makes this problem a nightmare to debug:
If I attach to and step through the mocha process I cannot continue to step into node-pre-gyp when it gets executed.
Same if I attach to node-pre-gyp and pre-gyp gets called, and so on.

[reconbot]

@BergWerkGIS lets see how deep the rabbit hole goes.

You mentioned making a test for this, anything worth sharing yet?

[wilhelmberg]

lets see how deep the rabbit hole goes.

Yeah, curious if we ever find out what's going on here.

You mentioned making a test for this, anything worth sharing yet?

Sorry, no dedicated test to consistently reproduce.
What I meant was that the error just pops up for me (sometimes) when running the node-pre-gyp test suite with npm test.
When I run the command that's shown in the error message on its own the error doesn't occur.

[wilhelmberg]

One step further:
using --loglevel=silly I see that node-gyp fails when it is verifying/trying to install node headers/libs:

gyp verb get node dir no --target version specified, falling back to host node version: 4.4.7
gyp verb command install [ '4.4.7' ]
gyp verb install input version string "4.4.7"
gyp verb install installing version: 4.4.7
gyp verb install --ensure was passed, so won't reinstall if already installed
gyp verb install version is already installed, need to check "installVersion"
gyp verb got "installVersion" 0
gyp verb needs "installVersion" 9
gyp verb install version is no good; reinstalling
gyp verb ensuring nodedir is created C:\Users\bergw\.node-gyp\4.4.7
gyp http GET https://nodejs.org/download/release/v4.4.7/node-v4.4.7-headers.tar.gz
gyp WARN install got an error, rolling back install
gyp verb command remove [ '4.4.7' ]
gyp verb remove using node-gyp dir: C:\Users\bergw\.node-gyp
gyp verb remove removing target version: 4.4.7
gyp verb remove removing development files for version: 4.4.7
gyp ERR! configure error 
gyp ERR! stack Error: ENOENT: no such file or directory, open 'c:\mb\node-pre-gyp\test\app2\undefined'
gyp ERR! stack     at Error (native)
gyp ERR! stack     at Object.fs.openSync (fs.js:549:18)
gyp ERR! stack     at Object.fs.readFileSync (fs.js:397:15)
gyp ERR! stack     at readCAFile (C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\lib\install.js:466:15)
gyp ERR! stack     at download (C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\lib\install.js:438:22)
gyp ERR! stack     at C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\lib\install.js:185:19
gyp ERR! stack     at C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\mkdirp\index.js:48:26
gyp ERR! stack     at FSReqWrap.oncomplete (fs.js:82:15)
gyp ERR! System Windows_NT 10.0.14905

Monitoring C:\Users\bergw\.node-gyp during npm install I see that the subdirectories 4.4.6 and 4.4.7 get deleted and created several times.

If I execute just the last command shown before the error from the command line the directories don't seem to get touched.

"C:\Program Files (x86)\nodejs\node.exe" 
"C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp\bin\node-gyp.js" configure 
--directory=c:\mb\node-pre-gyp\test\app2 
--clang=1 
--msvs_version=2015 
--custom_include_path=../include 
--toolset=cpp11 
--loglevel=silly 
--module=c:\mb\node-pre-gyp\test\app2\lib\binding\Release\node-pre-gyp-test-app2\app2.node 
--module_name=app2 
--module_path=c:\mb\node-pre-gyp\test\app2\lib\binding\Release\node-pre-gyp-test-app2 
--msvs_version=2015

---

Maybe there is some kind of race condition where one test tries to leave behind a clean slate (deleting node headers/libs) and the next test has already started.

Also not sure yet why node-gyp installs 4.4.6 headers when everything is set to 4.4.7.

[wilhelmberg]

I think my initial hunch about something strange happening during npm test is correct.
After npm test the node source directories within node-gyp are empty:

C:\Users\bergw\.node-gyp
λ tree
C:.
├───4.4.6
└───4.4.7

C:\Users\bergw\.node-gyp
λ find .
.
./4.4.6
./4.4.7

Unfortunately stepping through node-gyp configure (where the bad things happen) hasn't turned up anything.

Also noticed that sometimes commands shell out to

C:\Users\bergw\AppData\Roaming\npm\node_modules\node-gyp

and sometimes to

C:\Program Files (x86)\nodejs\node_modules\npm\node_modules\node-gyp

Still searching for the where and why ...

[springmeyer]

Dropping some info: with node-gdal this is only happening with node v4.x and v5.x x86 builds and not v6.x (both x64 and x86 work): https://ci.appveyor.com/project/brianreavis/node-gdal/build/682

[springmeyer]

Further isolated this issue.

To recap: the error we are trying to avoid is:

     gyp ERR! stack Error: ENOENT: no such file or directory, open 'C:\projects\node-pre-gyp\test\app1\undefined'

I've found that the workaround of:

  - npm config set -g cafile=package.json
  - npm config set -g strict-ssl=false

Does solve no such file or directory, open 'C:\projects\node-pre-gyp\test\app1\undefined' error, but (seen with node v4.8.3) but (at least with node-pre-gyp tests) now also triggers another error:

      node-pre-gyp ERR! install error 
      node-pre-gyp ERR! stack Error: unable to get local issuer certificate

So, we need a different workaround.

Luckily I've found that both of the above errors can be avoided by upgrading node-gyp:

npm install node-gyp@3.x

• Where I saw this work, it installed node-gyp at 3.6.2.
• Using nvm locally on my mac shows that node-gyp v3.4.0 is the default in node v4.8.3.
• So I presume some node-gyp bug was fixed between v3.4.0 and v3.6.2.

I'm now going to close this since I don't see anything more to do on the node-pre-gyp side.