Drastic performance decrease with newer Node builds

[stuff]

Hi there,
I've just update my old node from 0.10.33 to the shiny new 0.12.0 stable version. And my process build was 2 times slower :( (14s before update versus 29s exactly)

Every single steps seems a little bit slower (I'm using grunt, and a bunch of plugins) but the uglify task is VERY VERY slower. I've benchmarked a single test file using directly uglifyjs to double check it was the bottle neck. My script test looks like :

var UglifyJS = require("uglify-js");
var result = UglifyJS.minify(array_of_files);

array_of_files is an array of 66 files, from the biggest (jquery-ui) to the smallest (custom code with 10-15 lines), and the benchmark :

> nvm current
v0.10.33

> time node test.js
node test.js  3,08s user 0,10s system 99% cpu 3,188 total

> nvm use v0.12.0
Now using node v0.12.0

> time node test.js
node test.js  8,19s user 0,10s system 106% cpu 7,760 total

nearly 3x more times

I've tried with some intermediate node version, it's progressively slower with updates...

I'm going to deeper look inside, but is it a "known" issue ?

[stuff]

more info, with some intermediate times

 > time node test.js
1. parse: 467ms
2. compress: 1978ms
3. mangle: 524ms
4. output: 166ms
node test.js  3,18s user 0,11s system 98% cpu 3,329 total

> nvm use v0.12.0
Now using node v0.12.0

> time node test.js
1. parse: 1251ms
2. compress: 4400ms
3. mangle: 1433ms
4. output: 373ms
node test.js  8,12s user 0,11s system 106% cpu 7,746 total

[mishoo]

I'm going to deeper look inside, but is it a "known" issue ?

Not this time, but it happened in the past too (I don't remember the details/versions but it was some regression in node/v8 that has since been fixed). Perhaps you should ping NodeJS people about this? I'm still on 0.10.29.

[mishoo]

I can confirm it, just tried it myself. Seems about 2.5x slower here.

Just speculating, but the issue is probably V8. Besides reading file contents and writing them back to disk, UglifyJS is just pure CPU-intensive JS. I'd expect the degradation in speed to quickly become apparent in many other projects as people upgrade to Node 0.12.

CC @mraleph in case he's interested to dig this.

[mraleph]

Needs profiling, but I'd guess it can be caused by changes in megamorphic keyed accesses: https://code.google.com/p/v8/issues/detail?id=3842

[dwelle]

+1, I'm seeing huge performance drop. Task that previously ran for around 50-100ms now easily takes over 1-2s.

[mraleph]

The bug with megamorphic keyed accesses has been fixed in V8 fwiw. If you have a standalone UglifyJS benchmark then you can try benchmarking on a newer V8 and see if the issue is fixed or there is another issue underneath it.

[JasonBoy]

same problem, some other modules like minify-css, less, etc are also much slower than before

[misteroh]

Oh glad I found this. Can confirm that an 11s task now takes 20s :(

[dotnetwise]

same problem here

[Shahor]

👍

[tssajo]

I would like to know if the above situation improved with Node.js 0.12.4 ? Can someone please give us an update? Thanks!!

[avdg]

Seems not to be fixed yet...

It's easy to reproduce by running this script on c9.io

Setup

Updating nvm (to get iojs support):
run curl https://raw.githubusercontent.com/creationix/nvm/v0.25.4/install.sh | bash

Set up the script:
Save the snippet below (for example) under uglify-regression.sh, then run chmod +x uglify-regresion.sh to make the file executable.

Run

Once set up, run ./uglify-regression.sh. Benchmark results should pop up
(script also uploaded on https://gist.github.com/avdg/5d5965b00ae32453ab95)

. ~/.nvm/nvm.sh

npm install uglify-js
wget "https://code.jquery.com/jquery-2.1.4.js" -Ojquery.js

nvm install 0.10
time node node_modules/.bin/uglifyjs jquery.js > jquery.min.js

nvm install 0.12
time node node_modules/.bin/uglifyjs jquery.js > jquery.min.js

nvm install stable
time node node_modules/.bin/uglifyjs jquery.js > jquery.min.js

Edit: Updated to include iojs
Edit2: Seems c9 is not using the latest nvm version (0.13.0 instead of 0.25.4). Added upgrade instructions at setup
Edit3 (19 sept 2015): Updated shell script to run stable, as iojs ran out of testing and simply became node, also added gist for reference purposes or to review history

[mishoo]

@avdg like I said, I was able to repro the issue, but I've no idea how to fix. It's clearly a regression in Node.

[tssajo]

@avdg Thanks for the info!

@mishoo Yes, I know this is a regression in Node. I was just wondering if it got fixed in the latest 0.12.4 release. Apparently, not. :(

As I use UglifyJS frequently (btw, thanks for this great tool!) I must stay on Node 0.10.x for now.

It would be interesting to know if the performance regression is present in the latest version of io.js, too.

[stuff]

It is present in latest version of io. yes, I've tested. (with NVM it's
easy to switch)

Le sam. 6 juin 2015 15:21, Zoltan notifications@github.com a écrit :

@avdg https://github.com/avdg Thanks for the info!

@mishoo https://github.com/mishoo Yes, I know this is a regression in
Node. I was just wondering if it got fixed in the latest 0.12.4 release.
Apparently, not. :(

As I use UglifyJS frequently (btw, thanks for this great tool!) I must
stay on Node 0.10.x for now.

It would be interesting to know if the performance regression is present
in the latest version of io.js https://iojs.org/en/index.html ...

—
Reply to this email directly or view it on GitHub
#636 (comment).

[tssajo]

@stuff Thanks for the info!

re: with NVM it's easy to switch --> I'm on Windows platform... :\

[avdg]

It seems to be better on iojs, but not as good as node 0.10.x

v0.10.38 is already installed.
Now using node v0.10.38 (npm v1.4.28)

real    0m0.641s
user    0m0.592s
sys     0m0.048s
v0.12.4 is already installed.
Now using node v0.12.4 (npm v2.10.1)

real    0m1.419s
user    0m1.472s
sys     0m0.072s
iojs-v2.2.1 is already installed.
Now using io.js v2.2.1 (npm v2.11.0)

real    0m1.052s
user    0m1.092s
sys     0m0.068s

[mishoo]

What I don't get is, is UglifyJS the only project obviously affected by this? The slowdown is considerable and I was expecting it to affect tons of other projects. I don't think I'm doing anything particularly poor here...

[mraleph]

iojs v2.2.1 has https://codereview.chromium.org/878263002/ fixing https://code.google.com/p/v8/issues/detail?id=3842 which was my first guess at the slow down. I guess that's why it's improved compared to node v0.21.X

I'll take this benchmark for a spin tomorrow and file a V8 issue if I can prove that it's indeed one.

[nei]

I also upgraded our node version and I got worse performance on my app. Follow the results of my siege. about 50% slower.

v0.10.38
Transaction rate trans/sec 69.66
Throughput Mb/sec 3.13
Response time 0.72

v0.12.04
Transaction rate trans/sec 43.26
Throughput Mb/sec 1.95
Response time 1.15

[yamsellem]

@mraleph can you please share your benchmark on io.js with us?

[mraleph]

@yamsellem what do you mean "my benchmark"? I don't have one.

[also I didn't have a chance to look at @avdg's benchmark so far, even though I hoped I will - sorry have no time for this right now]

[yamsellem]

@mraleph damned, your last post refer to a V8 issue you would create if you prove something with a io.js benchmark. What made you think the v8 issue you've pointed may be a reason for this issue?

[mraleph]

@yamsellem it was just a guess based on the assumption that UglifyJS has a few hot megamorphic keyed calls inside.

[yamsellem]

@mraleph ok ;-) we're currently migrating to node 0.12 and our code use more cpu, is there a method to identify what's need to be done to keep a good cpu usage?

[tssajo]

@yamsellem Re: what's need to be done to keep a good cpu usage

Staying on 0.10.x ... ? ;)

[yamsellem]

@tssajo are you serious? is this the current state of mind of the community about migrating to 0.12? There are some out of the box cool features in this long awaited release ;-)

[tssajo]

@yamsellem Personally, I always love to upgrade to the latest version of software, too. But when there is a major and yet unresolved performance degradation bug present in the current release, then yes, I am serious about staying on the old version for a while. At least until the problem is not fixed.
While new harmony features are great and welcome, those features are not important to me, because I do not use those features. But a major performance degradation is something which I take much more seriously because that affects my daily workflow. So I simply refuse to upgrade to Node 0.12.x until this issue gets fixed. So yes, I am serious. ;)

[stuff]

please. both of you have good arguments, but please keep this issue clean :p

[avdg]

Still in io.js 3.0.0 which uses v8 4.4.63.26

v0.10.40 is already installed.
Now using node v0.10.40 (npm v1.4.28)

real    0m0.602s
user    0m0.560s
sys     0m0.048s
v0.12.7 is already installed.
Now using node v0.12.7 (npm v2.11.3)

real    0m1.263s
user    0m1.348s
sys     0m0.060s
iojs-v3.0.0 is already installed.
Now using io.js v3.0.0 (npm v2.13.3)

real    0m1.170s
user    0m1.236s
sys     0m0.068s

Still using this script: #636 (comment)

[mraleph]

Ok, I looked at node profile. It seems that it spends quite a bit of time in the 'vm' module related code. ContextifyContext::* and friends. This is actually a piece of node that changed quite a bit since v0.10.

You should try drop the usage of 'vm' in uglify and see what happens to the performance.

[yamsellem]

We've migrated a server to node 0.12 recently and encountered a lot of issues.

In the end, we've succeeded to get the same performance (cpu & ram) with a (slightly) better response time.

We've noticed that 0.12:

• is worst at object & array creation but better at object & array manipulation, reusing same objects when possible and pushing into arrays instead of concat should help (we were creating an empty array in a recursive loop, this was killing performance)
• using an object (or array) as a set (to check if a value is there) can be drastically improved using Set, Map, WeakSet or WeakMap if the number of keys > 10 (digit depends of what you do)
• there is not so much library suffering from a performance decrease, but some are hardly concerned

We've using benchmark.js a lot to micro benchmark chunks of our code, comparing 0.10 and 0.12 to pinpoint bottlenecks.

A lot of our code was really faster by default with 0.12. Only small chunks where a lot slower.

I hope this migration feedback may help here ;-). If I remember more optimisation trick I'll update this post.

