Node: degrading performance after using child_process

Created on 10 Mar 2016 · 44Comments · Source: nodejs/node

After running a child process ( using exec or spawn ) I have found that the performance of my node.js application decreases by a factor of 10. Below is a contrived example and output.

var exec = require('child_process').exec;

function runExpensiveOperation(times) {
  while(times > 0) {
    console.time('expensiveOperation');
    var str = 'lorem';
    for ( var i=0;i< 10000000; i++) {
      // string concatenation
      str = str.length < 1000 ? str + str : '';
      // math operation
      i * i * i;
    }
    console.timeEnd('expensiveOperation');
    times--;
  }
}

console.log('PRE EXEC');
runExpensiveOperation(10);
exec('echo "hello"');
console.log('POST EXEC');
runExpensiveOperation(10);

Output:

PRE EXEC
expensiveOperation: 66.458ms
expensiveOperation: 65.735ms
expensiveOperation: 69.237ms
expensiveOperation: 65.269ms
expensiveOperation: 69.133ms
expensiveOperation: 65.639ms
expensiveOperation: 67.944ms
expensiveOperation: 63.595ms
expensiveOperation: 64.153ms
expensiveOperation: 65.093ms
POST EXEC
expensiveOperation: 715.861ms
expensiveOperation: 739.671ms
expensiveOperation: 714.546ms
expensiveOperation: 714.845ms
expensiveOperation: 745.719ms
expensiveOperation: 743.240ms
expensiveOperation: 716.481ms
expensiveOperation: 732.916ms
expensiveOperation: 736.576ms
expensiveOperation: 742.416ms

In addition, this problem only occurs if the string concatenation AND math operation are run in the expensiveOperation - if either are commented out then there is no issue.

Version: 5.8.0
Platform: Darwin Kernel Version 15.3.0: Thu Dec 10 18:40:58 PST 2015; root:xnu-3248.30.4~1/RELEASE_X86_64 x86_64 ( Macbook Air OS X El Capitan )
Subsystem: child_process

child_process confirmed-bug macos performance

Source

dannymarsland

Most helpful comment

@Okahyphen thanks a lot for the data.

Here's the V8 bug corresponding to this issue: https://bugs.chromium.org/p/v8/issues/detail?id=4406. This is a mac specific issue in how signals interact with applications that use a mix of AVX and SSE instructions (although I would be interested in knowing if anyone on BSDs, on similar hardware, is also affected).

There are quite a few CLs attached to that bug that will need to be backported if we want to fix this in v4.x and v5.x. A simpler work-around might be to force the use of --noenable-avx on mac on AVX1 hardware.

ofrobots on 16 Mar 2016

👍2

All 44 comments

For reference http://stackoverflow.com/questions/35906269/node-js-degrading-performance-after-using-child-process - I have been updating this stackoverflow post with further information

dannymarsland on 10 Mar 2016

Can somebody confirm for OSX?
I don't have the same result on my computer (Fedora):

PRE EXEC
expensiveOperation: 37.305ms
expensiveOperation: 34.988ms
expensiveOperation: 34.839ms
expensiveOperation: 34.765ms
expensiveOperation: 34.869ms
expensiveOperation: 34.982ms
expensiveOperation: 34.929ms
expensiveOperation: 34.933ms
expensiveOperation: 34.900ms
expensiveOperation: 34.983ms
POST EXEC
expensiveOperation: 35.165ms
expensiveOperation: 34.794ms
expensiveOperation: 35.024ms
expensiveOperation: 34.812ms
expensiveOperation: 34.906ms
expensiveOperation: 34.922ms
expensiveOperation: 34.948ms
expensiveOperation: 35.160ms
expensiveOperation: 34.889ms
expensiveOperation: 35.936ms

targos on 10 Mar 2016

That's odd. I cannot reproduce on the exact same version of OS X

