Build error when run from npm script

[jan-j]

Exit code: 1
Command: sh
Arguments: -c node-gyp rebuild
Directory: /Users/john/projects/photo-booth/app/node_modules/printer
Output:
gyp info it worked if it ends with ok
gyp info using node-gyp@3.6.1
gyp info using node@7.9.0 | darwin | x64
gyp WARN download NVM_NODEJS_ORG_MIRROR is deprecated and will be removed in node-gyp v4, please use NODEJS_ORG_MIRROR
gyp WARN download NVM_NODEJS_ORG_MIRROR is deprecated and will be removed in node-gyp v4, please use NODEJS_ORG_MIRROR
gyp info spawn /usr/local/bin/python2
gyp info spawn args [ '/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/gyp_main.py',
gyp info spawn args   'binding.gyp',
gyp info spawn args   '-f',
gyp info spawn args   'make',
gyp info spawn args   '-I',
gyp info spawn args   '/Users/john/projects/photo-booth/app/node_modules/printer/build/config.gypi',
gyp info spawn args   '-I',
gyp info spawn args   '/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/addon.gypi',
gyp info spawn args   '-I',
gyp info spawn args   '/Users/john/.node-gyp/7.9.0/include/node/common.gypi',
gyp info spawn args   '-Dlibrary=shared_library',
gyp info spawn args   '-Dvisibility=default',
gyp info spawn args   '-Dnode_root_dir=/Users/john/.node-gyp/7.9.0',
gyp info spawn args   '-Dnode_gyp_dir=/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp',
gyp info spawn args   '-Dnode_lib_file=node.lib',
gyp info spawn args   '-Dmodule_root_dir=/Users/john/projects/photo-booth/app/node_modules/printer',
gyp info spawn args   '-Dnode_engine=v8',
gyp info spawn args   '--depth=.',
gyp info spawn args   '--no-parallel',
gyp info spawn args   '--generator-output',
gyp info spawn args   'build',
gyp info spawn args   '-Goutput_dir=.' ]
Traceback (most recent call last):
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/gyp_main.py", line 16, in <module>
    sys.exit(gyp.script_main())
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 545, in script_main
    return main(sys.argv[1:])
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 538, in main
    return gyp_main(args)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 514, in gyp_main
    options.duplicate_basename_check)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 130, in Load
    params['parallel'], params['root_targets'])
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2778, in Load
    variables, includes, depth, check, True)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 394, in LoadTargetBuildFile
    includes, True, check)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 266, in LoadOneBuildFile
    aux_data, includes, check)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 304, in LoadBuildFileIncludesIntoDict
    subdict_path, include)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2144, in MergeDicts
    MergeDicts(to[k], v, to_file, fro_file)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2137, in MergeDicts
    to[k] = MakePathRelative(to_file, fro_file, v)
  File "/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2036, in MakePathRelative
    if item[-1] == '/':
IndexError: string index out of range while reading includes of binding.gyp while trying to load binding.gyp
gyp ERR! configure error 
gyp ERR! stack Error: `gyp` failed with exit code: 1
gyp ERR! stack     at ChildProcess.onCpExit (/Users/john/.nvm/versions/node/v7.9.0/lib/node_modules/node-gyp/lib/configure.js:336:16)
gyp ERR! stack     at emitTwo (events.js:106:13)
gyp ERR! stack     at ChildProcess.emit (events.js:194:7)
gyp ERR! stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:215:12)
gyp ERR! System Darwin 16.6.0
gyp ERR! command "/Users/john/.nvm/versions/node/v7.9.0/bin/node" "/Users/john/.nvm/versions/node/v7.9.0/bin/node-gyp" "rebuild"
gyp ERR! cwd /Users/john/projects/photo-booth/app/node_modules/printer
gyp ERR! node -v v7.9.0
gyp ERR! node-gyp -v v3.6.1
gyp ERR! not ok

Environment:
MacOS 10.12.5
Node 7.9.0
Python 2.7.13