[mraleph]

Out of curiousity I ported an old vm module into newer node. Here are the results

# node 0.10
$ time ../node/node node_modules/.bin/uglifyjs jquery.js > jquery.min.js
../node/node node_modules/.bin/uglifyjs jquery.js > jquery.min.js  0.43s user 0.03s system 100% cpu 0.460 total
# io.js 3.X.X
$ time ../io.js/iojs node_modules/.bin/uglifyjs jquery.js > jquery.min.js
../io.js/iojs node_modules/.bin/uglifyjs jquery.js > jquery.min.js  1.01s user 0.04s system 115% cpu 0.912 total
# io.js 3.X.X using old vm module
$ time ../io.js/iojs node_modules/.bin/uglifyjs jquery.js > jquery.min.js
 ../io.js/iojs node_modules/.bin/uglifyjs jquery.js > jquery.min.js  0.63s user 0.02s system 117% cpu 0.553 total

So large chunk of this regression indeed is coming from whatever new things vm module is trying to do. However not all of it, which requires additional investigation.

[avdg]

Vm problems might be related to nodejs/node#472

[avdg]

Well, its not fitting the description, but at least fitting the title, not sure what the devs are planning to do with it.

[avdg]

Hmm I suspect that node/io.js don't have benchmarks on this. But too early to tell it for sure...

