Build static times much higher when upgrading from version 0.15.23 to 0.15.24

[sebasrodriguez]

The build static command went from 5 seconds on 0.15.23 to almost three minutes on 0.15.24.

Also the bundle went from 5.1 mb file to 6.4 mb.

This is my bundle configuration (disabled minify/mangle for easier comparation)

var builder = new Builder("client", "client/config.js");
    builder
        .buildStatic("core/app.module.js", "out.js", {
            minify: false,
            mangle: false,
            sourceMaps: false,
            runtime: true
        })
        .then(function () {
            callback();
        })
        .catch(function (err) {
            callback(err);
        });

The first thing I've noticed comparing both outputs is that the 0.15.24 version does not removes comments, which is actually ok since minify and mangle are both false but what I cannot see is why the bundle time takes from 5 seconds to 3 minutes on the new version.

Is it some other configuration option I need to pass to make the bundle faster?

[guybedford]

Unfortunately this is a consequence of moving to Babel for transformation.

The size increase may be due to the unnecessary _export statements since they are doubled up in the Babel transformer (see an example at https://github.com/babel/babel/blob/master/packages/babel-plugin-transform-es2015-modules-systemjs/test/fixtures/systemjs/hoist-function-exports/expected.js#L30 which strictly shouldn't exist). Unfortunately I didn't write this transformer, and can't tell easily how it would be fixed.

It will likely be a case of simply doing some optimization work on the System.register transformer to have better performance as well, and a few low hanging performance wins may get us far on that.

While Traceur's issue was its lack of comments support and source maps issues, Erik's experience and focus on performance always meant it has been incredibly fast... I'm not sure how easily we'll top that on top of Babel though. Note how slow https://github.com/babel/babili is as well.

//cc @jrauschenbusch @asapach.

[guybedford]

If anyone is interested in looking into this performance problem please do let me know.

If we don't address this it may be worth considering reverting the recent work, as bad source maps are a worthy price to pay for such a performance difference.

But a 5mb bundle is certainly pushing things though too...

[asapach]

I think the size difference can mostly be attributed to whitespace and comments (IMHO extra exports should not make that much of a difference). As for performance, @sebasrodriguez can you share your config?

[sebasrodriguez]

@guybedford thanks for the quick reply.

The size increase I think it's mostly related about version 0.15.23 removing comments even when I pass mangle and minify as false and not so much with the unnecesary _export. So it makes sense to have a smaller bundle in 0.15.23 than in 0.15.24 with the same options. About performance I think you are right and it has to do with the babel transformer cause that's the big change that was introduced in that version.

[sebasrodriguez]

sure @asapach this is my config:

System.config({
  baseURL: "/",
  defaultJSExtensions: true,
  transpiler: false,
  paths: {
    "github:*": "jspm_packages/github/*",
    "npm:*": "jspm_packages/npm/*"
  },

  packages: {
    "core": {
      "defaultExtension": "js",
      "format": "register"
    }
  },

  meta: {
    "rangy/lib/rangy-core.js": {
      "format": "global",
      "exports": "rangy"
    },
    "textangular": {
      "deps": [
        "rangy/lib/rangy-core.js"
      ]
    }
  },

  map: {
    "angular": "npm:angular@1.5.8",
    "angular-animate": "npm:angular-animate@1.5.8",
    "angular-bootstrap-datetimepicker": "npm:angular-bootstrap-datetimepicker@1.0.1",
    "angular-date-time-input": "npm:angular-date-time-input@1.1.0",
    "angular-ellipsis": "npm:angular-ellipsis@1.0.1",
    "angular-fallback-image": "npm:angular-fallback-image@1.2.0",
    "angular-flexslider": "npm:angular-flexslider@1.3.3",
    "angular-image-spinner": "npm:angular-image-spinner@0.1.6",
    "angular-mocks": "npm:angular-mocks@1.5.8",
    "angular-sanitize": "npm:angular-sanitize@1.5.8",
    "angular-sortable-view": "npm:angular-sortable-view@0.0.15",
    "angular-touch": "npm:angular-touch@1.5.8",
    "angular-ui-bootstrap": "npm:angular-ui-bootstrap@1.3.3",
    "angular-ui-grid": "github:aw2basc/ui-grid@3.1.2",
    "angular-ui-router": "npm:angular-ui-router@0.3.1",
    "angular-ui-tree": "npm:angular-ui-tree@2.16.0",
    "chosen-dropdown": "npm:chosen-dropdown@1.4.0",
    "css": "github:systemjs/plugin-css@0.1.23",
    "drmonty-chosen": "npm:drmonty-chosen@1.4.2",
    "flexslider": "npm:flexslider@2.6.0",
    "font-awesome": "npm:font-awesome@4.6.3",
    "jquery": "npm:jquery@2.2.4",
    "leaflet": "npm:leaflet@0.7.7",
    "leaflet-draw": "npm:leaflet-draw@0.3.2",
    "leaflet-image": "npm:leaflet-image@0.2.1",
    "leaflet-plugins": "npm:leaflet-plugins@1.6.1",
    "lodash": "npm:lodash@4.13.1",
    "moment": "npm:moment@2.13.0",
    "naturalSort": "npm:natural-sort@1.0.0",
    "ng-tags-input": "npm:ng-tags-input@3.1.1",
    "prune-cluster": "github:SINTEF-9012/PruneCluster@1.1.0",
    "rangy": "npm:rangy@1.3.0",
    "redux": "npm:redux@3.5.2",
    "restangular": "npm:restangular@1.5.2",
    "spin.js": "npm:spin.js@2.3.2",
    "textangular": "npm:textangular@1.5.5",
    "ui-grid-draggable-rows": "npm:ui-grid-draggable-rows@0.3.2",
    "npm:angular-bootstrap-datetimepicker@1.0.1": {
      "angular": "npm:angular@1.5.8",
      "moment": "npm:moment@2.13.0"
    },
    "npm:angular-date-time-input@1.1.0": {
      "angular": "npm:angular@1.5.8",
      "moment": "npm:moment@2.13.0"
    },
    "npm:angular-fallback-image@1.2.0": {
      "angular": "npm:angular@1.5.8"
    },
    "npm:angular-flexslider@1.3.3": {
      "angular": "npm:angular@1.5.8",
      "flexslider": "npm:flexslider@2.6.0",
      "jquery": "npm:jquery@2.2.4"
    },
    "npm:angular-ui-router@0.3.1": {
      "angular": "npm:angular@1.5.8"
    },
    "npm:drmonty-chosen@1.4.2": {
      "jquery": "npm:jquery@2.2.4"
    },
    "npm:flexslider@2.6.0": {
      "jquery": "npm:jquery@2.2.4"
    },
    "npm:font-awesome@4.6.3": {
      "css": "github:systemjs/plugin-css@0.1.23"
    },
    "npm:leaflet-image@0.2.1": {
      "d3-queue": "npm:d3-queue@2.0.3"
    },
    "npm:redux@3.5.2": {
      "lodash": "npm:lodash@4.13.1",
      "symbol-observable": "npm:symbol-observable@0.2.4"
    },
    "npm:restangular@1.5.2": {
      "lodash": "npm:lodash@4.13.1"
    },
    "npm:textangular@1.5.5": {
      "rangy": "npm:rangy@1.3.0"
    }
  }
});

[asapach]

This does seem to point to transform-system-register. @guybedford, what low-hanging wins did you have in mind? I don't see any obvious optimizations to be made there.

[asapach]

Just tried passing an empty plugin list (plugins: []) to babel instead of our transformers: https://github.com/systemjs/builder/blob/master/compilers/compiler.js#L21 It has very little effect on running time, so I'd guess that it's not the transformer that is slow, it's either babel itself, or the way we're using it.

[asapach]

@sebasrodriguez just in case, could you please check if you're affected by this issue? https://phabricator.babeljs.io/T6756 What NPM version are you using?

[guybedford]

Thanks @asapach for trying out the numbers, which is the most important first step.

Perhaps a simple Traceur / Babel parsing benchmark is needed here to see if there really is a 30x speed difference?

[sebasrodriguez]

@asapach I'm on npm: 3.10.2 node: 6.2.2

Tried that issue and I don't see the problem they point to. It compiles on babel6 in 400 ms in my computer.

[lukiffer]

+1, also seeing significantly increased build times. I can't exactly quantify the difference, but what used to run in ~4s not takes 20s (according to gulp's timers). Will likely revert to 0.15.23 as I agree with @guybedford bad sourcemaps are insignificant compared to the hinderance the increased build times have caused.

