Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Speed up incremental builds #723

Closed
Rich-Harris opened this issue Jun 16, 2016 · 21 comments
Closed

Speed up incremental builds #723

Rich-Harris opened this issue Jun 16, 2016 · 21 comments

Comments

@Rich-Harris
Copy link
Contributor

From rollup/rollup-watch#5:

First off, congrats on the release. This is a much awaited feature.

The build times however are not too great. I'm bundling react and a couple of internal files and my build times look like:

2715ms > 2065ms > 2052ms > ...

700ms is definitely an improvement, but not by much. What needs to be done to improve the rebuild speed?

We should spend some time profiling to see where the bulk of the work is happening, and where the low-hanging fruit is. A couple of thoughts though:

  • it's possible that tree-shaking doesn't have any effect on a library like React, in which case perhaps we can disable it on a per-module basis
  • in most cases, the bindings that are being imported from React aren't changing. So if there was a way to capture the result of the tree-shaking step for a given module indexed by which exports are used then we could re-use the analysis

Getting rudimentary caching and file watching was only really the first step, these are the sorts of optimisations we need to start thinking about now.

@PaulBGD
Copy link

PaulBGD commented Jun 16, 2016

Disabling treeshaking cuts the times by about 150ms for the initial build and rebuilds.

@Victorystick
Copy link
Contributor

@PaulBGD Is that using the--no-treeshake option?

@PaulBGD
Copy link

PaulBGD commented Jun 18, 2016

In the config, but yeah.

@TrySound
Copy link
Member

About cold start. Maybe we should support this pattern and follow it also in gobble?
https://github.com/avajs/find-cache-dir

@TrySound
Copy link
Member

@Rich-Harris Some benchmarking. Runs in acorn build:main (two targets), window8, node0.12

Phase 1 - discovery
start
[ 0, 013008154 ]
end
start
[ 0, 416093818 ]
end

Phase 2 - binding
start
[ 0, 001319085 ]
end
start
[ 0, 004428150 ]
end

Phase 3 - marking (mostly running)
start
[ 0, 001532979 ]
end
start
[ 0, 007409536 ]
end

Phase 4 - sorting and deconflicting
start
[ 0, 001402426 ]
end
start
[ 0, 000995164 ]
end

@TrySound
Copy link
Member

Seems like phase two can be successfully cached two.

@TrySound
Copy link
Member

Phases 2-4 don't need to cache they are extremely fast.
Generating takes about half or third time.

[21:07:43] Starting 'module:js'...
0 339.007502
[21:07:44] Finished 'module:js' after 1.02 s
[21:07:45] Starting 'module:js'...
0 379.969004
[21:07:46] Finished 'module:js' after 892 ms
[21:07:47] Starting 'module:js'...
0 386.825959
[21:07:48] Finished 'module:js' after 909 ms
[21:07:49] Starting 'module:js'...
0 393.40251
[21:07:50] Finished 'module:js' after 918 ms
[21:07:51] Starting 'module:js'...
0 396.205725
[21:07:52] Finished 'module:js' after 901 ms
[21:07:56] Starting 'module:js'...
0 397.967382
[21:07:57] Finished 'module:js' after 927 ms
[21:07:58] Starting 'module:js'...
0 412.556989
[21:07:59] Finished 'module:js' after 942 ms
[21:07:59] Starting 'module:js'...
0 486.143014
[21:08:00] Finished 'module:js' after 1.01 s
[21:08:00] Starting 'module:js'...
0 499.918507
[21:08:02] Finished 'module:js' after 1.25 s
[21:08:03] Starting 'module:js'...
0 348.139709
[21:08:04] Finished 'module:js' after 972 ms
[21:08:06] Starting 'module:js'...
0 383.274728
[21:08:06] Finished 'module:js' after 851 ms

This is the time of this chunk

    if ( options.sourceMap ) {
        var file = options.sourceMapFile || options.dest;
        if ( file ) file = path.resolve( typeof process !== 'undefined' ? process.cwd() : '', file );

        if ( this.hasLoaders || find( this.plugins, function (plugin) { return plugin.transform || plugin.transformBundle; } ) ) {
            map = magicString.generateMap( {} );
            map = collapseSourcemaps( file, map, usedModules, bundleSourcemapChain, this.onwarn );
        } else {
            map = magicString.generateMap({ file: file, includeContent: true });
        }

        map.sources = map.sources.map( normalize );
    }
