Skip to content

Slow rebuilds (profiler results attached) #11149

@jimrandomh

Description

@jimrandomh

From the 1.11 announcement:

If your app takes more than 2 seconds to do a full rebuild, please help us improve. Use the build-profiler package to take a CPU profile and share it by opening a new Github issue and providing as much information as you can. We’d appreciate it!

Here is some profiler data!

Codebase: LessWrong. Upgraded to meteor 1.11 for testing but otherwise the same as what's currently in the devel branch.
Profiler results:

The second incremental build is much faster than the first. This is not a fluke; after running npm start, the first file change triggers a much slower rebuild than subsequent changes do.

Build performed on Linux 4.15.0 (Ubuntu), in a VirtualBox VM on a Windows host, Core i7-4790K, SSD. In all tests, the OS filesystem cache was warm from previous builds. Excluding node_modules and .meteor, this project is ~1k source files, ~100k lines, mostly Typescript, all in packages/lesswrong. Running in debug mode, the uncompressed size of all the client bundle comes to ~16MB uncompressed. Most of the library footprint comes in from the top-level package.json, not from meteor packages.

Time until completion of first http request, benchmarked using scripts in the lesswrong repo without profiler active:

  • From npm start: ~40s
  • From changing a single file, the first time: ~25s
  • From changing a single file, subsequent times: ~13s

These times include running the code, not just compiling it; they're slower than what's in the profiler result files above, by ~6s for rebuilds (which is about right for executing our initialization code after compiling it) and ~15s for npm start. Pretty noticeable here is the ~12s difference between the first incremental rebuild and subsequent incremental rebuilds; that difference is reflected in the profiler results, and seems to all be compile time.

Measurements
Without the profiler active, total time from 'npm start' to completion of an http request is ~40s; time from file change to completion of an http request is ~25s the first time after an npm start, ~13s on subsequent times.

Things that jump out in the profile:

  • The first rebuild does a lot of work that subsequent rebuilds don't, most of it in babel. This suggests that babel has a cache which is not persisting from the initial build to the first rebuild, but is persisting from the first rebuild to the second rebuild.
  • The first rebuild spends 3.8s in babel precompileTypescript, seemingly on one extremely huge file. Has a compiled-output file accidentally been handed back to the input? The initial build also has some suspiciously long single babel passes.
  • In general, I/O operations seem surprisingly slow here. I might try redoing this on a RAMdisk, but I also see some complicated wrapping around the I/O functions in meteor-tools which might be making it worse somehow.

Metadata

Metadata

Assignees

No one assigned

    Labels

    confirmedWe want to fix or implement it

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions