Rebuild performance causes on a complex meteor app

In the project I am working on we have implemented a complex structure of meteor apps and packages. Lately, we achieved to improve the build performance and get consistently 8-10 seconds per code change. However, we think that according to our current project size, it could be improved even more. There is probably something that we do wrong on referencing our code.

Recently, we provided more features to the app, which resulted on include new dependency branches, referencing to modules implemented on the app and packages. But the rebuild timing raised up to 20 seconds on code change. We don’t understand what has been wrong, but according to our current research, we’d want to point possible causes, and confirm with you if those has been a problem for you. The changes required can get us to do high efforts and we’d want first to get more feedback on real causes and understanding on the meteor builder.

Circular dependencies on our dependency tree

By comparing the codebase state when we got 8 seconds per code change to the 20 seconds one, we have noted with madge cli that some of our packages introduce more circular dependencies. So our first state already have some of them but the new one gets even more. The modules that produce them are related with business logic (collections, models and etc), so I guess we should consider strategies to remove those like commented here if they have impact on builds.

  • Are circular dependencies a real issue for meteor builder to resolve the bundle? That could explain the timing we have got ever, but also we are aware that in ES6 are handled, so not 100% sure.

References to packages module and submodules

In order to get less weight bundles and supposedly reload times, we use specific paths to package submodules, so:

instead of

import { myModule } from 'meteor/example-package'; // api.mainModule usage

we use

import { myModule } from 'meteor/example-package/modules';
// or
import myModule from 'meteor/example-package/modules/my-module';
  • Does this have any impact on the meteor builder to resolve the bundle?
  • Could the cache be affected somehow and on using references like these the builder is not optimistic and need to resolve them again?

There are probably more things going on which we are trying to analyze and we will report, but for the moment we’d want to mention such items in case someone has a clear idea on how the meteor builder resolve those.

By the way, does it exist a tool for debugging the meteor builder? That could be cool to deep into the real causes quickly.

1 Like

There are some environment variables you can set that help to isolate where the time’s being spent.

export METEOR_PROFILE=n  # shows steps taking longer than n milliseconds.
export METEOR_DEBUG_BUILD=1  # time the build stages
export METEOR_LOG=debug  # sets log level to debug
1 Like

Oh, thanks.

We used METEOR_PROFILE, but not the others, which provide more useful information. I am gonna to put here a log on code change if that can help others to analyze our situation.