PRE EXEC
expensiveOperation: 32.146ms
expensiveOperation: 32.203ms
expensiveOperation: 31.290ms
expensiveOperation: 31.927ms
expensiveOperation: 30.191ms
expensiveOperation: 31.287ms
expensiveOperation: 30.355ms
expensiveOperation: 31.618ms
expensiveOperation: 30.189ms
expensiveOperation: 31.471ms
POST EXEC
expensiveOperation: 31.127ms
expensiveOperation: 31.332ms
expensiveOperation: 31.658ms
expensiveOperation: 31.066ms
expensiveOperation: 31.984ms
expensiveOperation: 30.074ms
expensiveOperation: 31.532ms
expensiveOperation: 30.624ms
expensiveOperation: 32.839ms
expensiveOperation: 30.665ms

evanlucas on 10 Mar 2016

How much memory your machine have and free? Could be GC hit early for you.
No problem with node 5.8.0 for me too, but different version of OSX

PRE EXEC
expensiveOperation: 53.951ms
expensiveOperation: 50.099ms
expensiveOperation: 49.237ms
expensiveOperation: 48.571ms
expensiveOperation: 48.465ms
expensiveOperation: 48.547ms
expensiveOperation: 48.973ms
expensiveOperation: 49.612ms
expensiveOperation: 49.372ms
expensiveOperation: 50.159ms
POST EXEC
expensiveOperation: 48.647ms
expensiveOperation: 49.510ms
expensiveOperation: 51.474ms
expensiveOperation: 49.291ms
expensiveOperation: 50.234ms
expensiveOperation: 48.961ms
expensiveOperation: 49.992ms
expensiveOperation: 48.754ms
expensiveOperation: 49.944ms
expensiveOperation: 50.800ms

S-YOU on 10 Mar 2016

Tested on 5.7.1 on a few of our test machines, including centos5, 6, 7, fedora 22, 23, FreeBSD 10 and SmartOS. Architectures: x64, x86 and ppc_le. Was not able to reproduce.

jbergstroem on 10 Mar 2016

(some of the machines ran 6.0-pre)

jbergstroem on 10 Mar 2016

I tried to boot into El Capitan, initial version 15.0.0. I can replicate now,
but I suspect it is OS issue, I normally use Mavericks because it is faster noticebly.

PRE EXEC
expensiveOperation: 53.461ms
expensiveOperation: 49.009ms
expensiveOperation: 48.811ms
expensiveOperation: 49.489ms
expensiveOperation: 60.916ms
expensiveOperation: 54.600ms
expensiveOperation: 48.435ms
expensiveOperation: 48.636ms
expensiveOperation: 49.117ms
expensiveOperation: 49.927ms
POST EXEC
expensiveOperation: 574.301ms
expensiveOperation: 602.717ms
expensiveOperation: 600.876ms
expensiveOperation: 578.266ms
expensiveOperation: 589.287ms
expensiveOperation: 574.418ms
expensiveOperation: 575.203ms
expensiveOperation: 572.978ms
expensiveOperation: 577.649ms
expensiveOperation: 568.333ms

S-YOU on 10 Mar 2016

I was unable to replicate on Ubuntu, running on a basic VPS, with Node 5.8.0:

$ uname -a
Linux _ 3.13.0-29-generic #53-Ubuntu SMP Wed Jun 4 21:00:20 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
$ node --version
v5.8.0
$ node qk.js 
PRE EXEC
expensiveOperation: 52.308ms
expensiveOperation: 49.528ms
expensiveOperation: 49.994ms
expensiveOperation: 49.998ms
expensiveOperation: 49.637ms
expensiveOperation: 49.430ms
expensiveOperation: 49.556ms
expensiveOperation: 49.726ms
expensiveOperation: 49.977ms
expensiveOperation: 49.739ms
POST EXEC
expensiveOperation: 49.613ms
expensiveOperation: 49.086ms
expensiveOperation: 49.447ms
expensiveOperation: 49.608ms
expensiveOperation: 49.154ms
expensiveOperation: 49.964ms
expensiveOperation: 49.403ms
expensiveOperation: 49.237ms
expensiveOperation: 49.427ms
expensiveOperation: 49.625ms

