Research Meteor build performance

[brylie]

We are interested to know about any work going on regarding Meteor build performance. Lets use this issue to discuss and share knowledge about current efforts, shortcomings, or other findings related to the Meteor build process.

cc: @bajiat

[brylie]

@mauriciovieira is having a slow build process related to an sqlite query in the ProjectContext prepareProjectForBuild step. It may be related to a Meteor package catalog, or something similar.

See: meteor/meteor#6137

[mauriciovieira]

meteor/meteor#6137 (comment) we can see that the sqlite is on $HOME/.meteor, and it's a global catalog. The solution for this problem, is pretty much having a faster HD (SSD).

We made a comparison between machines and an i7 Linux box with SSD and 8GB RAM is:

Top leaves:
| other Input#loadFromCatalog..............................1,995 ms (1)
| generate constraints.....................................1,230 ms (1)
| sqlite query...............................................499 ms (453)
| generate dependency requirements...........................267 ms (1)
| generate package variables.................................258 ms (1)
| minimize conflicts.........................................254 ms (1)
| pre-solve..................................................186 ms (1)
| other safeWatcher.watch....................................162 ms (915)
| other optimistic lstat.....................................121 ms (1564)
| analyze allowed versions...................................113 ms (1)
| other Isopack#initFromPath.................................106 ms (169)
|
| (#1) Total: 6,522 ms (ProjectContext prepareProjectForBuild)

Top leaves:
| other Babel.compile.....................................31,630 ms (684)
| linker File#computeAssignedVariables.....................8,584 ms (2219)
| ImportScanner#_findImportedModuleIdentifiers.............8,131 ms (1865)
| other safeWatcher.watch..................................4,421 ms (3685)
| other plugin templating-compiler.........................3,077 ms (1)
| other plugin coffeescript................................2,029 ms (2)
| getPrelinkedFiles toStringWithSourceMap..................1,998 ms (310)
| linker File#getPrelinkedOutput...........................1,948 ms (2773)
| other optimistic statOrNull..............................1,922 ms (38304)
| other PackageSourceBatch#_linkJS.........................1,707 ms (310)
| files.stat...............................................1,351 ms (33587)
| other plugin less..........................................964 ms (1)
| files.writeFile............................................609 ms (1056)
| other files.withCache......................................515 ms (5)
| other plugin ecmascript....................................494 ms (2)
| other PackageSourceBatch.computeJsOutputFilesMap...........421 ms (2)
| wrapped.fs.readFileSync....................................355 ms (699)
| other Resolver#_joinAndStat................................346 ms (8902)
| safeWatcher.watch..........................................290 ms (1333)
| other runJavaScript packages/ecmascript-runtime.js.........236 ms (5)
| CssTools.stringifyCss......................................213 ms (1)
| other linker.fullLink......................................200 ms (310)
| sha1.......................................................198 ms (6193)
| other compileUnibuild (the app)............................182 ms (2)
| other linker Module#getPrelinkedFiles......................178 ms (310)
| other optimistic readFile..................................157 ms (3443)
| other Resolver#_resolveNodeModule..........................149 ms (1523)
| CssTools.parseCss..........................................146 ms (90)
| other Target#_runCompilerPlugins...........................146 ms (2)
| files.readFile.............................................136 ms (3713)
| other optimistic hashOrNull................................134 ms (2343)
| ImportScanner#_getInstallPath..............................117 ms (2875)
| files.lstat................................................107 ms (2057)
| files.readdir..............................................106 ms (5436)
|
| (#2) Total: 78,465 ms (Build App)

Top leaves:
I20170421-13:52:02.225(3)? | Npm.require("share").....................................2,836 ms (1)
I20170421-13:52:02.225(3)? | other Load server bundles..................................237 ms (1)
I20170421-13:52:02.225(3)? | Npm.require("mongodb").....................................219 ms (4)
I20170421-13:52:02.225(3)? | require("/node_modules/elasticsearch/src/elasticsearch.js").209 ms (1)
I20170421-13:52:02.225(3)? | other require("./node_modules/meteor/mizzao:sharejs/sharejs-server.js").177 ms (1)
I20170421-13:52:02.225(3)? | require("meteor-ecmascript-runtime").......................161 ms (1)
I20170421-13:52:02.225(3)? | other require("./node_modules/meteor/accounts-base/server_main.js").142 ms (1)
I20170421-13:52:02.225(3)? | require("/node_modules/swagger-parser/lib/index.js").......122 ms (1)
I20170421-13:52:02.226(3)? | Npm.require("request").....................................113 ms (1)
I20170421-13:52:02.226(3)? | Npm.require("connect").....................................106 ms (2)
I20170421-13:52:02.226(3)? |
I20170421-13:52:02.226(3)? | (#1) Total: 6,165 ms (Server startup)

while an i5 MacBook Pro with 4GB RAM shows:

| Top leaves:
| sqlite query............................................85,876 ms (453)
| files.readFile..........................................18,931 ms (2384)
| other Input#loadFromCatalog..............................4,653 ms (1)
| files.read...............................................3,107 ms (2433)
| files.readdir............................................2,799 ms (113)
| generate constraints.....................................2,781 ms (1)
| other Input#loadOnlyPreviousSolution.....................1,627 ms (1)
| files.stat...............................................1,243 ms (3589)
| generate dependency requirements...........................470 ms (1)
| minimize conflicts.........................................449 ms (1)
| generate package variables.................................402 ms (1)
| other Isopack#initFromPath.................................379 ms (169)
| other optimistic lstat.....................................340 ms (1630)
| other safeWatcher.watch....................................299 ms (967)
| analyze allowed versions...................................244 ms (1)
| pre-solve..................................................238 ms (1)
| other optimistic statOrNull................................214 ms (1410)
| other _downloadMissingPackages.............................150 ms (1)
| other IsopackCache Load local isopack......................148 ms (169)
| files.mkdir................................................140 ms (340)
| minimize total_packages....................................107 ms (1)
|
| (#1) Total: 127,132 ms (ProjectContext prepareProjectForBuild)

| Top leaves:
| other Babel.compile.....................................58,420 ms (693)
| files.stat..............................................49,525 ms (36659)
| files.readFile..........................................47,070 ms (3747)
| files.writeFile.........................................28,562 ms (1056)
| other PackageSourceBatch#_linkJS........................21,008 ms (310)
| linker File#computeAssignedVariables....................15,622 ms (2219)
| ImportScanner#_findImportedModuleIdentifiers............13,188 ms (1865)
| other safeWatcher.watch..................................6,398 ms (3700)
| other plugin coffeescript................................6,113 ms (2)
| files.rename.............................................3,721 ms (1062)
| getPrelinkedFiles toStringWithSourceMap..................3,685 ms (310)
| other plugin templating-compiler.........................3,557 ms (1)
| other optimistic statOrNull..............................3,546 ms (38483)
| files.readdir............................................3,070 ms (7964)
| linker File#getPrelinkedOutput...........................2,990 ms (2773)
| files.symlink............................................2,779 ms (149)
| CssTools.stringifyCss....................................2,756 ms (1)
| files.mkdir..............................................2,533 ms (77)
| other plugin less........................................2,188 ms (1)
| other runJavaScript packages/ecmascript-runtime.js.......1,869 ms (5)
| other plugin ecmascript..................................1,548 ms (2)
| wrapped.fs.readFileSync..................................1,389 ms (724)
| other files.withCache....................................1,274 ms (5)
| safeWatcher.watch..........................................763 ms (1431)
| other PackageSourceBatch.computeJsOutputFilesMap...........742 ms (2)
| other compileUnibuild (the app)............................697 ms (2)
| other Resolver#_joinAndStat................................595 ms (9088)
| other optimistic readFile..................................574 ms (3501)
| other linker.fullLink......................................528 ms (310)
| other optimistic hashOrNull................................427 ms (2381)
| sha1.......................................................420 ms (6220)
| CssTools.parseCss..........................................323 ms (90)
| other linker Module#getPrelinkedFiles......................303 ms (310)
| other Target#_runCompilerPlugins...........................303 ms (2)
| files.realpath.............................................227 ms (4028)
| Target#minifyJs............................................193 ms (1)
| other Resolver#_resolveNodeModule..........................192 ms (1527)
| other optimistic readJsonOrNull............................181 ms (1646)
| ImportScanner#_getInstallPath..............................176 ms (2901)
| other JsImage#write........................................176 ms (1)
| files.lstat................................................144 ms (2173)
| Isopack#getUnibuildAtArch..................................142 ms (8556)
| other ClientTarget#write...................................136 ms (1)
| other Builder#write........................................128 ms (743)
| other Resolver#_resolve....................................115 ms (2904)
| other optimistic lstat.....................................114 ms (1218)
| other Target#_emitResources................................109 ms (2)
|
| (#2) Total: 311,725 ms (Build App)

| Top leaves:
| files.stat...............................................5,358 ms (171)
| files.readFile...........................................1,481 ms (169)
| other _downloadMissingPackages.............................989 ms (1)
|
| (#3) Total: 7,986 ms (ProjectContext prepareProjectForBuild)

| Top leaves:
| files.writeFile..........................................1,670 ms (6)
| files.readFile...........................................1,545 ms (844)
| other PackageSourceBatch#_linkJS.........................1,315 ms (310)
| linker File#getPrelinkedOutput...........................1,309 ms (843)
| other compileUnibuild (the app)..........................1,286 ms (2)
| getPrelinkedFiles toStringWithSourceMap....................850 ms (1)
| files.readdir..............................................771 ms (769)
| other Target#_runCompilerPlugins...........................716 ms (2)
| other plugin ecmascript....................................624 ms (2)
| other PackageSourceBatch.computeJsOutputFilesMap...........588 ms (2)
| other files.withCache......................................563 ms (5)
| files.rename...............................................399 ms (6)
| other Babel.compile........................................358 ms (634)
| Isopack#getUnibuildAtArch..................................320 ms (8556)
| sha1.......................................................308 ms (3921)
| wrapped.fs.readFileSync....................................238 ms (320)
| other JsImage#write........................................163 ms (1)
| Target#minifyJs............................................160 ms (1)
| ImportScanner#_getInstallPath..............................156 ms (2901)
| other ClientTarget#write...................................155 ms (1)
| other Target#make..........................................144 ms (2)
| other plugin templating-compiler...........................131 ms (1)
| other plugin less..........................................122 ms (1)
| optimistic statOrNull......................................107 ms (4533)
| other linker Module#getPrelinkedFiles......................106 ms (1)
|
| (#4) Total: 17,095 ms (Rebuild App)

Aside from using SSD on the slower machine, I will look for coding/tweaking/configuration solutions and post here.

[mauriciovieira]

@apinf/developers I would like to see if it is a general issue or only of my self.

So what I ask you to do is to checkout latest master and run

git checkout master
git pull 
METEOR_PROFILE=1 meteor 

and post the results of the last command on a gist.

If the scrollup in the terminal does not work, try using tee

METEOR_PROFILE=1 meteor | tee /tmp/profile.log

[mauriciovieira]

My log https://gist.github.com/mauriciovieira/b1a2b5e53d6b4468e131587bb9e6bbb7

[manzapanza]

My log https://gist.github.com/manzapanza/de3c88cdd2110deb02a898e449bca96f

[marla-singer]

@mauriciovieira Do you still need it?

My log https://gist.github.com/marla-singer/485a649f3e905259a2d93ed12ee0e0db
OS: Debian 8
CPU: Core i5-3210M 2.50GHz
RAM: 8GB
Type of HDD: SDD

[brylie]

Hi all. It would also be helpful to know some details about our environments:

• OS/version
• CPU (processor and model number)
• RAM
• Type of HDD (e.g. SDD)

This will help us to get a better understanding of the performance for comparison.

[brylie]

@marla-singer would you also post a gist of your re-build time after modifying a file? There are at least two scenarios we want to see:

• fresh build time when first running the meteor command
• rebuild time when changing a file

[marla-singer]

@brylie I updated my log file. Now it contains also Re-build data