Issue: npm install with local packages and symlinks - ENOENT ...

cli
priority:medium
triaged

#1

This is a continuation of issue #21197

What I Wanted to Do

npm install

What Happened Instead

Lots of ENOENT error messages.

Reproduction Steps

git clone git@github.com:MrSpider/npm-bugsample.git
cd npm-bugsample/server
npm install

Details

Steps I have taken that did NOT solve the bug

  • Remove the node_modules folder (I did this after every failed npm install)
  • Clean the npm cache
  • Downgrade npm to v5

npm install does not install transitive dependencies of local dependency
(Kat Marchán) #2

I’ve confirmed this bug in npm@5.7.0, npm@6.1.0 and the current npm@6.2.0 on release-next.

Thanks for the bug report! The repro is super helpful.


(Tim Oxley) #3

I can confirm that this is still an issue on npm@6.4.0.

The good news is that npm ci does not appear to be affected, however this is perhaps a consequence of it rebuilding symlinked dependencies for every consumer, which is a real PITA when the symlinked deps have slow install/build steps. If there were an npm ci --no-rebuild-symlinks or something equivalent then things would be in a good place IMO.


(Tim Oxley) #4

Can confirm issue has been present since npm@5.1.0. npm@5.0.0 through npm@5.0.4 work as expected, npm@5.1.0 and beyond do not.

Error occurs inside /lib/utils/move.js. Hacking maxConcurrency to something different does not prevent ENOENT issues from occurring.


(Tim Oxley) #5

After some poking around I didn’t yet gain a clear picture of what actually was going wrong, but it appears to be something to do with moving packages in and out of the staging area in install/action/finalize.js or install/action/extract.js?

My feeling is that it’s trying to double-handle the dependencies of symlinked dependencies? Maybe needs to dedupe finalize actions based on realpath or it’s missing a pkg.isInLink or some other realpath lookup somewhere? Also interesting that it’s following the stageBundledModule path, maybe that’s in error since this is a symlink not a bundle?

Stack Trace from debug log
21373 verbose stack Error: ENOENT: no such file or directory, rename '/Users/user/Projects/tests/npm-bugsample/server/node_modules/.staging/@shopiq/smp-081285dd/node_modules/@types/events' -> '/Users/
user/Projects/tests/npm-bugsample/server/node_modules/.staging/@types/events-70efa6a7'
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/move-concurrently/move.js:14:12
21373 verbose stack     at rename (/usr/local/lib/node_modules/npm/node_modules/move-concurrently/move.js:74:12)
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/run-queue/queue.js:63:24
21373 verbose stack     at RunQueue._runQueue (/usr/local/lib/node_modules/npm/node_modules/run-queue/queue.js:62:22)
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/run-queue/queue.js:30:12
21373 verbose stack     at RunQueue.run (/usr/local/lib/node_modules/npm/node_modules/run-queue/queue.js:27:24)
21373 verbose stack     at move (/usr/local/lib/node_modules/npm/node_modules/move-concurrently/move.js:46:16)
21373 verbose stack     at wrappedMove (/usr/local/lib/node_modules/npm/lib/utils/move.js:11:10)
21373 verbose stack     at mkdirp.then (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:131:14)
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/mkdirp/index.js:30:20
21373 verbose stack     at FSReqWrap.oncomplete (fs.js:135:15)
21373 verbose stack     at finishModule (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:130:42)
21373 verbose stack     at BB.map.then (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:123:12)
21373 verbose stack     at stageBundledModule (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:122:6)
21373 verbose stack     at BB.map (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:107:14)
21373 verbose stack     at runCallback (timers.js:794:20)
21373 verbose stack     at tryOnImmediate (timers.js:752:5)
21373 verbose stack     at processImmediate [as _immediateCallback] (timers.js:729:5)
21373 verbose stack     at readBundled (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:102:13)
21373 verbose stack     at BB.fromNode.then (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:89:14)
21373 verbose stack     at extract (/usr/local/lib/node_modules/npm/lib/install/action/extract.js:87:6)
21373 verbose stack     at BB.fromNode (/usr/local/lib/node_modules/npm/lib/install/actions.js:75:20)
21373 verbose stack     at runAction (/usr/local/lib/node_modules/npm/lib/install/actions.js:74:13)
21373 verbose stack     at isInstallable.then (/usr/local/lib/node_modules/npm/lib/install/actions.js:54:16)
21373 verbose stack     at actions.(anonymous function) (/usr/local/lib/node_modules/npm/lib/install/actions.js:52:44)
21373 verbose stack     at execAction (/usr/local/lib/node_modules/npm/lib/install/actions.js:191:18)
21373 verbose stack     at runCallback (timers.js:794:20)
21373 verbose stack     at tryOnImmediate (timers.js:752:5)
21373 verbose stack     at processImmediate [as _immediateCallback] (timers.js:729:5)
21373 verbose stack     at withInit (/usr/local/lib/node_modules/npm/lib/install/actions.js:125:15)
21373 verbose stack     at runCallback (timers.js:794:20)
21373 verbose stack     at withInit (/usr/local/lib/node_modules/npm/lib/install/actions.js:175:13)
21373 verbose stack     at doParallel (/usr/local/lib/node_modules/npm/lib/install/actions.js:124:10)
21373 verbose stack     at Array.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/slide/lib/bind-actor.js:15:8)
21373 verbose stack     at LOOP (/usr/local/lib/node_modules/npm/node_modules/slide/lib/chain.js:15:14)
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/slide/lib/chain.js:18:7
21373 verbose stack     at next (/usr/local/lib/node_modules/npm/node_modules/rimraf/rimraf.js:75:7)
21373 verbose stack     at CB (/usr/local/lib/node_modules/npm/node_modules/rimraf/rimraf.js:111:9)
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/rimraf/rimraf.js:137:14
21373 verbose stack     at /usr/local/lib/node_modules/npm/node_modules/graceful-fs/polyfills.js:284:29
21373 verbose stack     at FSReqWrap.oncomplete (fs.js:152:21)