But I can consistently replicate this on an OS X 10.11.3 machine, with any 4.x.x or 5.x.x version of Node:

Oka at XI in ~
↪ uname -a
Darwin XI.local 15.3.0 Darwin Kernel Version 15.3.0: Thu Dec 10 18:40:58 PST 2015; root:xnu-3248.30.4~1/RELEASE_X86_64 x86_64
Oka at XI in ~                                                                                                                               
↪ sw_vers
ProductName:    Mac OS X
ProductVersion: 10.11.3
BuildVersion:   15D21

Oka at XI in ~                                                                                                                               
↪ node --version
v5.8.0                                                                                                                              
↪ node osx.js
PRE EXEC
expensiveOperation: 53.091ms
expensiveOperation: 47.818ms
expensiveOperation: 49.784ms
expensiveOperation: 47.095ms
expensiveOperation: 49.638ms
expensiveOperation: 48.141ms
expensiveOperation: 46.363ms
expensiveOperation: 48.686ms
expensiveOperation: 47.384ms
expensiveOperation: 48.432ms
POST EXEC
expensiveOperation: 515.337ms
expensiveOperation: 583.728ms
expensiveOperation: 578.323ms
expensiveOperation: 581.836ms
expensiveOperation: 589.195ms
expensiveOperation: 586.495ms
expensiveOperation: 592.385ms
expensiveOperation: 592.540ms
expensiveOperation: 587.055ms
expensiveOperation: 569.888ms

Oka at XI in ~                                                                                                                               
↪ node --version
v4.4.0
Oka at XI in ~                                                                                                                               
↪ node osx.js
PRE EXEC
expensiveOperation: 44ms
expensiveOperation: 47ms
expensiveOperation: 44ms
expensiveOperation: 48ms
expensiveOperation: 49ms
expensiveOperation: 41ms
expensiveOperation: 43ms
expensiveOperation: 42ms
expensiveOperation: 45ms
expensiveOperation: 47ms
POST EXEC
expensiveOperation: 537ms
expensiveOperation: 537ms
expensiveOperation: 546ms
expensiveOperation: 535ms
expensiveOperation: 538ms
expensiveOperation: 545ms
expensiveOperation: 542ms
expensiveOperation: 521ms
expensiveOperation: 535ms
expensiveOperation: 525ms

Node version 0.12.12 for comparison:

Oka at XI in ~                                                                                                                               
↪ node --version
v0.12.12
Oka at XI in ~                                                                                                                               
↪ node osx.js
PRE EXEC
expensiveOperation: 59ms
expensiveOperation: 51ms
expensiveOperation: 47ms
expensiveOperation: 49ms
expensiveOperation: 49ms
expensiveOperation: 53ms
expensiveOperation: 47ms
expensiveOperation: 51ms
expensiveOperation: 52ms
expensiveOperation: 50ms
POST EXEC
expensiveOperation: 50ms
expensiveOperation: 54ms
expensiveOperation: 51ms
expensiveOperation: 46ms
expensiveOperation: 52ms
expensiveOperation: 47ms
expensiveOperation: 48ms
expensiveOperation: 53ms
expensiveOperation: 48ms
expensiveOperation: 51ms

okahyphen on 10 Mar 2016

I can reproduce on OS X 10.10.5 and Node v5.8.0:

Jeremiah@Jeremiahs-MacBook-Pro ~/D/here-be-dragons> node nodejs-5636.js 
PRE EXEC
expensiveOperation: 52.686ms
expensiveOperation: 41.100ms
expensiveOperation: 45.590ms
expensiveOperation: 45.547ms
expensiveOperation: 40.771ms
expensiveOperation: 41.216ms
expensiveOperation: 40.663ms
expensiveOperation: 43.700ms
expensiveOperation: 40.910ms
expensiveOperation: 41.425ms
POST EXEC
expensiveOperation: 613.715ms
expensiveOperation: 611.490ms
expensiveOperation: 619.924ms
expensiveOperation: 616.452ms
expensiveOperation: 627.340ms
expensiveOperation: 583.962ms
expensiveOperation: 603.324ms
expensiveOperation: 600.201ms
expensiveOperation: 589.123ms
expensiveOperation: 628.575ms

Fishrock123 on 10 Mar 2016

Looks like it appeared between iojs v1.x and v3.x ... I'll run a bisect.

v1.x:

Jeremiah@Jeremiahs-MacBook-Pro ~/D/here-be-dragons> 
../node/node nodejs-5636.js 
PRE EXEC
expensiveOperation: 48.087ms
...
POST EXEC
expensiveOperation: 45.235ms
...

v3.x:

Jeremiah@Jeremiahs-MacBook-Pro ~/D/here-be-dragons> 
../node/iojs nodejs-5636.js 
PRE EXEC
expensiveOperation: 43ms
...
POST EXEC
expensiveOperation: 590ms
...

Fishrock123 on 10 Mar 2016

git bisect says it's a v8 problem?

36cd5fb9d27b830320e57213f5b8829ffbb93324 is the first bad commit
commit 36cd5fb9d27b830320e57213f5b8829ffbb93324
Author: Ben Noordhuis <[email protected]>
Date:   Fri Mar 27 12:04:12 2015 +0100

    deps: upgrade v8 to 4.2.77.13

    This commit applies some secondary changes in order to make `make test`
    pass cleanly:

    * disable broken postmortem debugging in common.gypi

    * drop obsolete strict mode test in parallel/test-repl

    * drop obsolete test parallel/test-v8-features

    PR-URL: https://github.com/iojs/io.js/pull/1232
    Reviewed-By: Fedor Indutny <[email protected]>

:100644 100644 ea7779ee097a6966d317527320273d894294829d 8aee4eaaf749c15a909b5218a33535c0392723ed M  common.gypi
:040000 040000 7bedb40d00ebc73e01ce1edf96d1ef261bd343d1 e4f8c13bfc945eb42fe41541628c88a5aaaa9a99 M  deps
:040000 040000 c1c61ebdb89e84aa8fd5c2e29c9f6a6629cb326d 50b85faabaaf67ae8f5f8aab26dcafec5f64e418 M  test

cc @nodejs/v8

Fishrock123 on 10 Mar 2016

I tried to reproduce this and am seeing only a few calls slowing down after the call to exec:

PRE EXEC
expensiveOperation: 47ms
expensiveOperation: 44ms
expensiveOperation: 46ms
expensiveOperation: 49ms
expensiveOperation: 50ms
expensiveOperation: 48ms
expensiveOperation: 46ms
expensiveOperation: 50ms
expensiveOperation: 47ms
expensiveOperation: 49ms
POST EXEC
expensiveOperation: 583ms
expensiveOperation: 598ms
expensiveOperation: 609ms
expensiveOperation: 556ms
expensiveOperation: 43ms
expensiveOperation: 46ms
expensiveOperation: 48ms
expensiveOperation: 52ms
expensiveOperation: 52ms
expensiveOperation: 53ms

Additionally, the behavior doesn't reproduce reliably and some runs are fast on both sides of the exec. I looked at the optimizations and deoptimizations for both fast an slow runs and V8 is reporting the same trace of opts-deopts in both cases. @Fishrock123 Were you able to reproduce the issue consistently?

matthewloring on 11 Mar 2016

This behaviour actually happens AFTER the child process has completed, the performance degradation is not present during the execution of the child process - see the following example :