When doing npm install node-gyp rebuild command fails with the above error. But when I run the same command directly in the node_modules/{module} directory it works. I checked it with other native modules, so it's not related to the specific module. I also checked if python version used in the npm script run is the right one.

[refack]

@jan-j hello,
FWIW I can't reproduce on Windows.
It seems like GYP is failing to turn a path into a relative-to-buildroot path. Is any of the paths a symlink?
Also could you help with (1) posting your package.json (2) confirm that cd node_modules/printer ; node-gyp rebuild works (3) maybe post your env?
/cc @nodejs/platform-macos

[jan-j]

1. That's package.json of the library I'm trying to install/build https://github.com/tojocky/node-printer/blob/master/package.json, but it happens not only with this library. package.json of my root repo has nothing specific in it, it fails to install printer module even with clean package.json.
2. Yes, if I call it directly from terminal it works. But if added to package.json scripts like below and called - it fails:

  "scripts": {
    "ng": "cd node_modules/printer; node-gyp --verbose rebuild;"
  },

3. Node env in the attachment, I didn't find anything suspicious there.
   env.txt

[refack]

So as a non-macOS-expert, what I can say is that you don't need the ng script. npm i printer will automatically detects that printer needs to be built, and will call node-gyp as a default install hook.

AFAIK npm scripts run in a modified environment. I'm not sure but it might be incompatible with explicit calls to node-gyp. You can try to add:

"scripts": {
    "printenv": "cd node_modules/printer; env"
  },

and see what it does.

[jan-j]

So as a non-macOS-expert, what I can say is that you don't need the ng script. npm i printer will automatically detects that printer needs to be built, and will call node-gyp as a default install hook.

I know, I only added it to debug. It fails in both cases.

Here's env output (I believe it's the same, just different format than before).
env.txt

[aaronjensen]

I'm seeing the same thing while attempting to npm install something that includes node-pty

$ npm i
npm WARN registry Unexpected warning for https://registry.npmjs.org/: Miscellaneous Warning EINTEGRITY: sha1-wZyd+aAocC1nhhI4SmVSQExjbRU= integrity checksum failed when using sha1: wanted sha1-wZyd+aAocC1nhhI4SmVSQExjbRU= but got sha512-MJTUg1kjuLeQCJ+ccE4Vpa6kKVXkPYJ2mOCQyUuKLcLQsdrMCpBPUi8qVE6+YuaJkozeA9NusTAw3hLr8Xe5EQ==. (15621 bytes)

> node-pty@0.6.6 install /Users/aaronjensen/Source/hello-epics/node_modules/node-pty
> node scripts/install.js

Traceback (most recent call last):
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/gyp_main.py", line 16, in <module>
    sys.exit(gyp.script_main())
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 545, in script_main
    return main(sys.argv[1:])
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 538, in main
    return gyp_main(args)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 514, in gyp_main
    options.duplicate_basename_check)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/__init__.py", line 130, in Load
    params['parallel'], params['root_targets'])
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2778, in Load
    variables, includes, depth, check, True)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 394, in LoadTargetBuildFile
    includes, True, check)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 266, in LoadOneBuildFile
    aux_data, includes, check)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 304, in LoadBuildFileIncludesIntoDict
    subdict_path, include)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2144, in MergeDicts
    MergeDicts(to[k], v, to_file, fro_file)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2137, in MergeDicts
    to[k] = MakePathRelative(to_file, fro_file, v)
  File "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/gyp/pylib/gyp/input.py", line 2036, in MakePathRelative
    if item[-1] == '/':
IndexError: string index out of range while reading includes of binding.gyp while trying to load binding.gyp
gyp ERR! configure error
gyp ERR! stack Error: `gyp` failed with exit code: 1
gyp ERR! stack     at ChildProcess.onCpExit (/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:336:16)
gyp ERR! stack     at emitTwo (events.js:106:13)
gyp ERR! stack     at ChildProcess.emit (events.js:191:7)
gyp ERR! stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:215:12)
gyp ERR! System Darwin 16.6.0
gyp ERR! command "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/bin/node" "/Users/aaronjensen/.asdf/installs/nodejs/6.11.0/.npm/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild"
gyp ERR! cwd /Users/aaronjensen/Source/hello-epics/node_modules/node-pty
gyp ERR! node -v v6.11.0
gyp ERR! node-gyp -v v3.6.2
gyp ERR! not ok
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! node-pty@0.6.6 install: `node scripts/install.js`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the node-pty@0.6.6 install script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /Users/aaronjensen/.npm/_logs/2017-06-08T15_05_14_834Z-debug.log