[asapach]

I've created a benchmark: https://github.com/asapach/systemjs-benchmark

• took lodash-es (the ES6 version of lodash)
• transpiled it with babel to register format (to match @sebasrodriguez's config)
• duplicated it 10 times to increase the size
• ran buildStatic() and measured time and bundle size

Results:

• 0.15.23 (traceur): ~30s and ~6MB
• 0.15.31 (babel): ~55s and ~8MB

Tried it on Linux and Windows, node v4 and v6 - the results are consistent: babel is ~2x slower than traceur (times will vary depending on CPU, but should be relatively the same).

I'm not seeing the significant difference mentioned by @sebasrodriguez, however. It's not an order of magnitude.

Could somebody please try and recreate the results? Any other suggestion how to isolate the issue and benchmark the relevant piece of code?

[fictitious]

I can confirm - I don't see anything worse than 2x slowdown.

Here are some more examples:

build jQuery (global) and traceur (esm) https://github.com/fictitious/systemjs-builder-benchmarks

cycle 0.15.15 bundle jQuery x 5.19 ops/sec ±19.92% (32 runs sampled) cycle 0.15.23 bundle jQuery x 3.91 ops/sec ±17.29% (25 runs sampled) cycle 0.15.31 bundle jQuery x 3.35 ops/sec ±26.64% (23 runs sampled) cycle 0.15.15 bundle traceur sources x 0.10 ops/sec ±7.70% (5 runs sampled) cycle 0.15.23 bundle traceur sources x 0.10 ops/sec ±2.92% (5 runs sampled) cycle 0.15.31 bundle traceur sources x 0.09 ops/sec ±2.59% (5 runs sampled)

build Angular2 quickstart example (a couple of tsc-generated commonjs files + angular umd bundles) https://github.com/fictitious/systemjs-builder-benchmark-angular

cycle builder 0.15.23 x 0.80 ops/sec ±17.20% (9 runs sampled) cycle builder 0.15.31 x 0.70 ops/sec ±24.95% (8 runs sampled)

[guybedford]

This sounds great... thanks @asapach and @fictitious for looking into the numbers here.

A 2x slowdown is completely acceptable.

Perhaps there are edge cases where specific types of code are slower, corresponding to the details of the transform. If anyone does spot significant slowdown of more than 2x, and can share a code example that would be an amazing help to narrow down and fix any of these cases.

[lukiffer]

Ran @fictitious's benchmarks -- results are consistent with the comment above. Some co-workers have cloned the repo we're working on and don't have the issue. Digging into what might be causing the slow down and will open a separate issue if we're able to identify anything as it doesn't appear to be related to the .23 => .24 changes.

[sebasrodriguez]

@guybedford @fictitious @lukiffer I didn't had the time to create a sample code from my dependencies to narrow down the problem. Also tested the the benchmark that @fictitious and also see the same times he gets.

Just as a side note, I'm using plugin-css to import css files in my components, can this be causing the delay with the change from .23 => .24 ??

Thanks all for looking at this. I'll share more information once I have the time to create a benchmark with my dependencies.

[sebasrodriguez]

@guybedford @fictitious @lukiffer ok guys, so I started to investigate the problem and I found what was causing the delays on bundling on my environment.

I started to strip down my project to the bare minimum to see what was causing the problem and it was only fixed once I removed the npm-shrinkwrap from my code.

The interesting thing is that I deleted node_modules and installed from scratch with shrinkwrap and still didn't worked, but once I removed shrinkwrap and npm installed again the times went from 3 minutes to 20 seconds which is a completely acceptable delay.

Not sure why having an npm-shrinkwrap caused this delay, maybe collision in some dependencies or delay in node resolving some dependencies.

If someone wants to dig deeper into that I can send them my shrinpwrap. @guybedford if you want you can close the issue. Thanks again to all for your help.

[guybedford]

Sure, thanks @sebasrodriguez for the update and great to know we're still on good ground with the switch to Babel.