[21:12:43] Starting 'module:js'...
0 217.372294
[21:12:44] Finished 'module:js' after 806 ms
[21:12:45] Starting 'module:js'...
0 208.086132
[21:12:45] Finished 'module:js' after 833 ms
[21:12:45] Starting 'module:js'...
0 260.580308
[21:12:47] Finished 'module:js' after 1.07 s
[21:12:47] Starting 'module:js'...
0 263.053032
[21:12:48] Finished 'module:js' after 891 ms
[21:13:38] Starting 'module:js'...
0 262.874855
[21:13:39] Finished 'module:js' after 916 ms
[21:13:40] Starting 'module:js'...
0 263.445515
[21:13:41] Finished 'module:js' after 874 ms`

This takes iife finaliser

[21:16:34] Starting 'module:js'...
0 71.605547
[21:16:35] Finished 'module:js' after 939 ms
[21:16:35] Starting 'module:js'...
0 48.415391
[21:16:36] Finished 'module:js' after 925 ms
[21:16:36] Starting 'module:js'...
0 40.443801
[21:16:37] Finished 'module:js' after 891 ms
[21:16:37] Starting 'module:js'...
0 46.033398
[21:16:38] Finished 'module:js' after 863 ms
[21:16:43] Starting 'module:js'...
0 46.328992
[21:16:44] Finished 'module:js' after 868 ms
[21:16:44] Starting 'module:js'...
0 119.860824
[21:16:46] Finished 'module:js' after 1.1 s

This

this.orderedModules.forEach( function (module) {
        var source = module.render( format === 'es' );
        if ( source.toString().length ) {
            magicString.addSource( source );
            usedModules.push( module );
        }
    });

takes this

[21:19:27] Starting 'module:js'...
0 105.394382
[21:19:28] Finished 'module:js' after 1.01 s
[21:19:29] Starting 'module:js'...
0 52.655521
[21:19:30] Finished 'module:js' after 877 ms
[21:19:55] Starting 'module:js'...
0 55.009596
[21:19:56] Finished 'module:js' after 836 ms
[21:19:56] Starting 'module:js'...
0 51.354497
[21:19:57] Finished 'module:js' after 871 ms
[21:19:57] Starting 'module:js'...
0 46.045714
[21:19:58] Finished 'module:js' after 862 ms
[21:19:58] Starting 'module:js'...
0 91.707978
[21:19:59] Finished 'module:js' after 1.07 s

@TrySound
Copy link
Member

Seems like s.indent method of magic-string is very expensive.

@TrySound
Copy link
Member

With indent: false iife finaliser is instant.

@TrySound
Copy link
Member

resolveId should be cachable stuff. For now it takes half of the time with cache.

@TrySound
Copy link
Member

@Victorystick
Copy link
Contributor

@TrySound If we can speed up (iife) builds dramatically by just defaulting indent to false, I don't see why we shouldn't change the defaults.

resolveId should be cachable stuff.

What do you mean by that exactly?

@TrySound
Copy link
Member

TrySound commented Jul 29, 2016

I don't see why we shouldn't change the defaults.

Agree.

What do you mean by that exactly?

Module instance has resolvedIds property which can be cached and recovered. This will save 1/4 of my incremental build time.

@Victorystick
Copy link
Contributor

@TrySound That's quite an improvement! Would you have to be using the node-resolve plugin for that project?

@TrySound
Copy link
Member

Yep. It's very expensive relatively.

@TrySound
Copy link
Member

@Rich-Harris Is there a sense in cloning instance here https://github.com/rollup/rollup/blob/master/src/Module.js#L450?
Here's my results before and after removing clone call.

[16:10:38] Starting 'module:js'...
generate 0 498.429692
[16:10:47] Finished 'module:js' after 9.69 s
[16:10:47] Starting 'watch:js'...
[16:10:48] Finished 'watch:js' after 46 ms
[16:10:52] Starting 'module:js'...
generate 0 567.403906
[16:10:57] Finished 'module:js' after 4.81 s
[16:11:03] Starting 'module:js'...
generate 0 439.701537
[16:11:08] Finished 'module:js' after 4.9 s
[16:14:02] Starting 'module:js'...
generate 0 174.29616
[16:14:11] Finished 'module:js' after 8.37 s
[16:14:11] Starting 'watch:js'...
[16:14:11] Finished 'watch:js' after 54 ms
[16:14:15] Starting 'module:js'...
generate 0 164.607982
[16:14:20] Finished 'module:js' after 4.16 s
[16:14:25] Starting 'module:js'...
generate 0 160.673295
[16:14:29] Finished 'module:js' after 3.77 s

P.S. It's the same project on very slow machine.

This was referenced Jul 30, 2016
@TrySound
Copy link
Member

TrySound commented Aug 1, 2016

Here's my benchmark after last optimisations

[23:12:26] Starting 'app'...
multi-entry 0 239.2487
fetch 1 963.30285
render renderModules 0 144.992456
render generateMap 0 193.327791
render collapseSourcemaps 0 525.489834
render 0 868.81588
[23:12:29] Finished 'app' after 2.99 s
[23:12:29] Starting 'app:dev'...
[23:12:29] Finished 'app:dev' after 8.24 ms
[23:12:47] Starting 'app'...
multi-entry 0 120.948363
fetch 0 586.004865
render renderModules 0 137.628475
render generateMap 0 272.587164
render collapseSourcemaps 0 578.675781
render 0 992.658189
[23:12:49] Finished 'app' after 1.72 s
[23:12:52] Starting 'app'...
multi-entry 0 126.86763
fetch 0 485.941435
render renderModules 0 144.203385
render generateMap 0 210.620028
render collapseSourcemaps 0 744.292063
render 1 102.876498
[23:12:53] Finished 'app' after 1.78 s
[23:12:54] Starting 'app'...
multi-entry 0 114.513861
fetch 0 466.471246
render renderModules 0 143.958699
render generateMap 0 253.84816
render collapseSourcemaps 0 611.535959
render 1 14.011557
[23:12:55] Finished 'app' after 1.62 s
[23:13:02] Starting 'app'...
multi-entry 0 145.961346
fetch 0 506.275415
render renderModules 0 139.489485
render generateMap 0 242.76996
render collapseSourcemaps 0 619.2838
render 1 5.885602
[23:13:04] Finished 'app' after 1.66 s
[23:13:50] Starting 'app'...
multi-entry 0 129.220474
fetch 0 484.317722
render renderModules 0 139.588837
render generateMap 0 260.645585
render collapseSourcemaps 0 634.357443
render 1 38.945305
[23:13:52] Finished 'app' after 1.67 s

@TrySound
Copy link
Member

TrySound commented Aug 1, 2016

The result with removing magicString.clone(). Also tests in rollup are still passed.

[23:16:05] Starting 'app'...
multi-entry 0 238.684607
fetch 1 946.867424
render renderModules 0 31.394936
render generateMap 0 216.384108
render collapseSourcemaps 0 527.91904
render 0 781.395244
[23:16:08] Finished 'app' after 2.88 s
[23:16:08] Starting 'app:dev'...
[23:16:08] Finished 'app:dev' after 8.81 ms
[23:16:13] Starting 'app'...
multi-entry 0 118.300746
fetch 0 450.796153
render renderModules 0 27.06695
render generateMap 0 296.083998
render collapseSourcemaps 0 622.552986
render 0 950.406749
[23:16:14] Finished 'app' after 1.55 s
[23:16:17] Starting 'app'...
multi-entry 0 127.627142
fetch 0 469.756032
render renderModules 0 27.638432
render generateMap 0 282.02605
render collapseSourcemaps 0 598.66408
render 0 912.941466
[23:16:18] Finished 'app' after 1.53 s
[23:16:20] Starting 'app'...
multi-entry 0 164.787798
fetch 0 610.090013
render renderModules 0 28.652482
render generateMap 0 228.512075
render collapseSourcemaps 0 596.911045
render 0 858.481181
[23:16:22] Finished 'app' after 1.61 s

@TrySound
Copy link
Member

TrySound commented Aug 1, 2016

Seems like creating module is expensive operation too.

[23:48:53] Starting 'app'...
fetch new Module 627.034095
fetch 1 704.42508
render renderModules 0 222.051298
render generateMap 0 186.2787
render collapseSourcemaps 0 527.075776
render 0 940.472745
[23:48:56] Finished 'app' after 2.8 s
[23:48:56] Starting 'app:dev'...
[23:48:56] Finished 'app:dev' after 8.29 ms
[23:48:57] Starting 'app'...
fetch new Module 297.2598059999998
fetch 0 345.666163
render renderModules 0 146.492184
render generateMap 0 173.763586
render collapseSourcemaps 0 732.022457
render 1 56.442406
[23:48:59] Finished 'app' after 1.55 s
[23:48:59] Starting 'app'...
fetch new Module 299.909892
fetch 0 351.678624
render renderModules 0 141.150148
render generateMap 0 233.77036
render collapseSourcemaps 0 609.349796
render 0 988.138068
[23:49:00] Finished 'app' after 1.49 s
[23:49:01] Starting 'app'...
fetch new Module 295.1968069999999
fetch 0 339.975983
render renderModules 0 137.059458
render generateMap 0 192.443883
render collapseSourcemaps 0 610.614692
render 0 944.031777
[23:49:02] Finished 'app' after 1.43 s
[23:49:02] Starting 'app'...
fetch new Module 286.200495
fetch 0 323.514281
render renderModules 0 145.169402
render generateMap 0 196.89257
render collapseSourcemaps 0 694.757931
render 1 40.417116
[23:49:04] Finished 'app' after 1.54 s
[23:49:05] Starting 'app'...
fetch new Module 489.6983540000001
fetch 0 546.042225
render renderModules 0 145.748684
render generateMap 0 216.157896
render collapseSourcemaps 0 622.534101
render 0 988.931654
[23:49:07] Finished 'app' after 1.68 s
[23:49:10] Starting 'app'...
fetch new Module 316.4339859999999
fetch 0 368.191643
render renderModules 0 142.35305
render generateMap 0 199.492564
render collapseSourcemaps 0 651.406636
render 0 997.841344
[23:49:11] Finished 'app' after 1.51 s

@TrySound
Copy link
Member

TrySound commented Aug 1, 2016

Disabled sourceMaps works like this

[23:54:27] Starting 'app'...
fetch new Module 697.2745859999995
fetch 1 962.099126
render renderModules 0 174.979215
render 0 195.3834
[23:54:29] Finished 'app' after 2.27 s
[23:54:29] Starting 'app:dev'...
[23:54:29] Finished 'app:dev' after 9.29 ms
[23:54:31] Starting 'app'...
fetch new Module 299.54039900000026
fetch 0 346.479458
render renderModules 0 159.29468
render 0 162.570434
[23:54:32] Finished 'app' after 616 ms
[23:54:33] Starting 'app'...
fetch new Module 282.9427989999999
fetch 0 328.983588
render renderModules 0 144.333939
render 0 147.537437
[23:54:33] Finished 'app' after 580 ms
[23:54:34] Starting 'app'...
fetch new Module 297.23722300000003
fetch 0 354.330347
render renderModules 0 137.239688
render 0 140.946516
[23:54:35] Finished 'app' after 602 ms
[23:54:36] Starting 'app'...
fetch new Module 292.795515
fetch 0 337.937617
render renderModules 0 141.375127
render 0 144.315465
[23:54:36] Finished 'app' after 604 ms

TrySound added a commit that referenced this issue Aug 2, 2016
@TrySound TrySound closed this as completed Sep 8, 2016
@Finesse
Copy link

Finesse commented Feb 26, 2017

Disabling treeshaking cuts the times by about 150ms for the initial build and rebuilds.

Disabling treeshaking causes a bug: #1315

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants