fix `inline` handling of `AST_Call.args` #2059

alexlamsl · 2017-06-06T14:19:36Z

No description provided.

kzc · 2017-06-06T15:09:45Z

Looks like the fuzzer's handiwork - how many iterations so far?

alexlamsl · 2017-06-06T15:14:04Z

Only at the starting point of The Million Fuzz, as the box recovers from summer heat.

This one got hit ~1kFuzz - and after merge and restart we are currently at 30kFuzz and counting.

alexlamsl · 2017-06-06T15:29:17Z

Not a scientific measurement, but a crude test shows node@8 --turbo finally recovers back to the same performance level as node@0.10 (--turbo make things slower in that version).

kzc · 2017-06-06T15:43:17Z

node@8 --turbo finally recovers back to the same performance level as node@0.10

Can you show the timings with and without the node 8 --turbo flag for uglifyjs math.js -mc?

alexlamsl · 2017-06-06T15:54:34Z

$ node -v
v8.0.0

$ node bin/uglifyjs -V
uglify-js 3.0.15

$ node bin/uglifyjs math.js -mco min.js --timings
- parse: 0.531s
- scope: 0.391s
- compress: 8.812s
- mangle: 0.500s
- properties: 0.000s
- output: 0.328s
- total: 10.562s

$ node --turbo bin/uglifyjs math.js -mco min.js --timings
- parse: 0.609s
- scope: 0.390s
- compress: 7.719s
- mangle: 0.438s
- properties: 0.000s
- output: 0.297s
- total: 9.453s

kzc · 2017-06-06T16:06:00Z

--turbo was never documented as far as I know. Not clear what it does.

alexlamsl · 2017-06-06T16:13:08Z

--turbo was never documented as far as I know. Not clear what it does.

Following the flag around this file might give some clues:

https://github.com/v8/v8/blob/45618a9ab5cc98a5de200b0116670e8c272f0c5f/src/flag-definitions.h#L463

kzc · 2017-06-06T16:20:51Z

According to the V8 blog, Ignition (interpreter) and TurboFan (optimizing compiler) are the default now. So I'm guessing that --turbo disables the Ignition interpreter?

alexlamsl · 2017-06-06T16:25:36Z

Ignition seems to be off by default:
https://github.com/v8/v8/blob/45618a9ab5cc98a5de200b0116670e8c272f0c5f/src/flag-definitions.h#L323

and --turbo turns it on:
https://github.com/v8/v8/blob/45618a9ab5cc98a5de200b0116670e8c272f0c5f/src/flag-definitions.h#L276

alexlamsl · 2017-06-06T16:27:41Z

Obviously Google Chrome can be compiled with a modified set of default values, which may be what's mentioned in the blog post you've quoted.

kzc · 2017-06-06T16:30:13Z

So what timings do you get for node 8 with --no-turbo --no-ignition?

alexlamsl · 2017-06-06T16:33:49Z

$ node --no-turbo --no-ignition bin/uglifyjs math.js -mco min.js --timings
- parse: 0.531s
- scope: 0.390s
- compress: 8.641s
- mangle: 0.485s
- properties: 0.000s
- output: 0.343s
- total: 10.390s

kzc · 2017-06-06T16:36:07Z

It's still not clear to me what --turbo actually does.

alexlamsl · 2017-06-06T16:37:44Z

Judging by the numbers, I'd say Ignition is off by default, i.e. same as --no-ignition, then --turbo enables that.

OT: just hit 200kFuzz

alexlamsl · 2017-06-06T16:41:04Z

Obviously none of us are authoritative on this query, but can we safely assume that whatever combination of flags make test/ufuzz.js goes faster is the answer we are looking for?

Just want to be sure I didn't overlook anything here.

kzc · 2017-06-06T16:45:58Z

So on node 7 --turbo --no-ignition is fastest:

$ /usr/bin/time node773 bin/uglifyjs math.js -mco math.min.js
       12.54 real        13.21 user         0.12 sys

$ /usr/bin/time node773 --no-turbo --no-ignition bin/uglifyjs math.js -mco math.min.js
       12.49 real        13.16 user         0.12 sys

$ /usr/bin/time node773 --no-turbo --ignition bin/uglifyjs math.js -mco math.min.js
       14.02 real        14.38 user         0.11 sys

$ /usr/bin/time node773 --turbo --no-ignition bin/uglifyjs math.js -mco math.min.js
       10.51 real        12.79 user         0.14 sys

$ /usr/bin/time node773 --turbo --ignition bin/uglifyjs math.js -mco math.min.js
       12.19 real        13.49 user         0.13 sys

Is the same true for node 8?