[stuff]

not surprising, but with the new node v4.0.0, still have a build time 2 times slower than with v0.10.34. It seems we'll have to live with it...

[yamsellem]

Living with it seems a little defeatist :-|. As I say earlier, things have changed in node and v8 over time, but it may be possible, with micro benchmarks and analysis, to find some and fix them.

[chapati]

Hi there. Any updates on this? According to my tests the most recent v4.1.1 is still significantly slower than old good v0.10.x. Maybe somebody somewhere found a fix? Rebuilding from sources with different options? Anything else? Links to other bugs/issues trackers more related to node itself? Really want to go with the latest node and its shiny features but have to stay with 10.x Thanks in advance!

[avdg]

I hope the debugger stuff will get integrated soon on the nodejs end, so debugging in nodejs will get easier. Otherwise, I don't see any vm bugs related to this issue here https://github.com/nodejs/node/issues?q=is%3Aissue+is%3Aopen+vm+sort%3Aupdated-desc :/

[chapati]

Maybe the issue should be opened in the node's bugtracker? Has anyone tried to contact the node team with this?

[mraleph]

I am sure it would faster to just rewrite uglify to not use vm module to implement a custom module system. Dropping any dependencies on the vm would take maybe a day. It'll probably take weeks if not months to just find somebody inclined to dig deep enough to actually figure out where in the maze of things between vm, node and V8 something change so drastically that performance dropped.