console.log('PRE SPAWN');
runExpensiveOperation(10);
// simple endpoint that holds the http request for 3 seconds
var process = spawn('curl',['https://httpbin.org/delay/3']);
process.on('exit', function(){
  console.log('SPAWN EXIT');
  runExpensiveOperation(10);
});
setTimeout(function(){
  console.log('POST SPAWN');
  runExpensiveOperation(10);
},100);

Output :

PRE SPAWN
expensiveOperation: 68.140ms
expensiveOperation: 64.574ms
expensiveOperation: 65.773ms
expensiveOperation: 71.974ms
expensiveOperation: 63.766ms
expensiveOperation: 66.595ms
expensiveOperation: 71.057ms
expensiveOperation: 62.015ms
expensiveOperation: 76.570ms
expensiveOperation: 75.234ms
POST SPAWN
expensiveOperation: 75.726ms
expensiveOperation: 70.672ms
expensiveOperation: 66.938ms
expensiveOperation: 68.169ms
expensiveOperation: 73.752ms
expensiveOperation: 76.147ms
expensiveOperation: 68.912ms
expensiveOperation: 75.144ms
expensiveOperation: 74.116ms
expensiveOperation: 67.488ms
SPAWN EXIT
expensiveOperation: 782.959ms
expensiveOperation: 769.501ms
expensiveOperation: 771.076ms
expensiveOperation: 737.611ms
expensiveOperation: 708.857ms
expensiveOperation: 716.193ms
expensiveOperation: 704.008ms
expensiveOperation: 707.031ms
expensiveOperation: 701.662ms
expensiveOperation: 714.501ms

dannymarsland on 11 Mar 2016

👍1

I have personally tested this on 2 machines running OS X El Capitan 10.11.3. This issue is present on a Macbook Air (~2013) but not on a Macbook Retina Pro.

dannymarsland on 11 Mar 2016

I can reliably reproduce the behaviour and happy to help if you need any further information

dannymarsland on 11 Mar 2016

@dannymarsland were the tests conducted on the different Macbooks performed using the same version of Node (5.8.0)?

matthewloring on 11 Mar 2016