I can repro this with npm i stmux or, more directly: npm i node-pty

[aaronjensen]

More information, I added some debug statements to node-gyp around the MakePathRelative calls.

From a failing run:

INCLUDES:input.py:391:LoadTargetBuildFile Loading Target Build File 'binding.gyp'
INCLUDES:input.py:300:LoadBuildFileIncludesIntoDict Loading Included File: '/Users/aaronjensen/Source/test/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/test/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: 'deps/icu-small'
INCLUDES:input.py:2142:MergeDicts MakePathRelative: result: 'build/deps/icu-small'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/test/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: 'tools/icu/icu-generic.gyp'
INCLUDES:input.py:2142:MergeDicts MakePathRelative: result: 'build/tools/icu/icu-generic.gyp'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/test/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: ''

From a successful run:

INCLUDES:input.py:391:LoadTargetBuildFile Loading Target Build File 'binding.gyp'
INCLUDES:input.py:300:LoadBuildFileIncludesIntoDict Loading Included File: '/Users/aaronjensen/Source/hello-epics/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/hello-epics/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: 'deps/icu-small'
INCLUDES:input.py:2142:MergeDicts MakePathRelative: result: 'build/deps/icu-small'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/hello-epics/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: 'tools/icu/icu-generic.gyp'
INCLUDES:input.py:2142:MergeDicts MakePathRelative: result: 'build/tools/icu/icu-generic.gyp'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/hello-epics/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: '/deps/uv/'
INCLUDES:input.py:2142:MergeDicts MakePathRelative: result: '/deps/uv/'
INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/hello-epics/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: v: 'icudt58l.dat'
INCLUDES:input.py:2142:MergeDicts MakePathRelative: result: 'build/icudt58l.dat'

SO there is something about /deps/uv that is making it come out empty string in a failing run.

Any ideas? This has one of my machines completely hosed.

[aaronjensen]

Oh, and for what it's worth this repros on a homebrew installed node 8.1.0 (so no asdf in that case).

[aaronjensen]

And more info, on node 8.1.0 the failure mode is slightly different. It actually gets the /deps/uv but then has an extra path that again is an empty string. So it seems like that empty string is leaking in somewhere and it's the problem.

[aaronjensen]

Ok, fixed it. My problem was I had:

scripts-prepend-node-path=false

in my .npmrc, which apparently breaks node-gyp:

INCLUDES:input.py:2137:MergeDicts MakePathRelative: to_file: 'binding.gyp'
INCLUDES:input.py:2138:MergeDicts MakePathRelative: fro_file: '/Users/aaronjensen/Source/test/node_modules/node-pty/build/config.gypi'
INCLUDES:input.py:2139:MergeDicts MakePathRelative: k: 'scripts_prepend_node_path'
INCLUDES:input.py:2140:MergeDicts MakePathRelative: v: ''

This seems like a bug in node-gyp, yeah?

[refack]

@jan-j you also have npm_config_scripts_prepend_node_path: '' in your environment (comes from npm config. You can check with npm config list)

[jan-j]

@refack Yes, I had, not sure how it got there. Builds fine after removing it. Thanks.

[refack]

@refack Yes, I had, not sure how it got there. Builds fine after removing it. Thanks.

Happy I could be of assistance.

[aaronjensen]

Err, why is this closed? Is this not a bug? I set that variable to get rid of a nag warning from npm 5. Now I can't have it set because node gyp treats it like a path.

[jan-j]

@aaronjensen Sorry, I was maybe to eager to close this issue. I'm not really involved with this project, so can't say what can be done about this bug.