Diagnosing long build times on Meteor 1.5.2.2 on Windows 10 x64


#1

Starting my app in development using METEOR_PROFILE=100, I’m getting this output that breaks down the build process and how long each part takes:

| (#1) Profiling: ProjectContext resolveConstraints
|  Selecting package versions                /
| ProjectContext resolveConstraints.............................1,861 ms (1)
| └─ _resolveConstraints........................................1,856 ms (1)
|    ├─ bundler.readJsImage.....................................1,576 ms (1)
|    │  └─ meteorNpm.rebuildIfNonPortable.......................1,569 ms (7)
|    │     └─ meteorNpm.isPortable..............................1,563 ms (174)
|    │        ├─ optimistic readJsonOrNull                        107 ms (316)
|    │        └─ meteorNpm.isPortable...........................1,326 ms (1336)
|    │           ├─ optimistic lstat..............................235 ms (1336)
|    │           │  ├─ files.lstat                                122 ms (1336)
|    │           │  └─ other optimistic lstat                     112 ms
|    │           └─ meteorNpm.isPortable..........................930 ms (1700)
|    │              ├─ optimistic lstat...........................318 ms (1700)
|    │              │  ├─ files.lstat                             170 ms (1700)
|    │              │  └─ other optimistic lstat                  148 ms
|    │              └─ meteorNpm.isPortable.......................501 ms (1513)
|    │                 ├─ optimistic lstat........................281 ms (1513)
|    │                 │  ├─ files.lstat                          159 ms (1513)
|    │                 │  └─ other optimistic lstat               123 ms
|    │                 └─ meteorNpm.isPortable....................158 ms (587)
|    │                    └─ optimistic lstat                     122 ms (587)
|    └─ JsImage#load..............................................227 ms (1)
|       └─ runJavaScript packages/ecmascript-runtime-server.js....104 ms (1)
|          └─ require("./node_modules/meteor/ecmascript-runtime-server/runtime.js") 102 ms (1)
|
| Top leaves:
| files.lstat................................................538 ms (5436)
| other optimistic lstat.....................................383 ms (4549)
| other meteorNpm.isPortable.................................205 ms (5310)
|
| (#1) Total: 1,861 ms (ProjectContext resolveConstraints)
|

=> Started proxy.
| (#2) Profiling: ProjectContext prepareProjectForBuild
|  Building local packages                   |
| ProjectContext prepareProjectForBuild........................12,707 ms (1)
| ├─ _downloadMissingPackages                                     107 ms (1)
| └─ _buildLocalPackages.......................................12,597 ms (1)
|    └─ IsopackCache Load local isopack........................12,590 ms (106)
|       └─ Isopack#initFromPath................................12,491 ms (106)
|          ├─ bundler.readJsImage...............................8,770 ms (8)
|          │  └─ meteorNpm.rebuildIfNonPortable.................8,674 ms (44)
|          │     └─ meteorNpm.isPortable........................8,650 ms (721)
|          │        ├─ optimistic lstat                           118 ms (721)
|          │        ├─ optimistic readJsonOrNull..................287 ms (897)
|          │        │  ├─ optimistic readFile                     131 ms (897)
|          │        │  └─ other optimistic readJsonOrNull         123 ms
|          │        ├─ meteorNpm.isPortable.....................7,993 ms (2592)
|          │        │  ├─ optimistic lstat........................419 ms (2592)
|          │        │  │  ├─ files.lstat                          210 ms (2592)
|          │        │  │  └─ other optimistic lstat               207 ms
|          │        │  ├─ optimistic statOrNull                   122 ms (320)
|          │        │  ├─ meteorNpm.isPortable..................7,255 ms (3201)
|          │        │  │  ├─ optimistic lstat.....................577 ms (3201)
|          │        │  │  │  ├─ files.lstat                       298 ms (3201)
|          │        │  │  │  └─ other optimistic lstat            279 ms
|          │        │  │  ├─ meteorNpm.isPortable...............6,335 ms (3669)
|          │        │  │  │  ├─ optimistic lstat..................713 ms (3669)
|          │        │  │  │  │  ├─ files.lstat                    356 ms (3669)
|          │        │  │  │  │  └─ other optimistic lstat         355 ms
|          │        │  │  │  ├─ optimistic statOrNull             110 ms (285)
|          │        │  │  │  ├─ meteorNpm.isPortable............5,315 ms (3711)
|          │        │  │  │  │  ├─ optimistic lstat...............649 ms (3711)
|          │        │  │  │  │  │  ├─ files.lstat                 322 ms (3711)
|          │        │  │  │  │  │  └─ other optimistic lstat      326 ms
|          │        │  │  │  │  ├─ meteorNpm.isPortable.........4,202 ms (3162)
|          │        │  │  │  │  │  ├─ optimistic lstat............583 ms (3162)
|          │        │  │  │  │  │  │  ├─ files.lstat              288 ms (3162)
|          │        │  │  │  │  │  │  └─ other optimistic lstat   290 ms
|          │        │  │  │  │  │  ├─ optimistic statOrNull       131 ms (332)
|          │        │  │  │  │  │  ├─ meteorNpm.isPortable......3,299 ms (2860)
|          │        │  │  │  │  │  │  ├─ optimistic lstat.........592 ms (2860)
|          │        │  │  │  │  │  │  │  ├─ files.lstat           285 ms (2860)
|          │        │  │  │  │  │  │  │  └─ other optimistic lstat 306 ms
|          │        │  │  │  │  │  │  └─ meteorNpm.isPortable...2,443 ms (2164)
|          │        │  │  │  │  │  │     ├─ optimistic lstat......420 ms (2164)
|          │        │  │  │  │  │  │     │  ├─ files.lstat        206 ms (2164)
|          │        │  │  │  │  │  │     │  └─ other optimistic lstat 209 ms
|          │        │  │  │  │  │  │     └─ meteorNpm.isPortable.1,829 ms (1757)
|          │        │  │  │  │  │  │        ├─ optimistic lstat...386 ms (1757)
|          │        │  │  │  │  │  │        │  ├─ files.lstat     177 ms (1757)
|          │        │  │  │  │  │  │        │  └─ other optimistic lstat 208 ms
|          │        │  │  │  │  │  │        └─ meteorNpm.isPortable.1,249 ms (1719)
|          │        │  │  │  │  │  │           ├─ optimistic lstat.389 ms (1719)
|          │        │  │  │  │  │  │           │  ├─ files.lstat  178 ms (1719)
|          │        │  │  │  │  │  │           │  └─ other optimistic lstat 206 ms
|          │        │  │  │  │  │  │           └─ meteorNpm.isPortable.721 ms (1176)
|          │        │  │  │  │  │  │              ├─ optimistic lstat.262 ms (1176)
|          │        │  │  │  │  │  │              │  ├─ files.lstat 124 ms (1176)
|          │        │  │  │  │  │  │              │  └─ other optimistic lstat 137 ms
|          │        │  │  │  │  │  │              └─ meteorNpm.isPortable.352 ms (480)
|          │        │  │  │  │  │  │                 ├─ optimistic lstat 113 ms (480)
|          │        │  │  │  │  │  │                 └─ meteorNpm.isPortable.207 ms (91)
|          │        │  │  │  │  │  │                    └─ meteorNpm.isPortable 145 ms (143)
|          │        │  │  │  │  │  └─ other meteorNpm.isPortable  119 ms
|          │        │  │  │  │  ├─ optimistic readJsonOrNull      158 ms (434)
|          │        │  │  │  │  └─ other meteorNpm.isPortable     138 ms
|          │        │  │  │  └─ other meteorNpm.isPortable        138 ms
|          │        │  │  └─ other meteorNpm.isPortable           143 ms
|          │        │  └─ other meteorNpm.isPortable              138 ms
|          │        └─ other meteorNpm.isPortable                 104 ms
|          └─ meteorNpm.rebuildIfNonPortable....................3,441 ms (24)
|             └─ meteorNpm.isPortable...........................3,426 ms (617)
|                ├─ optimistic lstat                              192 ms (617)
|                ├─ optimistic readJsonOrNull                     147 ms (769)
|                └─ meteorNpm.isPortable........................2,896 ms (1904)
|                   ├─ optimistic lstat...........................276 ms (1904)
|                   │  ├─ files.lstat                             134 ms (1904)
|                   │  └─ other optimistic lstat                  141 ms
|                   └─ meteorNpm.isPortable.....................2,460 ms (2008)
|                      ├─ optimistic lstat........................291 ms (2008)
|                      │  ├─ files.lstat                          151 ms (2008)
|                      │  └─ other optimistic lstat               140 ms
|                      └─ meteorNpm.isPortable..................1,902 ms (3185)
|                         ├─ optimistic lstat.....................493 ms (3185)
|                         │  ├─ files.lstat                       257 ms (3185)
|                         │  └─ other optimistic lstat            234 ms
|                         └─ meteorNpm.isPortable...............1,233 ms (1641)
|                            ├─ optimistic lstat..................259 ms (1641)
|                            │  ├─ files.lstat                    134 ms (1641)
|                            │  └─ other optimistic lstat         125 ms
|                            └─ meteorNpm.isPortable..............828 ms (806)
|                               ├─ optimistic lstat               129 ms (806)
|                               └─ meteorNpm.isPortable...........638 ms (373)
|                                  └─ meteorNpm.isPortable........487 ms (833)
|                                     ├─ optimistic lstat         150 ms (833)
|                                     └─ meteorNpm.isPortable.....302 ms (119)
|                                        └─ meteorNpm.isPortable..246 ms (186)
|                                           └─ meteorNpm.isPortable.182 ms (106)
|                                              └─ meteorNpm.isPortable 118 ms (222)
|
| Top leaves:
| files.lstat..............................................3,561 ms (40348)
| other optimistic lstat...................................3,165 ms (34749)
| other meteorNpm.isPortable...............................1,527 ms (39081)
| files.stat.................................................705 ms (9799)
| files.readFile.............................................479 ms (4088)
| files.readdir..............................................369 ms (4237)
| other optimistic readJsonOrNull............................123 ms (897)
|
| (#2) Total: 12,707 ms (ProjectContext prepareProjectForBuild)
|
| (#3) Profiling: Build App                  \
|  Starting your app                         /
| Build App....................................................39,342 ms (1)
| └─ files.withCache...........................................39,341 ms (1)
|    ├─ compiler.compile(the app)..............................22,570 ms (1)
|    │  └─ files.withCache.....................................22,569 ms (2)
|    │     └─ compileUnibuild (the app)........................22,569 ms (2)
|    │        ├─ Isopack#ensurePluginsInitialized...............2,594 ms (24)
|    │        │  └─ JsImage#load................................2,584 ms (5)
|    │        │     ├─ runJavaScript packages/ecmascript-runtime.js 121 ms (2)
|    │        │     ├─ runJavaScript packages/babel-compiler.js...447 ms (2)
|    │        │     │  └─ Npm.require("meteor-babel")             441 ms (1)
|    │        │     ├─ runJavaScript packages/urigo_static-html-compiler.js 1,199 ms (1)
|    │        │     └─ runJavaScript packages/compileNGScript_plugin.js.563 ms (1)
|    │        │        └─ Npm.require("babel-core")               519 ms (1)
|    │        ├─ files.withCache...............................19,551 ms (2)
|    │        │  ├─ files.realpath                              1,988 ms (18363)
|    │        │  ├─ files.readdir                               2,588 ms (36726)
|    │        │  ├─ files.stat                                  7,222 ms (108397)
|    │        │  └─ other files.withCache                       7,734 ms
|    │        ├─ optimistic readFile                              109 ms (715)
|    │        └─ other compileUnibuild (the app)                  238 ms
|    ├─ bundler.bundle..makeClientTarget.......................10,465 ms (1)
|    │  └─ Target#make.........................................10,465 ms (1)
|    │     ├─ Target#_runCompilerPlugins........................5,288 ms (1)
|    │     │  ├─ Isopack#ensurePluginsInitialized.................581 ms (169)
|    │     │  │  ├─ JsImage#load                                  111 ms (1)
|    │     │  │  └─ Npm.require("meteor-babel")                   466 ms (1)
|    │     │  ├─ plugin ecmascript                                158 ms (1)
|    │     │  ├─ plugin pbastowski:angular-babel                1,537 ms (1)
|    │     │  ├─ plugin meteor                                    124 ms (1)
|    │     │  └─ plugin angular-templates                       2,846 ms (1)
|    │     ├─ Target#_emitResources.............................4,932 ms (1)
|    │     │  ├─ PackageSourceBatch.computeJsOutputFilesMap.....4,256 ms (1)
|    │     │  │  ├─ ImportScanner#_getInstallPath                 103 ms (1413)
|    │     │  │  ├─ ImportScanner#_findImportedModuleIdentifiers 2,892 ms (716)
|    │     │  │  ├─ Resolver#_resolve.............................835 ms (886)
|    │     │  │  │  ├─ Resolver#_resolveRelative..................243 ms (886)
|    │     │  │  │  │  └─ Resolver#_joinAndStat...................239 ms (699)
|    │     │  │  │  │     └─ optimistic statOrNull                198 ms (1370)
|    │     │  │  │  └─ Resolver#_resolveNodeModule................553 ms (187)
|    │     │  │  │     └─ Resolver#_joinAndStat...................537 ms (655)
|    │     │  │  │        └─ optimistic statOrNull................496 ms (2169)
|    │     │  │  │           ├─ safeWatcher.watch                 109 ms (753)
|    │     │  │  │           ├─ files.stat                        118 ms (1410)
|    │     │  │  │           └─ other optimistic statOrNull       227 ms
|    │     │  │  ├─ ImportScanner#_readFile.......................206 ms (574)
|    │     │  │  │  └─ optimistic readFile                        115 ms (574)
|    │     │  │  └─ other PackageSourceBatch.computeJsOutputFilesMap 212 ms
|    │     │  └─ PackageSourceBatch#getResources..................666 ms (77)
|    │     │     └─ PackageSourceBatch#_linkJS....................664 ms (77)
|    │     │        ├─ files.readFile                             257 ms (77)
|    │     │        └─ other PackageSourceBatch#_linkJS           406 ms
|    │     └─ Target#minifyJs                                     160 ms (1)
|    ├─ bundler.bundle..makeServerTarget........................1,754 ms (1)
|    │  └─ Target#make..........................................1,754 ms (1)
|    │     ├─ Target#_runCompilerPlugins........................1,147 ms (1)
|    │     │  ├─ plugin ecmascript                                123 ms (1)
|    │     │  ├─ plugin pbastowski:angular-babel                  809 ms (1)
|    │     │  └─ plugin angular-templates                         168 ms (1)
|    │     └─ Target#_emitResources...............................592 ms (1)
|    │        └─ PackageSourceBatch.computeJsOutputFilesMap.......515 ms (1)
|    │           ├─ ImportScanner#_findImportedModuleIdentifiers  248 ms (135)
|    │           └─ Resolver#_resolve.............................174 ms (197)
|    │              └─ Resolver#_resolveNodeModule................149 ms (109)
|    │                 └─ Resolver#_joinAndStat...................143 ms (258)
|    │                    └─ optimistic statOrNull                133 ms (662)
|    └─ bundler writeSiteArchive................................4,537 ms (1)
|       ├─ bundler writeTargetToPath............................3,885 ms (2)
|       │  ├─ ClientTarget#write................................1,802 ms (1)
|       │  │  ├─ bundler writeFile..............................1,613 ms (156)
|       │  │  │  └─ Builder#write...............................1,611 ms (156)
|       │  │  │     ├─ files.writeFile                          1,330 ms (156)
|       │  │  │     └─ files.rename                               253 ms (156)
|       │  │  └─ Builder#write....................................131 ms (17)
|       │  │     └─ files.writeFile                               101 ms (17)
|       │  └─ ServerTarget#write................................2,075 ms (1)
|       │     └─ JsImage#write..................................1,990 ms (1)
|       │        ├─ Builder#write...............................1,264 ms (106)
|       │        │  ├─ files.writeFile                          1,063 ms (106)
|       │        │  └─ files.rename                               174 ms (106)
|       │        ├─ meteorNpm.isPortable                          121 ms (17)
|       │        └─ Builder#copyDirectory.........................384 ms (17)
|       │           ├─ files.symlink                              185 ms (129)
|       │           └─ optimistic lstatOrNull                     129 ms (420)
|       └─ Builder#complete.......................................602 ms (1)
|          └─ files.renameDirAlmostAtomically.....................602 ms (1)
|             └─ files.rm_recursive                               599 ms (1)
|
| Top leaves:
| other files.withCache....................................7,745 ms (5)
| files.stat...............................................7,611 ms (112720)
| ImportScanner#_findImportedModuleIdentifiers.............3,140 ms (851)
| files.readdir............................................2,592 ms (36755)
| files.writeFile..........................................2,573 ms (297)
| files.realpath...........................................1,995 ms (18388)
| files.rm_recursive.........................................603 ms (4)
| files.rename...............................................487 ms (303)
| files.readFile.............................................466 ms (1950)
| other PackageSourceBatch#_linkJS...........................406 ms (77)
| other PackageSourceBatch.computeJsOutputFilesMap...........269 ms (2)
| other compileUnibuild (the app)............................238 ms (2)
| other optimistic statOrNull................................227 ms (2169)
| files.symlink..............................................186 ms (130)
| Target#minifyJs............................................160 ms (1)
| ImportScanner#_getInstallPath..............................129 ms (1855)
| Babel.compile..............................................128 ms (205)
| sha1.......................................................118 ms (3458)
|
| (#3) Total: 39,342 ms (Build App)
|
=> Started MongoDB.
I20171020-11:58:40.334(-4)? | (#1) Profiling: Server startup
I20171020-11:58:41.251(-4)? |
I20171020-11:58:41.253(-4)? | Server startup................................................1,262 ms (1)
I20171020-11:58:41.255(-4)? | └─ Load server bundles........................................1,234 ms (1)
I20171020-11:58:41.257(-4)? |    ├─ packages/ecmascript-runtime-server.js.....................104 ms (1)
I20171020-11:58:41.258(-4)? |    │  └─ require("./node_modules/meteor/ecmascript-runtime-server/runtime.js") 103 ms (1)
I20171020-11:58:41.260(-4)? |    ├─ packages/npm-mongo.js.....................................168 ms (1)
I20171020-11:58:41.262(-4)? |    │  └─ Npm.require("mongodb")                                 167 ms (1)
I20171020-11:58:41.264(-4)? |    ├─ packages/webapp.js........................................148 ms (1)
I20171020-11:58:41.266(-4)? |    │  └─ require("./node_modules/meteor/webapp/webapp_server.js") 148 ms (1)
I20171020-11:58:41.270(-4)? |    ├─ packages/http.js..........................................140 ms (1)
I20171020-11:58:41.272(-4)? |    │  └─ require("./node_modules/meteor/http/httpcall_server.js").139 ms (1)
I20171020-11:58:41.275(-4)? |    │     └─ Npm.require("request")                              137 ms (1)
I20171020-11:58:41.280(-4)? |    ├─ app/app.js                                                106 ms (1)
I20171020-11:58:41.281(-4)? |    └─ other Load server bundles                                 134 ms
I20171020-11:58:41.282(-4)? |
I20171020-11:58:41.284(-4)? | Top leaves:
I20171020-11:58:41.285(-4)? | Npm.require("mongodb").....................................167 ms (1)
I20171020-11:58:41.291(-4)? | Npm.require("request").....................................137 ms (1)
I20171020-11:58:41.293(-4)? | other Load server bundles..................................134 ms (1)
I20171020-11:58:41.295(-4)? |
I20171020-11:58:41.298(-4)? | (#1) Total: 1,262 ms (Server startup)
I20171020-11:58:41.299(-4)? |
=> Started your app.

I want to avoid needlessly opening an issue until I understand this better, but I don’t see an obvious culprit here. My project is pretty large, about 5 MB of total code and static assets, 170 MBs in node_modules, and .meteor is huge at 4 GBs which includes the dev_bundle and all the local db file and recent development builds (so I’d expect it to be huge).

I’ve got to assume size is factoring into all this, because on a fresh project or simple-todos, build times are very fast. As you can see the Build App routine

| (#3) Total: 39,342 ms (Build App)

takes the longest, and it’s relatively spread out among the component routines. Out of all the lower level stuff,

|    │        ├─ files.withCache...............................19,551 ms (2)

takes the longest. In general, it looks like things in the “Build App” section just take kinda long, and it quickly adds up.

On another weird note, it says

(#1) Total: 1,262 ms (Server startup)

which I find kinda hard to believe because after the => Started MongoDB. appears, I wait way more than 1 second. Not sure what’s going on there, either.

I have a pretty high performance workstation, both at the office and at home. Build times are generally the same on both, so I’m not sure any hardware is causing the bottleneck. I’m assuming for now it’s somewhere in the software, I’m just not yet certain if this is a Meteor issue, per se.

I’ve been using Meteor with this particular project for over 2 years, so it’s been upgraded from several releases, I wanna say the first Meteor version I used with this project was 1.1? Basically right after they started supporting Windows, iirc

Guess a few questions come to mind…

  1. Is my codebase just big, and it’s gonna take a long time to build no matter what I do?
  2. Is this a Windows specific phenomenon?
  3. Is there something funny going on with my .meteor directory? Should it be that large, and if not, what does its size imply?