@matthewloring yes they were both using 5.8.0 . I actually asked 5 colleagues to test it, all with Macbook Retina Pros ( I can't clarify which node version they were running, but i assume ~5 ) and none of them had the issue

dannymarsland on 12 Mar 2016

I have also test with node 4.0.0 and 0.12.12. There is no problem with 0.12.12 but the issue is there with version 4.0.0

dannymarsland on 12 Mar 2016

@dannymarsland Unfortunately, I don't have a computer that can reproduce this. Would you be able to try your above test case again but ignoring the child process output:

console.log('PRE SPAWN');
runExpensiveOperation(10);
// simple endpoint that holds the http request for 3 seconds
var process = spawn('curl',['https://httpbin.org/delay/3'],{stdio: 'ignore'});
process.on('exit', function(){
  console.log('SPAWN EXIT');
  runExpensiveOperation(10);
});
setTimeout(function(){
  console.log('POST SPAWN');
  runExpensiveOperation(10);
},100);

I suspect what you're seeing may be related to: https://github.com/nodejs/node/issues/3429.

matthewloring on 12 Mar 2016

@matthewloring Yeah, I was able to reproduce it consistently after but not before that commit.

Fishrock123 on 12 Mar 2016

@matthewloring the issue still occurs when ignoring the process output

dannymarsland on 13 Mar 2016

Is it possible that the affected machines have AVX enabled and the unaffected machines don't?

bnoordhuis on 14 Mar 2016

My machine (unaffected) has AVX/AVX2 support. @bnoordhuis How would I determine whether it is enabled?

matthewloring on 14 Mar 2016

@matthewloring What (if anything) does sysctl -a | grep machdep.cpu.features | grep AVX print? AVX1 is probably harmless, AVX2 probably isn't.

bnoordhuis on 14 Mar 2016

Maybe make that sysctl -a | grep machdep.cpu | grep -i avx, there can be more than one sysctl.

EDIT: Or even just sysctl -a | grep -i avx.

bnoordhuis on 14 Mar 2016

AVX1.0 and AVX2 both appear to be present.

Full Output:

machdep.cpu.features: FPU VME DE PSE TSC MSR PAE MCE CX8 APIC SEP MTRR PGE MCA CMOV PAT PSE36 CLFSH DS ACPI MMX FXSR SSE SSE2 SS HTT TM PBE SSE3 PCLMULQDQ DTES64 MON DSCPL VMX EST TM2 SSSE3 FMA CX16 TPR PDCM SSE4.1 SSE4.2 x2APIC MOVBE POPCNT AES PCID XSAVE OSXSAVE SEGLIM64 TSCTMR AVX1.0 RDRAND F16C
machdep.cpu.leaf7_features: SMEP ERMS RDWRFSGS TSC_THREAD_OFFSET BMI1 AVX2 BMI2 INVPCID FPU_CSDS

matthewloring on 14 Mar 2016

Jeremiah@Jeremiahs-MacBook-Pro ~/D/node> sysctl -a | grep -i avx
hw.optional.avx1_0: 1
hw.optional.avx2_0: 0
machdep.cpu.features: FPU VME DE PSE TSC MSR PAE MCE CX8 APIC SEP MTRR PGE MCA CMOV PAT PSE36 CLFSH DS ACPI MMX FXSR SSE SSE2 SS HTT TM PBE SSE3 PCLMULQDQ DTES64 MON DSCPL VMX SMX EST TM2 SSSE3 CX16 TPR PDCM SSE4.1 SSE4.2 x2APIC POPCNT AES PCID XSAVE OSXSAVE TSCTMR AVX1.0 RDRAND F16C

Edit: Looks like I only have AXV1?

Fishrock123 on 14 Mar 2016

hmmm both are enabled for me, and I was unable to reproduce the problem on this machine:

$ sysctl -a | grep -i avx
hw.optional.avx1_0: 1
hw.optional.avx2_0: 1
machdep.cpu.features: FPU VME DE PSE TSC MSR PAE MCE CX8 APIC SEP MTRR PGE MCA CMOV PAT PSE36 CLFSH DS ACPI MMX FXSR SSE SSE2 SS HTT TM PBE SSE3 PCLMULQDQ DTES64 MON DSCPL VMX EST TM2 SSSE3 FMA CX16 TPR PDCM SSE4.1 SSE4.2 x2APIC MOVBE POPCNT AES PCID XSAVE OSXSAVE SEGLIM64 TSCTMR AVX1.0 RDRAND F16C
machdep.cpu.leaf7_features: SMEP ERMS RDWRFSGS TSC_THREAD_OFFSET BMI1 HLE AVX2 BMI2 INVPCID RTM FPU_CSDS

evanlucas on 14 Mar 2016

My (affected) machine only has AVX1, as well:

hw.optional.avx1_0: 1
hw.optional.avx2_0: 0

machdep.cpu.features: FPU VME DE PSE TSC MSR PAE MCE CX8 APIC SEP MTRR PGE MCA CMOV PAT PSE36 CLFSH DS ACPI MMX FXSR SSE SSE2 SS HTT TM PBE SSE3 PCLMULQDQ DTES64 MON DSCPL VMX SMX EST TM2 SSSE3 CX16 TPR PDCM SSE4.1 SSE4.2 x2APIC POPCNT AES PCID XSAVE OSXSAVE TSCTMR AVX1.0 RDRAND F16C
machdep.cpu.leaf7_features: SMEP ERMS RDWRFSGS
machdep.cpu.extfeatures: SYSCALL XD EM64T LAHF RDTSCP TSCI

okahyphen on 14 Mar 2016

Okay, then it's probably not AVX-related. Some versions of OS X 10.9 and 10.10 suffer from performance degradation when mixing AVX and UNIX signals, but I think (although I'm not 100% sure) that's only with AVX2. V8 started emitting AVX instructions in 4.2 so that seemed almost too much of a coincidence.

