Meteor アプリのビルド時間の計測を行う方法(METEOR_PROFILE)


環境変数に `METEOR_PROFILE=50` をセットすると、Meteor アプリのビルド時間を計測できます。

```bash
METEOR_PROFILE=50 meteor
```

~~(50 の意味はよくわかっていません。どなたか教えてください。)~~
(11/1 追記)
コメントで教えていただきました。50は閾値で、上記のように指定した場合、処理に 50ms 以上かかった function のみ計測対象となるようです。
また、[meteor/tools/tool-env/profile.js](https://github.com/meteor/meteor/blob/dc3cd6eb92f2bdd1bb44000cdd6abd1e5d0285b1/tools/tool-env/profile.js) というツールがビルド時間の計測を行っているとのことです。
(追記ここまで)

## 計測例

Meteor の初期状態で、どれくらいビルドに時間がかかるのか計測してみました。

### 計測環境

Machine | MacBook Pro (Retina, Mid 2012)
-------|-----------
OS      | OS X Yosemite 10.10.5
CPU     | 2.3 GHz Intenl Core i7
Memory  | 16GB 1600 MHz DDR3


### サンプルアプリ作成
```console
$ cd /tmp
$ meteor create meteor-profile-example
$ cd meteor-profile-example
$ meteor --version
Meteor 1.2.0.2
```

### 計測

```
$ METEOR_PROFILE=50 meteor

[[[[[ /private/tmp/meteor-profile-example ]]]]]

=> Started proxy.
|  Selecting package versions                \
| JsImage#load: 410.1
|     other JsImage#load: 409.7
| Select Package Versions: 3630.7
|     Input#loadFromCatalog (sqlite): 3253.8
|     Solver#getAnswer: 349.7
|         generate constraints: 88.4
|         minimize total_packages: 173.3
|
| Input#loadFromCatalog (sqlite): 3253.8
| other JsImage#load: 409.7
| minimize total_packages: 173.3
| generate constraints: 88.4
| Total: 3925.2
=> Started MongoDB.
|  Building the application                  /
| files.readFile: 823.6
| bundler.readJsImage: 55.7
|     files.readFile: 51.6
| JsImage#load: 392.2
|     other JsImage#load: 391.7
| files.exists: 82.4
| files.writeFile: 19098.8
| files.rename: 9539.9
| Rebuild App: 18095.2
|     compiler.compile(the app): 4309.8
|         Isopack#ensurePluginsInitialized: 4284.2
|             JsImage#load: 2337.2
|                 files.exists: 560.2
|                 other JsImage#load: 1777.0
|             other Isopack#ensurePluginsInitialized: 1946.9
|     bundler.bundle..makeClientTarget: 8633.5
|         Target#make: 8633.3
|             Target#_runCompilerPlugins: 126.5
|                 processing files with ecmascript (for target web.browser): 61.5
|                     other processing files with ecmascript (for target web.browser): 61.4
|             Target#_emitResources: 8386.7
|                 PackageSourceBatch#getResources: 8383.3
|                     PackageSourceBatch#_linkJS: 8382.0
|                         files.readFile: 519.1
|                         linker.fullLink: 7762.7
|                             linker Module#getPrelinkedFiles: 2206.3
|                                 linker File#getPrelinkedOutput: 628.0
|                                 getPrelinkedFiles toStringWithSourceMap (packages): 1427.6
|                                 other linker Module#getPrelinkedFiles: 149.1
|                             linker Module#computeAssignedVariables: 5526.7
|                                 linker File#computeAssignedVariables: 5523.9
|                         other PackageSourceBatch#_linkJS: 94.7
|             ClientTarget#minifyCss: 73.1
|     bundler.bundle..makeServerTarget: 4173.4
|         Target#make: 4173.0
|             Target#_runCompilerPlugins: 993.2
|                 processing files with ecmascript (for target os.osx.x86_64): 965.6
|                     other processing files with ecmascript (for target os.osx.x86_64): 965.3
|             Target#_emitResources: 3159.4
|                 PackageSourceBatch#getResources: 3155.7
|                     PackageSourceBatch#_linkJS: 3154.0
|                         files.readFile: 188.3
|                         linker.fullLink: 2860.7
|                             linker Module#getPrelinkedFiles: 1851.7
|                                 linker File#getPrelinkedOutput: 511.5
|                                 getPrelinkedFiles toStringWithSourceMap (packages): 1209.0
|                                 other linker Module#getPrelinkedFiles: 131.2
|                             linker Module#computeAssignedVariables: 978.6
|                                 linker File#computeAssignedVariables: 976.3
|                         other PackageSourceBatch#_linkJS: 99.1
|     bundler..writeSiteArchive: 968.7
|         bundler..writeTargetToPath: 958.1
|             ClientTarget#write: 483.2
|                 Builder#write: 143.5
|                     files.writeFile: 118.3
|                 bundler..writeFile: 287.5
|                     Builder#write: 286.9
|                         files.writeFile: 266.3
|                 other ClientTarget#write: 51.4
|             ServerTarget#write: 470.4
|                 JsImage#write: 451.7
|                     Builder#write: 390.2
|                         files.writeFile: 330.3
|                     other JsImage#write: 56.6
|
| files.writeFile: 19818.5
| files.rename: 9570.4
| linker File#computeAssignedVariables: 6500.3
| getPrelinkedFiles toStringWithSourceMap (packages): 2636.6
| other JsImage#load: 2168.7
| other Isopack#ensurePluginsInitialized: 1946.9
| files.readFile: 1596.2
| linker File#getPrelinkedOutput: 1139.5
| other processing files with ecmascript (for target os.osx.x86_64): 965.3
| files.exists: 643.1
| other linker Module#getPrelinkedFiles: 280.3
| other PackageSourceBatch#_linkJS: 193.7
| ClientTarget#minifyCss: 73.1
| other processing files with ecmascript (for target web.browser): 61.4
| other linker.fullLink: 60.1
| other JsImage#write: 56.6
| other ClientTarget#write: 51.4
| Total: 47762.2
=> Started your app.

=> App running at: http://localhost:3000/

```

## 計測結果

&nbsp;   | MongoDB 起動 | App 起動   | Total
---------|-------------|------------|---------------------
初回起動時 | 3925.2 ms    | 47762.2 ms | 51687.4 ms ≒ 51.7s
２回目    | 3901. 0ms    | 5375.0 ms | 9,276 ms ≒ 9.3s
リロード時 | n/a          | 2915.0 ms | 2915.0 ≒ 2.9s

という結果になりました。
App の起動に結構時間がかかっているみたいですね。
起動時間が長いとストレスがかかるので、今後の改善に期待したいです。

## 参考

- [Rebuild time grew 50% after updating to 1.2 · Issue #5269 · meteor/meteor](https://github.com/meteor/meteor/issues/5269/)