Possible issue with pre-commit + npm + spawn env

[sudo-suhas]

When cross-spawn is invoked in a pre-commit hook code by husky, if the process.env is used, npm command errors out inexplicably on windows:

λ git commit
husky > npm run -s precommit (node v8.5.0)

,,

husky > pre-commit hook failed (add --no-verify to bypass)

On manually removing the silent(-s) flag in the husky pre-commit hook(subl ./.git/hooks/pre-commit), we can see the error logs:

npm error logs

λ git commit
husky > npm run precommit (node v8.5.0)


> test-cross-spawn-env@1.0.0 precommit E:\Projects\experiments\test-cross-spawn-env
> npm run spawn


> test-cross-spawn-env@1.0.0 spawn E:\Projects\experiments\test-cross-spawn-env
> node spawn.js

npm WARN invalid config access=undefined
npm WARN invalid config also=undefined
npm WARN invalid config https-proxy=undefined
npm WARN invalid config Must be a full url with 'http://'
npm WARN invalid config init-author-url=undefined
npm WARN invalid config Must be a full url with 'http://'
npm WARN invalid config only=undefined
npm WARN invalid config proxy=undefined
npm WARN invalid config Must be a full url with 'http://'
npm WARN onload-script failed to require onload script undefined
npm WARN onload-script Error: Cannot find module 'undefined'
npm WARN onload-script     at Function.Module._resolveFilename (module.js:527:15)
npm WARN onload-script     at Function.Module._load (module.js:476:23)
npm WARN onload-script     at Module.require (module.js:568:17)
npm WARN onload-script     at require (internal/module.js:11:18)
npm WARN onload-script     at cb (C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:225:11)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:356:16
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:81:7
npm WARN onload-script     at Array.forEach (<anonymous>)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:80:13
npm WARN onload-script     at f (C:\nvm\v8.5.0\node_modules\npm\node_modules\once\once.js:25:25)
npm WARN onload-script  { Error: Cannot find module 'undefined'
npm WARN onload-script     at Function.Module._resolveFilename (module.js:527:15)
npm WARN onload-script     at Function.Module._load (module.js:476:23)
npm WARN onload-script     at Module.require (module.js:568:17)
npm WARN onload-script     at require (internal/module.js:11:18)
npm WARN onload-script     at cb (C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:225:11)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:356:16
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:81:7
npm WARN onload-script     at Array.forEach (<anonymous>)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:80:13
npm WARN onload-script     at f (C:\nvm\v8.5.0\node_modules\npm\node_modules\once\once.js:25:25)
npm WARN onload-script   stack: 'Error: Cannot find module \'undefined\'\n    at Function.Module._resolveFilename (module.js:527:15)\n    at Function.Module._load (module.js:476:23)\n    at Module.require (module.js:568:17)\n    at require (internal/module.js:11:18)\n    at cb (C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\npm.js:225:11)\n
    at C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\npm.js:356:16\n    at C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\config\\core.js:81:7\n    at Array.forEach (<anonymous>)\n    at C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\config\\core.js:80:13\n    at f (C:\\nvm\\v8.5.0\\node_modules\\npm\\node_modules\\once\\once.js:25:25)',
npm WARN onload-script   code: 'MODULE_NOT_FOUND' }
npm WARN invalid config access=undefined
npm WARN invalid config also=undefined
npm WARN invalid config https-proxy=undefined
npm WARN invalid config Must be a full url with 'http://'
npm WARN invalid config init-author-url=undefined
npm WARN invalid config Must be a full url with 'http://'
npm WARN invalid config only=undefined
npm WARN invalid config proxy=undefined
npm WARN invalid config Must be a full url with 'http://'
npm WARN onload-script failed to require onload script undefined
npm WARN onload-script Error: Cannot find module 'undefined'
npm WARN onload-script     at Function.Module._resolveFilename (module.js:527:15)
npm WARN onload-script     at Function.Module._load (module.js:476:23)
npm WARN onload-script     at Module.require (module.js:568:17)
npm WARN onload-script     at require (internal/module.js:11:18)
npm WARN onload-script     at cb (C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:225:11)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:356:16
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:81:7
npm WARN onload-script     at Array.forEach (<anonymous>)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:80:13
npm WARN onload-script     at f (C:\nvm\v8.5.0\node_modules\npm\node_modules\once\once.js:25:25)
npm WARN onload-script  { Error: Cannot find module 'undefined'
npm WARN onload-script     at Function.Module._resolveFilename (module.js:527:15)
npm WARN onload-script     at Function.Module._load (module.js:476:23)
npm WARN onload-script     at Module.require (module.js:568:17)
npm WARN onload-script     at require (internal/module.js:11:18)
npm WARN onload-script     at cb (C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:225:11)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\npm.js:356:16
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:81:7
npm WARN onload-script     at Array.forEach (<anonymous>)
npm WARN onload-script     at C:\nvm\v8.5.0\node_modules\npm\lib\config\core.js:80:13
npm WARN onload-script     at f (C:\nvm\v8.5.0\node_modules\npm\node_modules\once\once.js:25:25)
npm WARN onload-script   stack: 'Error: Cannot find module \'undefined\'\n    at Function.Module._resolveFilename (module.js:527:15)\n    at Function.Module._load (module.js:476:23)\n    at Module.require (module.js:568:17)\n    at require (internal/module.js:11:18)\n    at cb (C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\npm.js:225:11)\n
    at C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\npm.js:356:16\n    at C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\config\\core.js:81:7\n    at Array.forEach (<anonymous>)\n    at C:\\nvm\\v8.5.0\\node_modules\\npm\\lib\\config\\core.js:80:13\n    at f (C:\\nvm\\v8.5.0\\node_modules\\npm\\node_modules\\once\\once.js:25:25)',
npm WARN onload-script   code: 'MODULE_NOT_FOUND' }