[stuff]

that's also what I'm thinking. The performance drop exists since 0.11.x. An impressive amount of updates occured in Node.js, and I've seen anybody else complaining about so drastic performance drop. So I'm pretty sure just no one will look deeper inside Node.js internals to fix that :(

[mishoo]

@mraleph the only reason why I do this is to be able to split my code across multiple files, yet be able to freely access something defined in one file from another without qualifying imports (like plain old <script> tag). A quick way to do this without using the vm module would be to just eval all code inside a single function (seriously, no big deal). Do you think it's worth trying that?

[mraleph]

@mishoo eval comes with it's own penalty. I suggest just gluing all sources together and then loading them - preferably with Function(source) to avoid eval related issues (e.g. disabled optimizations).

One of the reasons why I could not originally reproduce is because I was doing approximately that.

[stuff]

probably a noob question, but why not using require ?

[mishoo]

@stuff Matter of taste.

@mraleph Alright, I'll try that. Yeah, I meant new Function(code) rather than eval (though I think non-lexical eval should be pretty much the same).

[mishoo]

@mraleph huge speedup indeed if I get rid of vm. In my test, time dropped from 5s to 2.3s, still about 0.5s slower than node 0.10 which does the same file in 1.8s. Oh well, still a great speed-up.

The way I tested this was to generate a bundle using uglifyjs --self, and then load that with require. Can't commit a good fix yet, need to think how to make this more comfortable.

[stuff]

Pretty good news !

Le jeu. 24 sept. 2015 12:37, Mihai Bazon notifications@github.com a
écrit :

@mraleph https://github.com/mraleph huge speedup indeed if I get rid of
vm. In my test, time dropped from 5s to 2.3s, still about 0.5s slower
than node 0.10 which does the same file in 1.8s. Oh well, still a great
speed-up.

The way I tested this was to generate a bundle using uglifyjs --self, and
then load that with require. Can't commit a good fix yet, need to think how
to make this more comfortable.

—
Reply to this email directly or view it on GitHub
#636 (comment).

[chapati]

@stuff @mishoo Thanks for posting this. Sounds very promising. Please keep us updated. Looking forward to having the fix!

[mishoo]

Guys, I pushed a fix. Thanks everyone, double-thanks @mraleph for investigating this. My bad for acting so late; seems it was obvious for more than a month that the issue is about the vm module.

This could be a breaking change. If possible to test, please let me know how it works before I npm publish a new release.

[fresheneesz]

@mishoo When will this be released on npm? Looks like the latest version is still a few months old.

I'm using Uglify through webpack, and where compilation used to take a few seconds, its now taking a few minutes. I was also getting weird SIGABRT and SIGKILL signals while compiling with uglify (and not using uglify got rid of the issue). I hope this solution solves the problem

[fresheneesz]

nm, I was looking at uglify not uglify-js