alexlamsl · 2017-06-06T16:46:22Z

Under "Say hello to ~~my little~~ V8 5.8":
https://nodejs.org/en/blog/release/v8.0.0/#say-hello-to-v8-5-8

The V8 5.8 engine also helps set up a pending transition to the new TurboFan + Ignition compiler pipeline, which promises to provide significant new performance optimizations for all Node.js applications. Although they have existed in previous versions of V8, TurboFan and Ignition will be enabled by default for the first time in V8 5.9.

So I think those new stuff aren't enabled by default in Node.js 8 yet.

alexlamsl · 2017-06-06T16:51:40Z

Is the same true for node 8?

Ignition doesn't seem to slow things down over here:

$ nvs use node
node/8.0.0/x64

$ node bin/uglifyjs math.js -mco min.js --timings
- parse: 0.546s
- scope: 0.391s
- compress: 8.828s
- mangle: 0.500s
- properties: 0.000s
- output: 0.344s
- total: 10.609s

$ node --no-turbo --no-ignition bin/uglifyjs math.js -mco min.js --timings
- parse: 0.546s
- scope: 0.391s
- compress: 8.578s
- mangle: 0.485s
- properties: 0.000s
- output: 0.328s
- total: 10.328s

$ node --no-turbo --ignition bin/uglifyjs math.js -mco min.js --timings
- parse: 0.578s
- scope: 0.421s
- compress: 9.094s
- mangle: 0.516s
- properties: 0.000s
- output: 0.359s
- total: 10.968s

$ node --turbo --no-ignition bin/uglifyjs math.js -mco min.js --timings
- parse: 0.625s
- scope: 0.390s
- compress: 7.750s
- mangle: 0.422s
- properties: 0.000s
- output: 0.313s
- total: 9.500s

$ node --turbo --ignition bin/uglifyjs math.js -mco min.js --timings
- parse: 0.625s
- scope: 0.391s
- compress: 7.765s
- mangle: 0.437s
- properties: 0.000s
- output: 0.297s
- total: 9.515s

kzc · 2017-06-06T17:42:04Z

Confirmed that node 8.0.0 with --turbo on Mac is same speed as node 0.10:

$ /usr/bin/time node0_10_41 bin/uglifyjs math.js -mc | shasum
        6.21 real         6.13 user         0.11 sys
66a92e25b24ff41720e2065cb81c93574fab18be  -

$ /usr/bin/time node0_12_9 bin/uglifyjs math.js -mc | shasum
       11.05 real        11.85 user         0.14 sys
66a92e25b24ff41720e2065cb81c93574fab18be  -

$ /usr/bin/time node421 bin/uglifyjs math.js -mc | shasum
        7.20 real         9.39 user         0.17 sys
d22f1dcbd70de04df024dacd04f1494c6077e371  -

$ /usr/bin/time node690 bin/uglifyjs math.js -mc | shasum
        7.31 real         8.12 user         0.16 sys
d22f1dcbd70de04df024dacd04f1494c6077e371  -

$ /usr/bin/time node800 bin/uglifyjs math.js -mc | shasum
        6.78 real         7.42 user         0.15 sys
d22f1dcbd70de04df024dacd04f1494c6077e371  -

$ /usr/bin/time node800 --turbo bin/uglifyjs math.js -mc | shasum
        6.28 real         7.79 user         0.15 sys
d22f1dcbd70de04df024dacd04f1494c6077e371  -

node 8.0.0 achieves this speed by using a background thread - note the higher user CPU time compared to node 0.10.

Also note how the shasums differ after node 0.12 with latest master - what's up with that?

--- math.010.js	2017-06-06 13:34:39.000000000 -0400
+++ math.800.js	2017-06-06 13:34:23.000000000 -0400
@@ -8170 +8170 @@
-                    if ("%" === e) return "%";
+                    if ("%%" === e) return "%";

Original code:

            if (x === '%%') return '%';

Is there a bug in latest master when running on node 0.10 and node 0.12?

alexlamsl · 2017-06-06T17:50:30Z

Confirmed that node 8.0.0 with --turbo on Mac is same speed as node 0.10:

Good to know the performance difference is OS-independent.

Also note how the shasums differ after node 0.12 with latest master - what's up with that?

Interesting - investigating now.

kzc · 2017-06-06T17:50:42Z

$ echo 'function f(x){ if (x === "%%") return "%"; } console.log(f("%%"));' | node0_12_9 bin/uglifyjs -cm
function f(f){if("%"===f)return"%"}console.log(f("%"));

$ echo 'function f(x){ if (x === "%%") return "%"; } console.log(f("%%"));' | node421 bin/uglifyjs -cm
function f(f){if("%%"===f)return"%"}console.log(f("%%"));

$ echo 'function f(x){ if (x === "%%") return "%"; } console.log(f("%%"));' | node800 bin/uglifyjs -cm
function f(f){if("%%"===f)return"%"}console.log(f("%%"));

kzc · 2017-06-06T17:56:46Z

simpler test case:

$ echo 'console.log("%%");' | node0_12_9 bin/uglifyjs -cm
console.log("%");

$ echo 'console.log("%%");' | node421 bin/uglifyjs -cm
console.log("%%");

alexlamsl · 2017-06-06T17:59:51Z

May be related to bin/uglifyjs changes:

$ node -v
v0.10.48

$ git checkout v2.8.28
$ echo 'function f(x){if(x==="%%")return"%"}console.log(f("%%"))' | node bin/uglifyjs -c
function f(x){if("%%"===x)return"%"}console.log(f("%%"));

$ git checkout v3.0.0
$ echo 'function f(x){if(x==="%%")return"%"}console.log(f("%%"))' | node bin/uglifyjs -c
function f(x){if("%"===x)return"%"}console.log(f("%"));

kzc · 2017-06-06T18:03:00Z

$ git checkout v3.0.0
HEAD is now at 7313465... v3.0.0

$ echo 'console.log("%%");' | node0_12_9 bin/uglifyjs -cm
console.log("%");

$ echo 'console.log("%%");' | node421 bin/uglifyjs -cm
console.log("%%");

alexlamsl · 2017-06-06T18:04:57Z

Quick debug on bin/uglifyjs:

--- a/bin/uglifyjs
+++ b/bin/uglifyjs
@@ -173,6 +173,7 @@ if (program.self) {
     var chunks = [];
     process.stdin.setEncoding("utf8");
     process.stdin.on("data", function(chunk) {
+console.error(chunk);
         chunks.push(chunk);
     }).on("end", function() {
         files = [ chunks.join("") ];

So is there any known issues with reading from stdin in earlier versions of Node.js?

$ node -v
v0.10.48

$ echo 'x("%%")' | node bin/uglifyjs -c
x("%")

x("%");

$ node -v
v4.8.3

$ echo 'x("%%")' | node bin/uglifyjs -c
x("%%")

x("%%");

kzc · 2017-06-06T18:07:14Z

It's broken in parse:

$ echo '"%%"' | node0_12_9 bin/uglifyjs -o ast
{
  "_class": "AST_Toplevel",
  "body": [
    {
      "_class": "AST_Directive",
      "value": "%",
      "quote": "\""
    }
  ]
}

$ echo '"%%"' | node421 bin/uglifyjs -o ast
{
  "_class": "AST_Toplevel",
  "body": [
    {
      "_class": "AST_Directive",
      "value": "%%",
      "quote": "\""
    }
  ]
}

alexlamsl · 2017-06-06T18:08:56Z

It's broken in parse:

Well, it's broken before that - see #2059 (comment) where I literally print out what I read from process.stdin, and the % went AWOL.

kzc · 2017-06-06T18:10:43Z

Well, it's broken before that - see #2059 (comment) where I literally print out what I read from process.stdin, and the % went AWOL.

2.x uses different node I/O calls?

alexlamsl · 2017-06-06T18:13:22Z

The only difference I can tell is the use of process.openStdin():
https://github.com/mishoo/UglifyJS2/blob/4027a0c962b266f72b303e9367a6bad430097f59/bin/uglifyjs#L596-L603

But I just tried that on master and Node.js 0.10 and it doesn't seem to make any difference.

kzc · 2017-06-06T18:18:24Z

Not specific to stdin:

$ cat q.js
"%%";

$ node0_12_9 bin/uglifyjs q.js
"%";

$ node421 bin/uglifyjs q.js
"%%";

alexlamsl · 2017-06-06T18:23:15Z

Not specific to stdin:

Of course you are correct - what was I thinking... 😞

Okay this is getting funky...

--- a/bin/uglifyjs
+++ b/bin/uglifyjs
@@ -189,6 +189,8 @@ function run() {
     UglifyJS.AST_Node.warn_function = function(msg) {
         console.error("WARN:", msg);
     };
+console.log(files);
+console.log(files[0]);
     if (program.timings) options.timings = true;
     try {
         if (program.parse) {

$ node -v
v0.10.48

$ echo 'x("%%")' | node bin/uglifyjs -c
[ 'x("%%") \r\n' ]
x("%")

x("%");

alexlamsl · 2017-06-06T18:24:06Z

Notice that printing the whole array looks correct, but retrieving the string and print that, % gets dropped.

rvanvelzen · 2017-06-06T18:28:31Z

I think the console.log misbehaving may be the console.log sprintf-like formatting?

https://nodejs.org/api/console.html#console_console_log_data_args

If formatting elements (e.g. %d) are not found in the first string then util.inspect() is called on each argument and the resulting string values are concatenated. See util.format() for more information.

alexlamsl · 2017-06-06T18:29:36Z

We are both looking at the wrong side - it's console.log() on Node.js 0.x which is at fault 🤣

$ node -v
v0.10.48

$ echo 'console.log("%%")' | node
%

$ node -v
v4.8.3

$ echo 'console.log("%%")' | node
%%

alexlamsl · 2017-06-06T18:30:22Z

I think the console.log misbehaving may be the console.log sprintf -like formatting?

@rvanvelzen yup, what you just said 👍

alexlamsl · 2017-06-06T18:31:51Z

uglify-js 2.x avoids this fiasco by doing console.log("%s", txt):
https://github.com/mishoo/UglifyJS2/blob/4027a0c962b266f72b303e9367a6bad430097f59/bin/uglifyjs#L634

Making a PR to fix master now.

kzc · 2017-06-06T18:34:02Z

Yes, @rvanvelzen @alexlamsl - I recall that node bug now. They changed the way util.format worked:

$ node0_12_9 -p 'require("util").format("%%")'
%

$ node421 -p 'require("util").format("%%")'
%%

In any case we'd have to avoid using such a call for binary (unicode) data.

kzc · 2017-06-06T18:39:44Z

Shouldn't we avoid console.log() for code output for both speed and correctness?

$ node0_12_9 -e 'process.stdout.write("%%\n");'
%%

$ node421 -e 'process.stdout.write("%%\n");'
%%

alexlamsl · 2017-06-06T18:41:11Z

Shouldn't we avoid console.log() for code output for both speed and correctness?

I was about to copy from v2.x, but I don't mind it either way - so I'll go with your suggestion then.

kzc · 2017-06-06T18:42:56Z

At least the -o option was still working correctly for 3.x for node <= 0.12:

$ echo '"%%"' | node0_10_41 bin/uglifyjs 
"%";

$ echo '"%%"' | node0_10_41 bin/uglifyjs -o out.js
$ cat out.js
"%%";

kzc · 2017-06-06T18:46:34Z

I was about to copy from v2.x, but I don't mind it either way - so I'll go with your suggestion then.

Regarding the newline at the end of the console output, I think this is slightly more efficient:

process.stdout.write(code);
process.stdout.write("\n");

than:

process.stdout.write(code + "\n");

but this is splitting hairs.

rvanvelzen · 2017-06-06T18:46:36Z

(aside: process.stdout.write('%%') seems to be lot faster than console.log('%s', '%%') across versions)

alexlamsl · 2017-06-06T18:49:18Z

but this is splitting hairs.

Why not - better than losing hair... 😏

Partially reverts mishoo#2059 as this has better coverage and performance. fixes mishoo#2062

Partially reverts #2059 as this has better coverage and performance. fixes #2062

fix inline handling of AST_Call.args

e3f614b

alexlamsl merged commit b9ad53d into mishoo:master Jun 6, 2017

alexlamsl deleted the inline-args branch June 6, 2017 14:55

alexlamsl mentioned this pull request Jun 6, 2017

fix CLI output corruption #2061

Merged

alexlamsl added a commit to alexlamsl/UglifyJS that referenced this pull request Jun 7, 2017

fix cascade on multi-branch evaluations

bb63953

Partially reverts mishoo#2059 as this has better coverage and performance. fixes mishoo#2062

alexlamsl mentioned this pull request Jun 7, 2017

fix cascade on multi-branch evaluations #2067

Merged

alexlamsl added a commit that referenced this pull request Jun 7, 2017

fix cascade on multi-branch evaluations (#2067)

9db0695

Partially reverts #2059 as this has better coverage and performance. fixes #2062

fix inline handling of AST_Call.args #2059

fix inline handling of AST_Call.args #2059

Conversation

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017 • edited

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017 • edited

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017 • edited

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

rvanvelzen commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

kzc commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

kzc commented Jun 6, 2017

kzc commented Jun 6, 2017

rvanvelzen commented Jun 6, 2017

alexlamsl commented Jun 6, 2017

fix `inline` handling of `AST_Call.args` #2059

fix `inline` handling of `AST_Call.args` #2059

alexlamsl commented Jun 6, 2017 •

edited

alexlamsl commented Jun 6, 2017 •

edited

alexlamsl commented Jun 6, 2017 •

edited