| (#7) Profiling: Rebuild App
 START CAPTURE 0 building the application took NaN
   START 1 determining active pluginse-v...  -
   DONE 1 determining active plugins took 1  -
   START 1 determining active plugins        \
   DONE 1 determining active plugins took 0  \
   START 1 building for web.browser          \
     START 2 linking the program             \
     DONE 2 linking the program took 7       \
     START 2 processing files with ecmascript (for target web.browser)
     DONE 2 processing files with ecmascript (for target web.browser) took 2311
     START 2 processing files with templating-compiler (for target web.browser)
     DONE 2 processing files with templating-compiler (for target web.browser) took 3
     START 2 processing files with meteor (for target web.browser)
     DONE 2 processing files with meteor (for target web.browser) took 1
     START 2 processing files with fourseven:scss (for target web.browser)
     DONE 2 processing files with fourseven:scss (for target web.browser) took 14
     START 2 processing files with universe:i18n (for target web.browser)
     DONE 2 processing files with universe:i18n (for target web.browser) took 0
     START 2 processing files with coffeescript (for target web.browser)
     DONE 2 processing files with coffeescript (for target web.browser) took 0
     START 2 minifying app code              \
     DONE 2 minifying app code took 0        \
   DONE 1 building for web.browser took 13708-
   START 1 building for os.osx.x86_64        -
     START 2 linking the program             -
     DONE 2 linking the program took 234     \
     START 2 processing files with ecmascript (for target os.osx.x86_64)
     DONE 2 processing files with ecmascript (for target os.osx.x86_64) took 1243
     START 2 processing files with universe:i18n (for target os.osx.x86_64)
     DONE 2 processing files with universe:i18n (for target os.osx.x86_64) took 1
     START 2 processing files with coffeescript (for target os.osx.x86_64)
     DONE 2 processing files with coffeescript (for target os.osx.x86_64) took 13
   DONE 1 building for os.osx.x86_64 took 2739
 END CAPTURE 0 building the application took 18377
| 
| Rebuild App..................................................18,378 ms (1)
| └─ files.withCache...........................................18,378 ms (1)
|    β”œβ”€ compiler.compile(the app)...............................1,280 ms (1)
|    β”‚  └─ files.withCache......................................1,280 ms (2)
|    β”‚     └─ compileUnibuild (the app).........................1,279 ms (2)
|    β”‚        β”œβ”€ files.withCache..................................221 ms (2)
|    β”‚        β”‚  β”œβ”€ files.realpath                                 15 ms (594)
|    β”‚        β”‚  β”œβ”€ files.stat                                     17 ms (1544)
|    β”‚        β”‚  β”œβ”€ safeWatcher.watch                               4 ms (333)
|    β”‚        β”‚  β”œβ”€ files.readdir                                  29 ms (1188)
|    β”‚        β”‚  └─ other files.withCache                         156 ms
|    β”‚        β”œβ”€ optimistic readFile................................7 ms (1426)
|    β”‚        β”‚  β”œβ”€ files.readFile                                  1 ms (58)
|    β”‚        β”‚  └─ other optimistic readFile                       6 ms
|    β”‚        β”œβ”€ optimistic hashOrNull                              4 ms (1426)
|    β”‚        └─ other compileUnibuild (the app)                1,046 ms
|    β”œβ”€ bundler.bundle..makeClientTarget.......................13,708 ms (1)
|    β”‚  └─ Target#make.........................................13,708 ms (1)
|    β”‚     β”œβ”€ Isopack#getUnibuildAtArch                             2 ms (1290)
|    β”‚     β”œβ”€ Target#_runCompilerPlugins........................2,364 ms (1)
|    β”‚     β”‚  β”œβ”€ sha1                                               3 ms (132)
|    β”‚     β”‚  β”œβ”€ Isopack#getUnibuildAtArch                          2 ms (1254)
|    β”‚     β”‚  β”œβ”€ plugin ecmascript..............................2,311 ms (1)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic statOrNull.......................1,399 ms (52290)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.stat                                 492 ms (8181)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ safeWatcher.watch...........................25 ms (1703)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.stat                                1 ms (38)
|    β”‚     β”‚  β”‚  β”‚  β”‚  └─ other safeWatcher.watch                  24 ms
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic statOrNull                883 ms
|    β”‚     β”‚  β”‚  β”œβ”€ Babel.compile                                 224 ms (2846)
|    β”‚     β”‚  β”‚  β”œβ”€ sha1                                           23 ms (2859)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic readJsonOrNull                       2 ms (410)
|    β”‚     β”‚  β”‚  └─ other plugin ecmascript                       662 ms
|    β”‚     β”‚  β”œβ”€ plugin templating-compiler                         3 ms (1)
|    β”‚     β”‚  β”œβ”€ plugin fourseven:scss.............................15 ms (1)
|    β”‚     β”‚  β”‚  β”œβ”€ sha1                                            4 ms (4)
|    β”‚     β”‚  β”‚  └─ other plugin fourseven:scss                    10 ms
|    β”‚     β”‚  └─ other Target#_runCompilerPlugins                  28 ms
|    β”‚     β”œβ”€ Target#_emitResources............................10,485 ms (1)
|    β”‚     β”‚  β”œβ”€ PackageSourceBatch.computeJsOutputFilesMap....10,457 ms (1)
|    β”‚     β”‚  β”‚  β”œβ”€ sha1                                            3 ms (357)
|    β”‚     β”‚  β”‚  β”œβ”€ ImportScanner#_getInstallPath                 139 ms (6515)
|    β”‚     β”‚  β”‚  β”œβ”€ ImportScanner#_findImportedModuleIdentifiers   13 ms (5775)
|    β”‚     β”‚  β”‚  β”œβ”€ files.stat                                    811 ms (19532)
|    β”‚     β”‚  β”‚  β”œβ”€ safeWatcher.watch                              98 ms (6262)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic statOrNull.......................5,525 ms (106862)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ safeWatcher.watch                           44 ms (4792)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.stat                               1,990 ms (35719)
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic statOrNull              3,491 ms
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic readJsonOrNull.....................116 ms (2423)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic readFile.........................17 ms (396)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.readFile                           13 ms (396)
|    β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic readFile                 5 ms
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic readJsonOrNull             97 ms
|    β”‚     β”‚  β”‚  β”œβ”€ ImportScanner#_readFile.......................406 ms (3265)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic readFile........................198 ms (3265)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.readFile                           83 ms (3260)
|    β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic readFile               115 ms
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic hashOrNull......................165 ms (3265)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ optimistic readFile                      35 ms (3260)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ sha1                                     36 ms (3260)
|    β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic hashOrNull              94 ms
|    β”‚     β”‚  β”‚  β”‚  └─ other ImportScanner#_readFile               43 ms
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic hashOrNull..........................54 ms (349)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic readFile.........................27 ms (298)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.readFile                            7 ms (298)
|    β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic readFile                20 ms
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ sha1                                         2 ms (298)
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic hashOrNull                 26 ms
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic readFile............................15 ms (217)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.readFile                              12 ms (217)
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic readFile                    4 ms
|    β”‚     β”‚  β”‚  └─ other PackageSourceBatch.computeJsOutputFilesMap 3,276 ms
|    β”‚     β”‚  β”œβ”€ PackageSourceBatch#getResources...................21 ms (104)
|    β”‚     β”‚  β”‚  └─ PackageSourceBatch#_linkJS.....................20 ms (104)
|    β”‚     β”‚  β”‚     β”œβ”€ sha1                                         6 ms (208)
|    β”‚     β”‚  β”‚     └─ other PackageSourceBatch#_linkJS            15 ms
|    β”‚     β”‚  └─ other Target#_emitResources                        8 ms
|    β”‚     β”œβ”€ Target#minifyJs                                     714 ms (1)
|    β”‚     β”œβ”€ Target#rewriteSourceMaps                             13 ms (1)
|    β”‚     β”œβ”€ sha1                                                 85 ms (216)
|    β”‚     └─ other Target#make                                    44 ms
|    β”œβ”€ bundler.bundle..makeServerTarget........................2,739 ms (1)
|    β”‚  └─ Target#make..........................................2,739 ms (1)
|    β”‚     β”œβ”€ Isopack#getUnibuildAtArch                           101 ms (1415)
|    β”‚     β”œβ”€ Target#_runCompilerPlugins........................1,744 ms (1)
|    β”‚     β”‚  β”œβ”€ sha1                                               4 ms (158)
|    β”‚     β”‚  β”œβ”€ Isopack#getUnibuildAtArch                         64 ms (1405)
|    β”‚     β”‚  β”œβ”€ plugin ecmascript..............................1,244 ms (1)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic statOrNull.........................342 ms (45336)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.stat                                  83 ms (1915)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ safeWatcher.watch                           18 ms (667)
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic statOrNull                241 ms
|    β”‚     β”‚  β”‚  β”œβ”€ Babel.compile                                 174 ms (3019)
|    β”‚     β”‚  β”‚  β”œβ”€ sha1                                           14 ms (3032)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic readJsonOrNull                       1 ms (480)
|    β”‚     β”‚  β”‚  └─ other plugin ecmascript                       712 ms
|    β”‚     β”‚  β”œβ”€ plugin coffeescript                               13 ms (1)
|    β”‚     β”‚  └─ other Target#_runCompilerPlugins                 420 ms
|    β”‚     β”œβ”€ Target#_emitResources...............................752 ms (1)
|    β”‚     β”‚  β”œβ”€ PackageSourceBatch.computeJsOutputFilesMap.......741 ms (1)
|    β”‚     β”‚  β”‚  β”œβ”€ ImportScanner#_getInstallPath                  30 ms (3127)
|    β”‚     β”‚  β”‚  β”œβ”€ ImportScanner#_findImportedModuleIdentifiers    3 ms (1545)
|    β”‚     β”‚  β”‚  β”œβ”€ files.stat                                     33 ms (1362)
|    β”‚     β”‚  β”‚  β”œβ”€ safeWatcher.watch                              13 ms (1438)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic statOrNull.........................230 ms (20035)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.stat                                  43 ms (1458)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ safeWatcher.watch                            3 ms (307)
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic statOrNull                184 ms
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic readJsonOrNull......................27 ms (591)
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic readFile.........................13 ms (249)
|    β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.readFile                           11 ms (249)
|    β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic readFile                 2 ms
|    β”‚     β”‚  β”‚  β”‚  β”œβ”€ safeWatcher.watch                            3 ms (240)
|    β”‚     β”‚  β”‚  β”‚  └─ other optimistic readJsonOrNull             11 ms
|    β”‚     β”‚  β”‚  β”œβ”€ ImportScanner#_readFile                         3 ms (44)
|    β”‚     β”‚  β”‚  β”œβ”€ optimistic readFile............................14 ms (27)
|    β”‚     β”‚  β”‚  β”‚  └─ files.readFile                              14 ms (27)
|    β”‚     β”‚  β”‚  └─ other PackageSourceBatch.computeJsOutputFilesMap 388 ms
|    β”‚     β”‚  β”œβ”€ PackageSourceBatch#getResources....................7 ms (114)
|    β”‚     β”‚  β”‚  └─ PackageSourceBatch#_linkJS......................7 ms (114)
|    β”‚     β”‚  β”‚     β”œβ”€ sha1                                         2 ms (228)
|    β”‚     β”‚  β”‚     └─ other PackageSourceBatch#_linkJS             5 ms
|    β”‚     β”‚  └─ other Target#_emitResources                        3 ms
|    β”‚     └─ other Target#make                                   142 ms
|    β”œβ”€ bundler writeSiteArchive..................................645 ms (1)
|    β”‚  β”œβ”€ bundler writeTargetToPath..............................628 ms (2)
|    β”‚  β”‚  β”œβ”€ ClientTarget#write..................................132 ms (1)
|    β”‚  β”‚  β”‚  β”œβ”€ bundler writeFile..................................4 ms (439)
|    β”‚  β”‚  β”‚  β”‚  └─ Builder#write...................................4 ms (439)
|    β”‚  β”‚  β”‚  β”‚     β”œβ”€ Builder#_ensureDirectory                     2 ms (439)
|    β”‚  β”‚  β”‚  β”‚     └─ other Builder#write                          2 ms
|    β”‚  β”‚  β”‚  β”œβ”€ Builder#write......................................8 ms (29)
|    β”‚  β”‚  β”‚  β”‚  └─ sha1                                            8 ms (29)
|    β”‚  β”‚  β”‚  β”œβ”€ sha1                                              29 ms (662)
|    β”‚  β”‚  β”‚  └─ other ClientTarget#write                          90 ms
|    β”‚  β”‚  └─ ServerTarget#write..................................495 ms (1)
|    β”‚  β”‚     β”œβ”€ JsImage#write....................................477 ms (1)
|    β”‚  β”‚     β”‚  β”œβ”€ Builder#write..................................17 ms (149)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ sha1                                        16 ms (149)
|    β”‚  β”‚     β”‚  β”‚  └─ other Builder#write                          1 ms
|    β”‚  β”‚     β”‚  β”œβ”€ meteorNpm.isPortable..........................227 ms (31)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ optimistic lstat                            15 ms (31)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ optimistic statOrNull                        3 ms (31)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ optimistic readdir...........................3 ms (31)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.readdir                             2 ms (31)
|    β”‚  β”‚     β”‚  β”‚  β”‚  └─ other optimistic readdir                  1 ms
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ meteorNpm.isPortable.......................201 ms (884)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic lstat.........................62 ms (884)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.lstat                            6 ms (884)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic lstat                56 ms
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic statOrNull....................59 ms (884)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.stat                             5 ms (882)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic statOrNull           53 ms
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic readJsonOrNull................68 ms (886)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  β”œβ”€ optimistic readFile...................34 ms (886)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  β”‚  β”œβ”€ files.readFile                     13 ms (886)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  β”‚  └─ other optimistic readFile          21 ms
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”‚  └─ other optimistic readJsonOrNull       34 ms
|    β”‚  β”‚     β”‚  β”‚  β”‚  └─ other meteorNpm.isPortable               11 ms
|    β”‚  β”‚     β”‚  β”‚  └─ other meteorNpm.isPortable                   5 ms
|    β”‚  β”‚     β”‚  β”œβ”€ Builder#copyDirectory.........................106 ms (31)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ files.symlink                                7 ms (198)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ files.rm_recursive                          16 ms (99)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ optimistic lstatOrNull......................71 ms (761)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”œβ”€ files.lstat                               3 ms (617)
|    β”‚  β”‚     β”‚  β”‚  β”‚  β”œβ”€ optimistic lstat                         16 ms (761)
|    β”‚  β”‚     β”‚  β”‚  β”‚  └─ other optimistic lstatOrNull             51 ms
|    β”‚  β”‚     β”‚  β”‚  └─ other Builder#copyDirectory                 10 ms
|    β”‚  β”‚     β”‚  β”œβ”€ optimistic statOrNull..........................13 ms (439)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ files.stat                                   4 ms (187)
|    β”‚  β”‚     β”‚  β”‚  └─ other optimistic statOrNull                 10 ms
|    β”‚  β”‚     β”‚  β”œβ”€ optimistic readJsonOrNull.......................6 ms (71)
|    β”‚  β”‚     β”‚  β”‚  β”œβ”€ optimistic readFile..........................2 ms (68)
|    β”‚  β”‚     β”‚  β”‚  β”‚  └─ files.readFile                            1 ms (68)
|    β”‚  β”‚     β”‚  β”‚  └─ other optimistic readJsonOrNull              4 ms
|    β”‚  β”‚     β”‚  └─ other JsImage#write                           108 ms
|    β”‚  β”‚     └─ other ServerTarget#write                          16 ms
|    β”‚  └─ other bundler writeSiteArchive                          17 ms
|    └─ other files.withCache                                       4 ms
| 
| Top leaves:
| other optimistic statOrNull..............................4,862 ms (225846)
| other PackageSourceBatch.computeJsOutputFilesMap.........3,664 ms (2)
| files.stat...............................................3,480 ms (70857)
| other plugin ecmascript..................................1,375 ms (2)
| other compileUnibuild (the app)..........................1,046 ms (2)
| Target#minifyJs............................................714 ms (1)
| other Target#_runCompilerPlugins...........................448 ms (2)
| Babel.compile..............................................398 ms (5865)
| sha1.......................................................236 ms (11754)
| other Target#make..........................................186 ms (2)
| safeWatcher.watch..........................................184 ms (14250)
| other optimistic readFile..................................173 ms (6832)
| Isopack#getUnibuildAtArch..................................170 ms (5820)
| ImportScanner#_getInstallPath..............................169 ms (9642)
| other files.withCache......................................160 ms (5)
| files.readFile.............................................157 ms (5521)
| other optimistic readJsonOrNull............................146 ms (3971)
| other optimistic hashOrNull................................120 ms (3614)
| other JsImage#write........................................108 ms (1)
| 
| (#7) Total: 18,378 ms (Rebuild App)

For anyone that can help us to analyze our problem further, we’ve prepared a report explaining how our meteor app infrastructure is shaped. There we provide the project sizes and some profiles measuring our timings on code change. I hope this can serve for someone to foresee what could be doing wrong in our project. Besides, we’ve also reported some of our practices that may affect the meteor builder to get down performance. We just want to check with you if these are good patterns or if can significatively affect to our timings.

You can check out the report here.

Have you considered direct support from MDG? It is a paid-for service, but they should be able to offer much deeper insight.