bnoordhuis on 15 Mar 2016

I don't have AVX2 too and affected.

sysctl -a | grep -i avx                                                                                                                $
hw.optional.avx1_0: 1
hw.optional.avx2_0: 0
machdep.cpu.features: FPU VME DE PSE TSC MSR PAE MCE CX8 APIC SEP MTRR PGE MCA CMOV PAT PSE36 CLFSH DS ACPI MMX FXSR SSE SSE2 SS HTT TM PBE SSE3 PCLMULQDQ DTES64 MON DSCPL VMX SMX EST TM2 SSSE3 CX16 TPR PDCM SSE4.1 SSE4.2 x2APIC POPCNT AES PCID XSAVE OSXSAVE TSCTMR AVX1.0

Isn't that everyone that don't have AVX2 affected?
Isn't it like binary is compiled to use those instructions enabled,
but problem happen on CPUs that don't have those?

S-YOU on 15 Mar 2016

Folks that can reproduce this, can you try with the --noenable-avx flag and see if that changes anything?

ofrobots on 15 Mar 2016

👍1

@ofrobots yes, that fixes it. Also, this is fixed somewhere in master, so it must indeed be a v8 bug.

Fishrock123 on 15 Mar 2016

👍1

Tentatively marking this lts-watch to keep an eye on it just in case we need to fix this in v4 also

jasnell on 15 Mar 2016

Perhaps this is related?
https://codereview.chromium.org/878063002
V8 issue: https://bugs.chromium.org/p/v8/issues/detail?id=3846

targos on 15 Mar 2016

@ofrobots yes it fixes the issue for me too. @ofrobots what are the side effects of using --noenable-avx ?

dannymarsland on 15 Mar 2016

--noenable-avx tells V8 to avoid generating AVX instructions. The JIT compilers behave as if you are running on a processor that doesn't support AVX instructions. Using this option may reduce performance if your workload is sensitive to this feature.

Would folks mind trying the following nightly builds:

https://nodejs.org/download/nightly/v6.0.0-nightly201603024c724dd439/ – Mar02 – should have V8 4.8
https://nodejs.org/download/nightly/v6.0.0-nightly20160119df4d209ad5/ – Jan19 – should have V8 4.7

This will help narrow down when this got fixed in V8.

ofrobots on 15 Mar 2016

@ofrobots Some data, with and without --noenable-avx. Appears to be fixed in the Mar02 build.

Jan19:

Oka at XI in ~/D/node-v6.0.0-nightly20160119df4d209ad5
↪ ./node --version
v6.0.0-pre
Oka at XI in ~/D/node-v6.0.0-nightly20160119df4d209ad5               
↪ ./node ~/osx.js
PRE EXEC
expensiveOperation: 56.145ms
expensiveOperation: 48.590ms
expensiveOperation: 45.105ms
expensiveOperation: 46.103ms
expensiveOperation: 46.482ms
expensiveOperation: 44.786ms
expensiveOperation: 44.023ms
expensiveOperation: 44.009ms
expensiveOperation: 50.380ms
expensiveOperation: 44.237ms
POST EXEC
expensiveOperation: 550.309ms
expensiveOperation: 552.331ms
expensiveOperation: 551.128ms
expensiveOperation: 547.652ms
expensiveOperation: 548.428ms
expensiveOperation: 545.683ms
expensiveOperation: 545.651ms
expensiveOperation: 551.198ms
expensiveOperation: 548.487ms
expensiveOperation: 550.837ms
Oka at XI in ~/D/node-v6.0.0-nightly20160119df4d209ad5               
↪ ./node --noenable-avx ~/osx.js
PRE EXEC
expensiveOperation: 53.805ms
expensiveOperation: 45.973ms
expensiveOperation: 43.450ms
expensiveOperation: 47.712ms
expensiveOperation: 48.413ms
expensiveOperation: 45.503ms
expensiveOperation: 46.244ms
expensiveOperation: 48.230ms
expensiveOperation: 48.879ms
expensiveOperation: 48.132ms
POST EXEC
expensiveOperation: 50.016ms
expensiveOperation: 47.327ms
expensiveOperation: 73.101ms
expensiveOperation: 46.448ms
expensiveOperation: 47.300ms
expensiveOperation: 49.577ms
expensiveOperation: 45.852ms
expensiveOperation: 49.045ms
expensiveOperation: 49.020ms
expensiveOperation: 45.724ms