edit 18/08/29:

Interestingly, npm install --no-package-lock & npm install --package-lock-only both work.

Unfortunately, --package-lock-only cannot be used with npm install --save, so in order to get --save while also using package locks, the process is thus:

 # add dependency to package.json & node_modules, without triggering ENOENT
> npm install --save --no-package-lock dependency
 # update package-lock.json to include new dep
> npm install --package-lock-only
# use npm ci to (re)install all dependencies
> npm ci

(Kat Marchán) #6

I think this might be one that @iarna explained to me at what point what results in multiple moves happening. Maybe it had to do with peerDeps or something? I can’t remember.


(Gaston Sanchez) #7

I’m getting this bug inside Docker using image node:8.9.3 with npm version 6.4.1. Any idea when this will get fixed?


(Gaston Sanchez) #8

I fixed it, in my case I’m using an authentication token to download private packages and my token was wrong. I fixed it and it fixed the problem.

It’s a shame though that the error message is misleading.


(Lars Willighagen) #9

This related report also mentions deleting package-lock.json works.


(Cat Ears) #10

I have also investigated this a bit on my workplaces code. I think it is the same problem that occur for us as with npm-bugsample. I verified it with the following patch

diff --git a/lib/install.js b/lib/install.js
index e15bc4791..be2658c93 100644
--- a/lib/install.js
+++ b/lib/install.js
@@ -542,11 +542,23 @@ Installer.prototype.executeActions = function (cb) {
 
   cb = unlockCB(node_modules, '.staging', cb)
 
+  var counter = 0
+  const ping = (cb) => {
+    console.log('#', ++counter)
+    cb()
+  }
+  const debugMe = (cb) => {
+    debugger
+    cb()
+  }
+
   steps.push(
     [doSerialActions, 'global-install', staging, todo, trackLifecycle.newGroup('global-install')],
     [lock, node_modules, '.staging'],
     [rimraf, staging],
+    [ping],
     [doParallelActions, 'extract', staging, todo, cg.newGroup('extract', 100)],
+    [ping],
     [doReverseSerialActions, 'unbuild', staging, todo, cg.newGroup('unbuild')],
     [doSerialActions, 'remove', staging, todo, cg.newGroup('remove')],
     [doSerialActions, 'move', staging, todo, cg.newGroup('move')],
@@ -561,6 +573,8 @@ Installer.prototype.executeActions = function (cb) {
 
   var self = this
   chain(steps, function (er) {
+    console.log('HEREHEREHERE', er)
+    debugMe(() => {})
     if (!er || self.rollback) {
       rimraf(staging, function () { cb(er) })
     } else {

Running npm install under the debugger[1] will only print #1, but not #2 and we reach the debugMe() function in the error handler, which is in line with what @timoxley said in regards to extract being a likely suspect. I looked further into it and for our code the problem occurs in stageBundledModule(), specifically when move is called from within finishModule(). It tries to move a module in node_module from a package present in the local package. Example:

mv ~/npm-bugsample/server/node_modules/.staging/@shopiq/smp-78f181fd/node_modules/@types/events ~/npm-bugsample/server/node_modules/.staging/@types/events-08b3ff65

However when inspecting the file system with the debugger and the following patch:

diff --git a/lib/install/action/extract.js b/lib/install/action/extract.js
index e8d7a6c4f..0c5d39c8b 100644
--- a/lib/install/action/extract.js
+++ b/lib/install/action/extract.js
@@ -125,6 +125,9 @@ function stageBundledModule (bundler, child, staging, parentPath) {
 }
 
 function finishModule (bundler, child, stageTo, stageFrom) {
+  if (stageFrom.includes('smp')) {
+    debugger
+  }
   // If we were the one's who bundled this module…
   if (child.fromBundle === bundler) {
     return mkdirp(path.dirname(stageTo)).then(() => {

I found that no node_modules existed inside any of the submodules, which in the above example would be that the following path would not exist ~/npm-bugsample/server/node_modules/.staging/@shopiq/smp-78f181fd/node_modules but ~/.../smp-78f181fd/ would exist.

Output[2]:

$ pwd
~/npm-bugsample/server/node_modules/.staging/@shopiq/smp-78f181fd
$ ls -la
total 12
drwxr-xr-x 2 XXX XXX 4096 sep  5 09:41 .
drwxr-xr-x 3 XXX XXX 4096 sep  5 09:41 ..
-rw-r--r-- 1 XXX XXX  397 sep  5 09:41 package.json
$ cd ../../
$ fd node_modules
$

I don’t know that much about NPM internals, but it seems that a core assumption about the existance of node_modules, assumed to exist by extract.js is broken when handling submodules (?). Should the node_modules of submodules exist? I have no idea, but I felt like I could contribute something to the issue.

[1] Using npm/cli#latest, applying the patches mentioned in this post, installing with sudo make install and running with node inspect /usr/local/bin/npm install
[2] fd is used to find files


(John Johnson) #11

We are seeing this as well, started happening while trying to make use of the file: specifier. I’ve isolated it to a combination of peer dependencies and file: specifier to link to a local repo.

The first npm install with no lock file works, but after a lock file is created, installing from the lock file doesn’t work.

When I go into the package-lock file and change all instances of "bundled": true to false for the dependencies in the package that is file: linked, it then correctly downloads the dependencies, and npm seems to then find the files correctly.

Error dump below:

npm ERR! path /Users/john/dev/monorepo/node_modules/.staging/@types/react-transition-group-672de1ad
npm ERR! code ENOENT
npm ERR! errno -2
npm ERR! syscall rename
npm ERR! enoent ENOENT: no such file or directory, rename '/Users/john/dev/monorepo/node_modules/.staging/@types/react-transition-group-672de1ad' -> '/Users/john/dev/monorepo/packages/LOCAL_FILE_SPECIFIED_NPM_PACKAGE/node_modules/@types/react-transition-group'
npm ERR! enoent This is related to npm not being able to find a file.

I am trying to repro in a separate shareable repo.


(Cat Ears) #12

I have tried removing so that only the “file:” dependencies are left. I did this both for the package.json file and the package-lock.json file and put them in a new repo. Thanks, @MrSpider for creating the initial repo.

The repo can be found here: https://github.com/CatEars/npm-bugsample

I noticed however that if you remove the package-lock.json file and run npm install it will install correctly, but instead of nesting the dependencies it will put them at the top level (I am guessing so that npm does not run into problems with naming for other packages with same name but different versions at the top level)


(Cat Ears) #13

I found a proof of concept for the bug and have tested different versions of npm to find where the bug might have been introduced. I created a repository with a very small proof of concept, see bottom.

I also tested different versions of npm to see where and when the bug might have been introduced.

| Version      | Worked | Release Date  |
|--------------|--------|---------------|
| 5.10.0       | No     | 11 May 2018   |
| 6.0.1        | No     | 10 May 2018   |
| 6.0.0        | No     | 4 May 2018    |
| 5.9.0-next.0 | Yes    | 15 April 2018 |
| 5.8.0        | Yes    | 24 March 2018 |
| 5.7.1        | Yes    | 22 Feb 2018   |

It seems like the bug was introduced in version 6 of npm, and I am guessing that there is some overlaps in commits between npm@6.0.0 and npm@5.10.0. I believe that the problem is not with lib/install/actions/extract.js as it seems to have been last edited around mid 2017. Or perhaps it should have been updated in response to something else? I’ll look into this a little bit more and try to find where the bug occurs.

git@github.com:CatEars/npm-enoent-bug.git
(Got a “sorry cannot post to that host” when trying to link to github page?)

Edit: By means of git bisect I found that commit 3888d20517593095038caa3cff68d697ae8769a8 is where the bug was introduced.


(John Johnson) #14

This PR seems to fix the issue:

Hopefully this can land soon. Lerna 3.x guidance is to use file: now, so I imagine as more people upgrade Lerna in their monorepo they’ll hit this too. Let me know if I can help in any way.

(from this issue discussion thread: npm install for package with local dependency fails)