npm hangs on Node 6.4.0

[NullDivision]

When running npm i the process hangs with message:

npm iextract:webpack: sill doParallel extract 1000

[mattkime]

which OS? whats does your package.json look like? this is likely due to your setup.

[NullDivision]

Happens an Arch Linux with all packages up to date. Install works fine if I install each package separately but not when installing all of them.

Rolled back to version 6.3.1 and now install works fine.

[codejunkienick]

I can confirm that. I am also having this problem on archlinux but with node 6.4

[NullDivision]

Today I tried doing another update, this time got Node 6.5.0.

Output:

npm WARN deprecated minimatch@2.0.10: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
npm WARN deprecated minimatch@0.2.14: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
npm WARN deprecated lodash@1.0.2: lodash@<3.0.0 is no longer maintained. Upgrade to lodash@^4.0.0.
npm WARN deprecated graceful-fs@1.2.3: graceful-fs v3.0.0 and before will fail on node releases >= v7.0. Please update to graceful-fs@^4.0.0 as soon as possible. Use 'npm ls graceful-fs' to find it in the tree.
npm WARN deprecated cross-spawn-async@2.2.4: cross-spawn no longer requires a build toolchain, use it instead!
[             .....] / extract:webpack-dev-server: sill doParallel extract 1112

Version output:

/home/nulldivision>node -v && npm -v
v6.5.0
3.10.6

EDIT: Also tried clearing NPM cache but it made no difference.

[leafi]

I'm also experiencing the same issue, same distro, same versions.

$ npm i
npm WARN deprecated minimatch@2.0.10: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
          .....] | extract:webpack-validator: sill doParallel extract 914

Npm sits there pegging a core to 100%. I've tried leaving it overnight to no avail.

[leaf@unicorn ~]$ node -v && npm -v
v6.5.0
3.10.6

[NullDivision]

Ok. So far we have confirmation on Arch. Someone should confirm this on another OS/distro.

[addaleax]

Npm sits there pegging a core to 100%.

Can you try attaching a debugger to the process when it’s stuck? gdb -p pid & running backtrace inside gdb should give a proper stack trace, and the output of strace -p pid might also be helpful.

[iscekic]

Same issue, also on Arch.

node --version
v6.5.0
npm --version
3.10.6

My package.json: https://github.com/Torwori/ts-mobx-react-starter-kit/blob/update-deps/package.json

The "hanging":

[             .....] | extract:webpack-dev-server: sill doParallel extract 886

gdb backtrace output:

(gdb) backtrace
#0  0x00007f488a5c9171 in write () from /usr/lib/libpthread.so.0
#1  0x00007f488a9eff85 in ?? () from /usr/lib/libuv.so.1
#2  0x00007f488a9f041f in ?? () from /usr/lib/libuv.so.1
#3  <signal handler called>
#4  0x0000000000989f95 in v8::internal::FieldType::AsClass() ()
#5  0x000000000098a0f4 in v8::internal::FieldType::Convert(v8::internal::Zone*) ()
#6  0x0000000000787c8b in v8::internal::compiler::AccessInfoFactory::ComputePropertyAccessInfo(v8::internal::Handle<v8::internal::Map>, v8::internal::Handle<v8::internal::Name>, v8::internal::compiler::AccessMode, v8::internal::compiler::PropertyAccessInfo*) ()
#7  0x000000000078831e in v8::internal::compiler::AccessInfoFactory::ComputePropertyAccessInfos(v8::internal::List<v8::internal::Handle<v8::internal::Map>, v8::internal::FreeStoreAllocationPolicy> const&, v8::internal::Handle<v8::internal::Name>, v8::internal::compiler::AccessMode, v8::internal::ZoneVector<v8::internal::compiler::PropertyAccessInfo>*) ()
#8  0x00000000007f9566 in v8::internal::compiler::JSNativeContextSpecialization::ReduceNamedAccess(v8::internal::compiler::Node*, v8::internal::compiler::Node*, v8::internal::List<v8::internal::Handle<v8::internal::Map>, v8::internal::FreeStoreAllocationPolicy> const&, v8::internal::Handle<v8::internal::Name>, v8::internal::compiler::AccessMode, v8::internal::LanguageMode, v8::internal::compiler::Node*) ()
#9  0x00000000007fb3af in v8::internal::compiler::JSNativeContextSpecialization::ReduceNamedAccess(v8::internal::compiler::Node*, v8::internal::compiler::Node*, v8::internal::FeedbackNexus const&, v8::internal::Handle<v8::internal::Name>, v8::internal::compiler::AccessMode, v8::internal::LanguageMode) ()
#10 0x00000000007fb43f in v8::internal::compiler::JSNativeContextSpecialization::ReduceJSLoadNamed(v8::internal::compiler::Node*) ()
#11 0x00000000007fda15 in v8::internal::compiler::JSNativeContextSpecialization::Reduce(v8::internal::compiler::Node*) ()
#12 0x00000000007ca506 in v8::internal::compiler::GraphReducer::Reduce(v8::internal::compiler::Node*) ()
#13 0x00000000007caf5c in v8::internal::compiler::GraphReducer::ReduceTop() ()
#14 0x00000000007cb088 in v8::internal::compiler::GraphReducer::ReduceNode(v8::internal::compiler::Node*) ()
#15 0x00000000008325ed in v8::internal::compiler::Pipeline::GenerateCode() ()
#16 0x00000000008895a2 in v8::internal::OptimizedCompileJob::CreateGraph() ()
#17 0x000000000088a945 in ?? ()
#18 0x000000000088b6d9 in v8::internal::Compiler::CompileOptimized(v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Compiler::ConcurrencyMode) ()
#19 0x0000000000b63e05 in v8::internal::Runtime_CompileOptimized_Concurrent(int, v8::internal::Object**, v8::internal::Isolate*) ()
#20 0x000024abc6e092a7 in ?? ()
#21 0x000024abc6e091e1 in ?? ()
#22 0x00007ffc39673740 in ?? ()
#23 0x0000000300000000 in ?? ()
#24 0x00007ffc39673798 in ?? ()
#25 0x000024abc6e3ba38 in ?? ()
#26 0x000037f4771a6cd9 in ?? ()
#27 0x000025b36eb04381 in ?? ()
#28 0x000037f4771a6cd9 in ?? ()
#29 0x0000000000000000 in ?? ()