> test-cross-spawn-env@1.0.0 hello E:\Projects\experiments\test-cross-spawn-env
> node index.js

npm ERR! file undefined
npm ERR! path undefined
npm ERR! code ELIFECYCLE
npm ERR! errno ENOENT
npm ERR! syscall spawn undefined
npm ERR! test-cross-spawn-env@1.0.0 hello: `node index.js`
npm ERR! spawn undefined ENOENT
npm ERR!
npm ERR! Failed at the test-cross-spawn-env@1.0.0 hello script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
npm ERR! code ELIFECYCLE
npm ERR! errno -4058
npm ERR! test-cross-spawn-env@1.0.0 hello: `node index.js`
npm ERR! Exit status -4058
npm ERR!
npm ERR! Failed at the test-cross-spawn-env@1.0.0 hello 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!     C:\Users\suhas.karanth\AppData\Roaming\npm-cache\_logs\2017-09-21T04_55_49_244Z-debug.log
,,
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! test-cross-spawn-env@1.0.0 spawn: `node spawn.js`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the test-cross-spawn-env@1.0.0 spawn 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!     C:\Users\suhas.karanth\AppData\Roaming\npm-cache\_logs\2017-09-21T04_55_49_341Z-debug.log
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! test-cross-spawn-env@1.0.0 precommit: `npm run spawn`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the test-cross-spawn-env@1.0.0 precommit 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!     C:\Users\suhas.karanth\AppData\Roaming\npm-cache\_logs\2017-09-21T04_55_49_408Z-debug.log

husky > pre-commit hook failed (add --no-verify to bypass)

I faced and fixed these issues in a couple of places. The solution was to filter process.env for undefined values:

Repo	Issue	PR
kentcdodds/kcd-scripts	kentcdodds/kcd-scripts#4	kentcdodds/kcd-scripts#5
ta2edchimp/opt-cli	sezna/nps#155	ta2edchimp/opt-cli#213

I have created a repo for demonstrating the issue - https://github.com/sudo-suhas/test-cross-spawn-env

I am not entirely sure if this is a problem which cross-spawn should handle. Thoughts?

cc @kentcdodds

[sudo-suhas]

If I switch everything out to yarn, this happens:

λ git commit
husky > yarn run precommit (node v8.5.0)

yarn run v1.0.2
warning ..\package.json: No license field
$ npm run spawn

> test-cross-spawn-env@1.0.0 spawn E:\Projects\experiments\test-cross-spawn-env
> node spawn.js

warning ..\package.json: No license field
error Could not open cafile: ENOENT: no such file or directory, open 'E:\Projects\experiments\test-cross-spawn-env\undefined'
hello
,,
Done in 2.35s.

Does not fail but still causes an error somewhere.

[evocateur]

I found this to be a problem only in Windows (on AppVeyor hosts, specifically). Runs on linux (TravisCI) and OS X do not exhibit this problem.

The cheesy workaround is to add --no-onload-script to any npm calls, but as this is just duplicating what should be the default for that option, it's not a long-term solution.

[sudo-suhas]

You could also filter process.env for undefined values to fix this issue. That was how we had fixed the issue in kcd-scripts and opt-cli.

[satazor]

@sudo-suhas I've cloned the repository that you have created but I was unable to reproduce the error on Windows.

C:\Work\test-cross-spawn-env>git commit -m'foo'
husky > npm run -s precommit (node v8.9.1)

hello
,,
[master 030a66e] 'foo'
1 file changed, 0 insertions(+), 0 deletions(-)
create mode 100644 fdsfs.txt

C:\Work\test-cross-spawn-env>

I'm running node v8.9. Could you please help me reproduce?

[sudo-suhas]

This is very odd but I am not able to reproduce the issue either. I am no longer seeing undefined values in process.env. This could be because I updated cmder version but I am not sure. I am closing this for now. I will reopen it if I am able to reproduce the issue.