Mar02:

Oka at XI in ~/D/node-v6.0.0-nightly201603024c724dd439
↪ ./node --version
v6.0.0-pre
Oka at XI in ~/D/node-v6.0.0-nightly201603024c724dd439               
↪ ./node ~/osx.js
PRE EXEC
expensiveOperation: 52.884ms
expensiveOperation: 46.866ms
expensiveOperation: 46.788ms
expensiveOperation: 45.380ms
expensiveOperation: 49.307ms
expensiveOperation: 42.706ms
expensiveOperation: 45.491ms
expensiveOperation: 48.018ms
expensiveOperation: 46.618ms
expensiveOperation: 49.353ms
POST EXEC
expensiveOperation: 46.085ms
expensiveOperation: 50.011ms
expensiveOperation: 45.186ms
expensiveOperation: 51.053ms
expensiveOperation: 45.617ms
expensiveOperation: 45.710ms
expensiveOperation: 43.065ms
expensiveOperation: 49.217ms
expensiveOperation: 46.529ms
expensiveOperation: 50.416ms
Oka at XI in ~/D/node-v6.0.0-nightly201603024c724dd439               
↪ ./node --noenable-avx ~/osx.js
PRE EXEC
expensiveOperation: 53.757ms
expensiveOperation: 47.107ms
expensiveOperation: 48.006ms
expensiveOperation: 49.681ms
expensiveOperation: 48.921ms
expensiveOperation: 49.080ms
expensiveOperation: 49.982ms
expensiveOperation: 53.690ms
expensiveOperation: 48.214ms
expensiveOperation: 49.141ms
POST EXEC
expensiveOperation: 44.735ms
expensiveOperation: 46.640ms
expensiveOperation: 48.634ms
expensiveOperation: 48.363ms
expensiveOperation: 48.377ms
expensiveOperation: 47.957ms
expensiveOperation: 48.650ms
expensiveOperation: 48.903ms
expensiveOperation: 47.977ms
expensiveOperation: 47.929ms

okahyphen on 16 Mar 2016

@Okahyphen thanks a lot for the data.

ofrobots on 16 Mar 2016

👍2

--noenable_avx seems like a reasonable approach, although I suppose it might be hampered by proper bug detection. You don't want to disable it on unaffected machines.

(Although performance on OS X is of less concern because it's not what people deploy their production software on.)

bnoordhuis on 20 Mar 2016

Upon reflection, I think the above V8 issue might be worth backporting in full. The issue does includes a lot of commits, and does change the compiler to generate different machine instructions. The changes themselves aren't complex however. Furthermore these instructions have been getting a significant amount of testing on a huge number on macs through Chrome 48 and 49. I am feeling comfortable that this is safe to backport.

ofrobots on 23 Mar 2016

I don't think it's a good idea to back-port a huge body of code for a relatively minor performance issue on a platform where top performance isn't that important.

bnoordhuis on 23 Mar 2016

Fair enough.

ofrobots on 23 Mar 2016

I'll close out the issue. v5.x is EOL and v6.x is not affected; affected v4.x users can use --noenable_avx as a workaround. The bug has been fixed in newer OS X releases, I believe.

bnoordhuis on 12 Oct 2016

Was this page helpful?

0 / 5 - 0 ratings