strace output:

--- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
read(3, "*", 1)                         = 1
write(7, "X\3072\2\0\0\0\0\v\0\0\0\0\0\0\0", 16) = -1 EAGAIN (Resource temporarily unavailable)
write(4, "*", 1)                        = 1
rt_sigreturn({mask=[]})                 = 0
--- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
read(3, "*", 1)                         = 1
write(7, "X\3072\2\0\0\0\0\v\0\0\0\0\0\0\0", 16) = -1 EAGAIN (Resource temporarily unavailable)
write(4, "*", 1)                        = 1
rt_sigreturn({mask=[]})                 = 0
--- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
... and so on

[addaleax]

@Torwori That looks like something different… your process doesn’t hang with 100 % CPU, does it?

Your problem looks like nodejs/node#8310 (where more information is certainly likely to be useful, too) … I assume that only occurs since Node v6.5.0?

[iscekic]

@addaleax It uses 100%. I left it running for an hour and then had to SIGKILL it.

I'll try Node v6.4.0 and let you know.

[addaleax]

@Torwori oh, that seems like useful information on why the process hangs then… would be really good to know if the same stack trace appears with v6.4.0.

Also, do you happen to have anything installed that handles segmentation faults? Can you run your npm install command wrapped in strace, like this: strace -fe execve npm install?

I really appreciate your help with digging into this!

[iscekic]

@addaleax Just tried npm install with Node v6.4.0, works fine.

Also, do you happen to have anything installed that handles segmentation faults?

Not that I know of.

strace -fe execve npm install (Node v6.5.0) output:

execve("/usr/bin/npm", ["npm", "install"], [/* 46 vars */]) = 0
execve("/usr/local/sbin/node", ["node", "/usr/bin/npm", "install"], [/* 46 vars */]) = -1 ENOENT (No such file or directory)
execve("/usr/local/bin/node", ["node", "/usr/bin/npm", "install"], [/* 46 vars */]) = -1 ENOENT (No such file or directory)
execve("/usr/bin/node", ["node", "/usr/bin/npm", "install"], [/* 46 vars */]) = 0
strace: Process 3227 attached
strace: Process 3226 attached
strace: Process 3225 attached
strace: Process 3224 attached
strace: Process 3223 attached
strace: Process 3231 attached
strace: Process 3230 attached
strace: Process 3229 attached
strace: Process 3228 attached
[pid  3222] --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
[pid  3222] --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
[pid  3222] --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
[pid  3222] --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x38} ---
... until I stopped it

[addaleax]

So… repeated SIGSEGVs usually mean that something is trying to handle the segmentation fault (which would otherwise just crash the program) and tries to continue executing… I’ll try to reproduce this myself, maybe it’ll “work” in a VM.

A more or less brute-force way to inspect the situation would be looking at the disassembly in one of the stack frames above the signal handler (the #2 0x00007f488a9f041f in ?? () from /usr/lib/libuv.so.1 lines from your gdb output)… if you don’t mind, you could run

(gdb) frame 2
(gdb) disassemble $rip-40,$rip+40

which shows what exactly is being executed after each SIGSEGV.

[iscekic]

@addaleax Output:

Dump of assembler code from 0x7fe70e3bf308 to 0x7fe70e3bf358:
   0x00007fe70e3bf308:  xor    0x28,%rsi
   0x00007fe70e3bf310:  jne    0x7fe70e3bf329
   0x00007fe70e3bf312:  add    $0xa8,%rsp
   0x00007fe70e3bf319:  retq   
   0x00007fe70e3bf31a:  nopw   0x0(%rax,%rax,1)
   0x00007fe70e3bf320:  mov    %rdx,%rax
   0x00007fe70e3bf323:  jmp    0x7fe70e3bf2f4
   0x00007fe70e3bf325:  xor    %eax,%eax
   0x00007fe70e3bf327:  jmp    0x7fe70e3bf2ff
   0x00007fe70e3bf329:  callq  0x7fe70e3b33f0 <__stack_chk_fail@plt>
   0x00007fe70e3bf32e:  xchg   %ax,%ax
=> 0x00007fe70e3bf330:  push   %r14
   0x00007fe70e3bf332:  push   %r13
   0x00007fe70e3bf334:  mov    %edi,%r13d
   0x00007fe70e3bf337:  push   %r12
   0x00007fe70e3bf339:  push   %rbp
   0x00007fe70e3bf33a:  push   %rbx
   0x00007fe70e3bf33b:  sub    $0x20,%rsp
   0x00007fe70e3bf33f:  mov    %fs:0x28,%rax
   0x00007fe70e3bf348:  mov    %rax,0x18(%rsp)
   0x00007fe70e3bf34d:  xor    %eax,%eax
   0x00007fe70e3bf34f:  callq  0x7fe70e3b3160 <__errno_location@plt>
   0x00007fe70e3bf354:  movq   $0x0,(%rsp)
End of assembler dump.