Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rebuild time grew 50% after updating to 1.2 #5269

Closed
avalanche1 opened this issue Sep 24, 2015 · 34 comments
Closed

Rebuild time grew 50% after updating to 1.2 #5269

avalanche1 opened this issue Sep 24, 2015 · 34 comments

Comments

@avalanche1
Copy link

@avalanche1 avalanche1 commented Sep 24, 2015

_1 Upvote_ It now loads compileLessBatch, compile-ecmascript, CosmosBrowserify, builds for web.cordova.
meteor-load
Refresh time grew accordingly.
I'm on win7, btw.

@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Sep 24, 2015

Things to do if you want to improve your report:

  • post what packages you are using and what versions of the packages?
  • post how many files of each extension are you using in your project? how big are the files?
  • post what files are you changing that triggers the rebuild? server-side file? client-side file? CSS? template? etc?
  • CosmosBrowserify is usually very slow. What npm packages are you trying to load with browserify?
  • post output with the METEOR_PROFILE=50 env variable set.
@avalanche1

This comment has been minimized.

Copy link
Author

@avalanche1 avalanche1 commented Sep 25, 2015

Here you go:

accounts-password              1.1.3  Password support for accounts
audit-argument-checks          1.0.4  Try to detect inadequate input sanitiza...
bigdsk:inputmask               3.1.63  JQuery InputMask for Meteor
blaze-html-templates           1.0.1  Compile HTML templates into reactive UI...
check                          1.0.6  Check whether a value matches a pattern
coffeescript                   1.0.9  Javascript dialect with fewer braces an...
dburles:lazy                   1.0.0  A handy little development tool
ejson                          1.0.7  Extended and Extensible JSON library
fastclick                      1.0.7  Faster touch events on mobile
jquery                         1.11.4  Manipulate the DOM using CSS selectors
kadira:debug                   2.2.3  Full Stack Debugging Solution for Meteor
logging                        1.0.8  Logging facility.
manuel:viewmodel               1.9.12  MVVM, two-way data binding, and compon...
manuel:viewmodel-explorer      1.0.5  Side panel for manuel:viewmodel
meteor-base                    1.0.1  Packages that every Meteor app needs
meteorhacks:fast-render        2.10.0  Render your app before the DDP connect...
meteorhacks:subs-manager       1.6.2  Subscriptions Manager for Meteor
momentjs:moment                2.10.6  Moment.js (official): parse, validate,...
mongo                          1.1.1  Adaptor for using MongoDB and Minimongo...
mquandalle:bower               1.5.2  Use Bower packages in your Meteor app
mquandalle:jade                0.4.3_1  Jade template language
mquandalle:stylus              1.1.1  Expressive, dynamic, robust CSS
msavin:fetcher                 1.1.0  Retrieve static data from Methods
msavin:jetsetter               1.0.20  Visual Get/Set Tool for Sessions
msavin:mongol                  1.1.5  The insanely handy development package ...
multiply:iron-router-progress  1.0.2  Progressbar for iron:router
random                         1.0.4  Random number generator and utilities
reactive-var                   1.0.6  Reactive variable
reload                         1.1.4  Reload the page while preserving applic...
remcoder:chronos               0.3.1  Reactive time utilities. Includes react...
rubaxa:sortable                1.2.1  Sortable: reactive minimalist reorderab...
semantic:ui-css                2.1.2  Semantic UI - CSS Release of Semantic UI
session                        1.1.1  Session variable
spacebars                      1.0.7  Handlebars-like template language for M...
standard-minifiers             1.0.0  Standard minifiers used with Meteor app...
tracker                        1.0.8  Dependency tracker to allow reactive ca...
underscore                     1.0.4  Collection of small helpers: _.map, _.e...
zodern:nice-reload             2.0.0  Trigger hot reload with ctr + l (alt + ...

As you can see, I dont have Browserify added, so I have no idea why it's mentioned during build time.
But I do get the following message running meteor update:

This project is already at Meteor 1.2.0.1, the latest release.
Your top-level dependencies are at their latest compatible versions.

Newer versions of the following indirect dependencies are available:
 * babrahams:editable-json 0.5.7 (0.6.0 is available)
 * cosmos:browserify 0.4.0 (0.7.0 is available)
To update one or more of these packages, pass their names to `meteor update`.

Here are my files:
image
image
They are not many, nor are they big.


  • In my initial post I attached a capture of initial app start timing.
  • With or w\o 'METEOR_PROFILE=50' it takes 24 seconds to start.
  • And I don't know why it mentions web.cordova as my proj has nothing to do with cordova development for the time being.
@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Sep 25, 2015

@avalanche1 please, post the output of env METEOR_PROFILE=50 meteor run after a rebuild.

@avalanche1

This comment has been minimized.

Copy link
Author

@avalanche1 avalanche1 commented Sep 29, 2015

I've actually managed to significantly improve build time by deleting .meteor folder in User/Appdata/Local and also in my prj folder (_just don't forget to backup your db which is in prj/.meteor/local/db_)
Then I installed v1.1 (because v1.2 installer won't work - #5293), build time = 4s.
Installed all packages, build time = 10s
Updated to 1.2, build time = 15s.
Better, than 24s, but still a 50% increase in time 1.2 vs 1.1.

And I don't know how to copy profiling results after METEOR_PROFILE=50 because there are dozens and dozens of lines of output.

@steph643

This comment has been minimized.

Copy link

@steph643 steph643 commented Sep 29, 2015

My rebuild time has gone from 5s to 7s (Win 7) when changing a client-side js file.

Packages:

accounts-facebook                         1.0.6  Login service for Faceb...
accounts-google                           1.0.6  Login service for Googl...
accounts-password                         1.1.3  Password support for ac...
aldeed:collection2                        2.5.0  Automatic validation of...
audit-argument-checks                     1.0.4  Try to detect inadequat...
blaze-html-templates                      1.0.1  Compile HTML templates ...
brettle:accounts-multiple                 0.3.0* Handles users that logi...
check                                     1.0.6  Check whether a value m...
dburles:collection-helpers                1.0.3  Transform your collecti...
ecmascript                                0.1.4* Compiler plugin that su...
ejson                                     1.0.7  Extended and Extensible...
email                                     1.0.7  Send email messages
es5-shim                                  4.1.13  Shims and polyfills to...
gadicohen:reactive-window                 1.0.6  Reactive functions for ...
http                                      1.1.1  Make HTTP calls to remo...
ian:accounts-ui-bootstrap-3               1.2.80  Bootstrap-styled accou...
jquery                                    1.11.4  Manipulate the DOM usi...
kadira:blaze-layout                       2.1.0  Layout Manager for Blaz...
kadira:flow-router                        2.6.2  Carefully Designed Clie...
meteor-base                               1.0.1  Packages that every Met...
mizzao:bootboxjs                          4.4.0  Programmatic dialog box...
mobile-experience                         1.0.1  Packages for a great mo...
momentjs:moment                           2.10.6  Moment.js (official): ...
mongo                                     1.1.1* Adaptor for using Mongo...
random                                    1.0.4  Random number generator...
reactive-dict                             1.1.1* Reactive dictionary
reactive-var                              1.0.6  Reactive variable
sdecima:javascript-detect-element-resize  0.5.3  Official.  Efficient cr...
service-configuration                     1.0.5  Manage the configuratio...
session                                   1.1.1  Session variable
standard-minifiers                        1.0.0* Standard minifiers used...
templates:forms                           1.14.2  Dead easy reactive for...
tracker                                   1.0.8* Dependency tracker to a...
twbs:bootstrap                            3.3.5  The most popular front-...
vazco:universe-html-purifier              1.2.3  Package to sanitize HTM...

Files, excluding .meteor:

  • 83 js files, 427 453 bytes
  • 45 html files, 81 101 bytes
  • 48 css files, 290 010 bytes

Files, including .meteor:

  • 391 js files, 14.9MB
  • 51 html files, 92 849 bytes
  • 64 css files, 731 368 bytes

METEOR_PROFILE=50 output:

=> Started proxy.
=> Started MongoDB.
|  Downloading 16 packages                   /
| Isopack.readMetadataFromDirectory: 3424.2
|     files.exists: 1234.2
|     files.readFile: 2172.9
| files.exists: 6467.4
| JsImage#load: 436.5
|     other JsImage#load: 433.4
| files.writeFile: 64.9
| Select Package Versions: 6039.7
|     Input#loadFromCatalog (sqlite): 4880.3
|     new CS.Solver: 74.6
|         Solver#analyze: 74.3
|             analyze constraints: 55.7
|     Solver#getAnswer: 1075.8
|         generate package variables: 74.7
|         generate dependency requirements: 88.9
|         generate constraints: 134.3
|         pre-solve: 340.1
|         minimize conflicts: 126.5
|         minimize previous_root_incompat: 95.0
|         minimize total_packages: 102.3
|
| files.exists: 7704.7
| Input#loadFromCatalog (sqlite): 4880.3
| files.readFile: 2203.8
| other JsImage#load: 433.4
| pre-solve: 340.1
| generate constraints: 134.3
| minimize conflicts: 126.5
| minimize total_packages: 102.3
| minimize previous_root_incompat: 95.0
| generate dependency requirements: 88.9
| generate package variables: 74.7
| files.writeFile: 64.9
| analyze constraints: 55.7
| Total: 16304.5
|  Downloading 16 packages                   |
| files.readFile: 53.5
| JsImage#load: 513.0
|     other JsImage#load: 511.9
| files.exists: 56.3
| files.realpath: 2431.4
| files.mkdir: 2515.6
| files.stat: 2933.8
| files.readdir: 1552.8
| files.lstat: 1658.5
| files.rename: 428.2
| files.rm_recursive: 547.9
| files.open: 51.1
| files.close: 50.8
| files.chmod: 2064.1
| Isopack#saveToPath: 11140.6
|     files.stat: 313.8
|     files.mkdir: 446.0
|     Builder#write: 3153.4
|         files.stat: 348.9
|         files.writeFile: 2281.3
|         files.rename: 476.1
|     files.writeFile: 641.3
|     files.rename: 62.9
|     linker.prelink: 4465.6
|         linker Module#computeAssignedVariables: 2669.4
|             linker File#computeAssignedVariables: 2668.0
|         linker Module#getPrelinkedFiles: 1783.1
|             linker File#getPrelinkedOutput: 442.6
|             getPrelinkedFiles toStringWithSourceMap (packages): 1251.2
|             other linker Module#getPrelinkedFiles: 89.3
|     Builder#copyDirectory: 1497.0
|         files.lstat: 223.2
|         files.stat: 113.0
|         other Builder#copyDirectory: 1136.7
|     JsImage#write: 409.9
|         Builder#write: 389.3
|             files.writeFile: 355.7
|     other Isopack#saveToPath: 102.1
| Rebuild App: 20527.5
|     compiler.compile(the app): 7726.5
|         Isopack#ensurePluginsInitialized: 4499.9
|             JsImage#load: 2720.1
|                 files.exists: 757.7
|                 other JsImage#load: 1962.5
|             other Isopack#ensurePluginsInitialized: 1779.8
|         files.readdir: 1832.9
|         files.stat: 446.9
|         files.realpath: 67.5
|         files.readFile: 711.9
|         other compiler.compile(the app): 149.6
|     bundler.bundle..makeClientTarget: 6114.2
|         Target#make: 6114.0
|             Target#_runCompilerPlugins: 3846.5
|                 Isopack#ensurePluginsInitialized: 3339.1
|                     JsImage#load: 3330.2
|                         files.exists: 608.2
|                         other JsImage#load: 2722.0
|                 processing files with ecmascript (for target web.browser): 136
.7
|                     other processing files with ecmascript (for target web.bro
wser): 134.6
|                 processing files with templating (for target web.browser): 280
.2
|                     wrapped.fs.readFileSync: 257.1
|                 other Target#_runCompilerPlugins: 64.1
|             Target#_emitResources: 1610.4
|                 PackageSourceBatch#getResources: 1595.9
|                     PackageSourceBatch#_linkJS: 1593.0
|                         files.readFile: 1399.2
|                         other PackageSourceBatch#_linkJS: 183.0
|             ClientTarget#minifyCss: 576.7
|     bundler.bundle..makeServerTarget: 775.5
|         Target#make: 775.2
|             Target#_runCompilerPlugins: 100.6
|             Target#_emitResources: 650.0
|                 PackageSourceBatch#getResources: 643.0
|                     PackageSourceBatch#_linkJS: 639.8
|                         files.readFile: 546.3
|                         other PackageSourceBatch#_linkJS: 82.2
|     bundler..writeSiteArchive: 5896.0
|         bundler..writeTargetToPath: 4589.1
|             ClientTarget#write: 3434.8
|                 Builder#write: 1070.4
|                     files.stat: 403.3
|                     files.writeFile: 334.0
|                     files.rename: 267.0
|                 bundler..writeFile: 2125.0
|                     Builder#write: 2120.7
|                         files.stat: 1066.0
|                         files.writeFile: 582.4
|                         files.rename: 404.9
|                         other Builder#write: 58.2
|                 other ClientTarget#write: 196.0
|             ServerTarget#write: 1103.3
|                 JsImage#write: 1054.2
|                     Builder#write: 836.8
|                         files.stat: 101.1
|                         files.writeFile: 380.0
|                         files.rename: 248.6
|                         other Builder#write: 65.1
|                     other JsImage#write: 202.5
|         Builder#complete: 1277.5
|             files.rm_recursive: 1263.8
|
| files.stat: 5784.6
| other JsImage#load: 5196.4
| files.writeFile: 4611.8
| files.readdir: 3397.9
| files.mkdir: 3027.0
| files.readFile: 2793.3
| linker File#computeAssignedVariables: 2668.0
| files.realpath: 2498.9
| files.chmod: 2064.1
| files.rename: 2012.8
| files.lstat: 1881.8
| files.rm_recursive: 1817.8
| other Isopack#ensurePluginsInitialized: 1788.7
| files.exists: 1429.5
| getPrelinkedFiles toStringWithSourceMap (packages): 1251.2
| other Builder#copyDirectory: 1136.7
| ClientTarget#minifyCss: 576.7
| linker File#getPrelinkedOutput: 442.6
| other PackageSourceBatch#_linkJS: 265.2
| wrapped.fs.readFileSync: 257.1
| other JsImage#write: 204.2
| other ClientTarget#write: 196.0
| other Builder#write: 194.6
| sha1: 157.9
| other compiler.compile(the app): 149.6
| other processing files with ecmascript (for target web.browser): 134.6
| other Isopack#saveToPath: 102.1
| other Target#_runCompilerPlugins: 96.0
| other linker Module#getPrelinkedFiles: 89.3
| Isopack#getUnibuildAtArch: 58.1
| files.open: 51.1
| files.close: 50.8
| Total: 46386.3
=> Started your app.

=> App running at: http://localhost:3000/
   Type Control-C twice to stop.
@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Sep 30, 2015

Given that these reports only come from the Windows users (so far), the slow down could be relevant to this issue: #5278. Although the output from @steph643 doesn't indicate this.

@JeremySaks

This comment has been minimized.

Copy link

@JeremySaks JeremySaks commented Sep 30, 2015

The build time has also roughly doubled for me on OSX, if I'm understanding the METEOR_PROFILE=50 output correctly. I get Total: 2694.6 on 1.1.0.3, and on a fresh install of the same app at 1.2.0.2 I get Total: 5914.2. LMK if packages and/or detailed profile output would be useful to see. Both versions are running cosmos:browserify.

@aaronjudd

This comment has been minimized.

Copy link

@aaronjudd aaronjudd commented Oct 1, 2015

On OSX compiling is orders of magnitude slower. Without going back and checking - because it's so much slower that it's really obvious . Building reactioncommerce/reaction repo:

=> Started proxy.                             
=> Started MongoDB.                           
|  Selecting package versions                -
| JsImage#load: 244.9
|     other JsImage#load: 244.6
| Select Package Versions: 4368.0
|     Input#loadFromCatalog (sqlite): 2981.9
|     new CS.Solver: 52.6
|         Solver#analyze: 52.4
|     Solver#getAnswer: 1325.1
|         generate package variables: 166.3
|         generate dependency requirements: 126.6
|         generate constraints: 265.9
|         pre-solve: 292.8
|         minimize conflicts: 186.4
|         minimize total_packages: 121.2
| 
| Input#loadFromCatalog (sqlite): 2981.9
| pre-solve: 292.8
| generate constraints: 265.9
| other JsImage#load: 244.6
| minimize conflicts: 186.4
| generate package variables: 166.3
| generate dependency requirements: 126.6
| minimize total_packages: 121.2
| Total: 4385.6
|  Building the application                  |
| files.readFile: 160.4
| JsImage#load: 340.3
|     other JsImage#load: 338.2
| files.writeFile: 67484.9
| files.rename: 33677.3
| Rebuild App: 51118.1
|     compiler.compile(the app): 649.1
|         Isopack#ensurePluginsInitialized: 553.8
|             JsImage#load: 553.4
|                 files.exists: 426.0
|                 other JsImage#load: 127.4
|     bundler.bundle..makeClientTarget: 39899.1
|         Target#make: 39898.9
|             Target#_runCompilerPlugins: 15731.7
|                 Isopack#ensurePluginsInitialized: 642.0
|                     JsImage#load: 638.7
|                         other JsImage#load: 634.2
|                 processing files with ecmascript (for target web.browser): 8700.2
|                     other processing files with ecmascript (for target web.browser): 8695.8
|                 processing files with templating (for target web.browser): 1395.2
|                     wrapped.fs.readFileSync: 75.0
|                     other processing files with templating (for target web.browser): 1312.8
|                 processing files with less (for target web.browser): 4895.0
|                     other processing files with less (for target web.browser): 4883.9
|                 other Target#_runCompilerPlugins: 66.7
|             Target#_emitResources: 23092.9
|                 PackageSourceBatch#getResources: 23083.9
|                                 linker File#computeAssignedVariables: 11154.3
|                             other linker.fullLink: 237.8
|                         other PackageSourceBatch#_linkJS: 494.7
|             ClientTarget#minifyCss: 943.0
|     bundler.bundle..makeServerTarget: 9640.9
|         Target#make: 9640.7
|             Target#_runCompilerPlugins: 2884.1
|                 processing files with ecmascript (for target os.osx.x86_64): 2819.1
|                     other processing files with ecmascript (for target os.osx.x86_64): 2817.0
|             Target#_emitResources: 6689.7
|                 PackageSourceBatch#getResources: 6679.7
|                     PackageSourceBatch#_linkJS: 6676.4
|                         files.readFile: 110.1
|                         linker.fullLink: 6315.8
|                             linker Module#getPrelinkedFiles: 4186.1
|                                 linker File#getPrelinkedOutput: 1182.3
|                                 getPrelinkedFiles toStringWithSourceMap (packages): 2648.4
|                                 other linker Module#getPrelinkedFiles: 353.5
|                             linker Module#computeAssignedVariables: 2060.5
|                                 linker File#computeAssignedVariables: 2056.2
|                             other linker.fullLink: 69.2
|                         other PackageSourceBatch#_linkJS: 229.8
|     bundler..writeSiteArchive: 917.8
|         bundler..writeTargetToPath: 909.0
|             ClientTarget#write: 487.9
|                 Builder#write: 123.9
|                 bundler..writeFile: 134.7
|                     Builder#write: 132.9
|                         files.writeFile: 74.4
|                 other ClientTarget#write: 225.3
|             ServerTarget#write: 417.7
|                 JsImage#write: 397.1
|                     Builder#write: 246.8
|                         files.writeFile: 103.2
|                     other JsImage#write: 134.4
| 
| files.writeFile: 67715.6
| files.rename: 33754.0
| linker File#computeAssignedVariables: 13210.6
| getPrelinkedFiles toStringWithSourceMap (packages): 9405.7
| other processing files with ecmascript (for target web.browser): 8695.8
| other processing files with less (for target web.browser): 4883.9
| linker File#getPrelinkedOutput: 4391.9
| other processing files with ecmascript (for target os.osx.x86_64): 2817.0
| other linker Module#getPrelinkedFiles: 1320.4
| other processing files with templating (for target web.browser): 1312.8
| other JsImage#load: 1099.8
| ClientTarget#minifyCss: 943.0
| other PackageSourceBatch#_linkJS: 724.5
| files.readFile: 511.8
| files.exists: 455.1
| other linker.fullLink: 307.0
| other ClientTarget#write: 225.3
| Isopack#getUnibuildAtArch: 137.3
| other JsImage#write: 134.4
| sha1: 123.2
| files.stat: 110.7
| other Target#_runCompilerPlugins: 107.4
| wrapped.fs.readFileSync: 85.7
| other Builder#write: 75.3
| other Target#make: 73.2
| Total: 152621.5

Yup, that's Total: 152621.5.

Note: a package we're using is installing cosmos:browserify as a dependency. We're in the process of removing that, so we'll see if that's the real culprit.

@bwhitty

This comment has been minimized.

Copy link
Contributor

@bwhitty bwhitty commented Oct 1, 2015

Can confirm that this is very slow on 1.2 on OSX Yosemite. The most egregious are when modifying client files.

Packages:

$ meteor list
blaze-html-templates      1.0.1  Compile HTML templates into reactive UI with Meteor Blaze
coresense:docker          0.0.2+
ecmascript                0.1.5  Compiler plugin that supports ES2015+ in all .js files
es5-shim                  4.1.13  Shims and polyfills to improve ECMAScript 5 support
jquery                    1.11.4  Manipulate the DOM using CSS selectors
meteor-base               1.0.1  Packages that every Meteor app needs
mobile-experience         1.0.1  Packages for a great mobile user experience
momentjs:moment           2.10.6  Moment.js (official): parse, validate, manipulate, and display dates - official Meteor packaging
mongo                     1.1.2  Adaptor for using MongoDB and Minimongo over DDP
msavin:mongol             1.2.0  The insanely handy development package for Meteor.
react                     0.1.13  Everything you need to use React with Meteor.
reactrouter:react-router  0.1.8* react-router (official): A complete routing solution for React.js
sanjo:jasmine             0.20.0  Velocity integration of the Jasmine testing framework
semantic:ui-css           2.1.2  Semantic UI - CSS Release of Semantic UI
session                   1.1.1  Session variable
standard-minifiers        1.0.1  Standard minifiers used with Meteor apps by default.
tracker                   1.0.9  Dependency tracker to allow reactive callbacks
velocity:html-reporter    0.9.0  Reactive Velocity test reports in your app.

Profiling from initial app run

=> Started proxy.
=> Started MongoDB.
|  Selecting package versions                \
| JsImage#load: 289.8
|     other JsImage#load: 289.5
| Select Package Versions: 5651.2
|     Input#loadFromCatalog (sqlite): 3718.5
|     new CS.Solver: 94.9
|         Solver#analyze: 94.7
|             analyze constraints: 73.3
|     Solver#getAnswer: 1828.9
|         generate package variables: 131.1
|         generate dependency requirements: 187.0
|         generate constraints: 373.1
|         pre-solve: 475.8
|         minimize conflicts: 269.0
|         minimize previous_root_incompat: 82.8
|         minimize total_packages: 159.9
|
| Input#loadFromCatalog (sqlite): 3718.5
| pre-solve: 475.8
| generate constraints: 373.1
| other JsImage#load: 289.5
| minimize conflicts: 269.0
| generate dependency requirements: 187.0
| minimize total_packages: 159.9
| generate package variables: 131.1
| minimize previous_root_incompat: 82.8
| analyze constraints: 73.3
| Total: 5759.9
|  Building the application                  -
| JsImage#load: 503.3
|     other JsImage#load: 502.8
| files.exists: 191.0
| Rebuild App: 8255.2
|     compiler.compile(the app): 3175.2
|         Isopack#ensurePluginsInitialized: 3131.1
|             JsImage#load: 2070.0
|                 files.exists: 593.4
|                 other JsImage#load: 1476.6
|             other Isopack#ensurePluginsInitialized: 1061.1
|     bundler.bundle..makeClientTarget: 3750.7
|         Target#make: 3750.2
|             Target#_runCompilerPlugins: 1964.3
|                 Isopack#ensurePluginsInitialized: 1870.3
|                     JsImage#load: 1865.4
|                         other JsImage#load: 1831.1
|             Target#_emitResources: 325.4
|                 PackageSourceBatch#getResources: 319.5
|                     PackageSourceBatch#_linkJS: 317.2
|                         files.readFile: 119.1
|                         other PackageSourceBatch#_linkJS: 186.8
|             ClientTarget#minifyCss: 1362.2
|     bundler.bundle..makeServerTarget: 349.3
|         Target#make: 348.9
|             Target#_runCompilerPlugins: 99.1
|                 processing files with ecmascript (for target os.osx.x86_64): 50.8
|             Target#_emitResources: 213.9
|                 PackageSourceBatch#getResources: 206.8
|                     PackageSourceBatch#_linkJS: 204.1
|                         files.readFile: 62.9
|                         other PackageSourceBatch#_linkJS: 132.7
|     bundler..writeSiteArchive: 968.1
|         bundler..writeTargetToPath: 793.0
|             ClientTarget#write: 369.5
|                 Builder#write: 95.2
|                 bundler..writeFile: 147.9
|                     Builder#write: 146.4
|                         files.writeFile: 104.9
|                 other ClientTarget#write: 120.4
|             ServerTarget#write: 419.7
|                 JsImage#write: 400.0
|                     Builder#write: 215.3
|                         files.writeFile: 88.7
|                     other JsImage#write: 144.8
|         Builder#complete: 168.2
|             files.rm_recursive: 167.9
|
| other JsImage#load: 3810.5
| ClientTarget#minifyCss: 1362.2
| other Isopack#ensurePluginsInitialized: 1066.1
| files.exists: 819.2
| other PackageSourceBatch#_linkJS: 319.5
| files.writeFile: 239.6
| files.readFile: 198.8
| files.rm_recursive: 169.1
| other JsImage#write: 144.8
| sha1: 122.0
| other ClientTarget#write: 120.4
| Isopack#getUnibuildAtArch: 84.0
| files.stat: 75.7
| other Target#_runCompilerPlugins: 63.9
| other Builder#write: 55.1
| Total: 8650.7
=> Started your app.

After modifying a client file (note, it takes ~10 seconds before the profiling output even begins)

|
| Select Package Versions: 24918.7
|     Input#loadFromCatalog (sqlite): 24762.6
|     other Select Package Versions: 128.0
|
| Input#loadFromCatalog (sqlite): 24762.6
| other Select Package Versions: 128.0
| Total: 24890.6
|
| files.writeFile: 1540.3
| files.rename: 56.8
| Rebuild App: 3523.5
|     compiler.compile(the app): 191.6
|         files.readFile: 130.0
|     bundler.bundle..makeClientTarget: 2824.1
|         Target#make: 2823.8
|             Target#_runCompilerPlugins: 394.2
|                 processing files with jsx (for target web.browser): 312.3
|                     other processing files with jsx (for target web.browser): 312.1
|             Target#_emitResources: 1057.6
|                 PackageSourceBatch#getResources: 1052.3
|                     PackageSourceBatch#_linkJS: 1049.7
|                         files.readFile: 675.6
|                         linker.fullLink: 88.1
|                             linker Module#getPrelinkedFiles: 86.9
|                         other PackageSourceBatch#_linkJS: 277.8
|             ClientTarget#minifyCss: 1305.1
|     bundler..writeTargetToPath: 500.8
|         ClientTarget#write: 498.6
|             Builder#write: 216.3
|                 files.writeFile: 131.4
|                 files.rename: 59.4
|             bundler..writeFile: 57.9
|                 Builder#write: 56.6
|                     files.writeFile: 50.5
|             other ClientTarget#write: 180.0
|
| files.writeFile: 1746.0
| ClientTarget#minifyCss: 1305.1
| files.readFile: 829.9
| other processing files with jsx (for target web.browser): 312.1
| other PackageSourceBatch#_linkJS: 277.8
| other ClientTarget#write: 180.0
| files.rename: 133.4
| sha1: 76.9
| Total: 4861.2
=> Client modified -- refreshing
@derwaldgeist

This comment has been minimized.

Copy link

@derwaldgeist derwaldgeist commented Oct 2, 2015

Some for me on Yosemite. I wish I hadn't updated to Meteor 1.2 this early. :-/

@avalanche1

This comment has been minimized.

Copy link
Author

@avalanche1 avalanche1 commented Oct 3, 2015

Remember that you can develop in previous version with
meteor --release 1.1.0.3
And also:
I've actually managed to significantly improve build time by deleting .meteor folder in User/Appdata/Local and also in my prj folder (*just don't forget to backup your db which is in prj/.meteor/local/db*) and then install fresh version of Meteor.

@derwaldgeist

This comment has been minimized.

Copy link

@derwaldgeist derwaldgeist commented Oct 3, 2015

Yep, I've already downgraded to 1.1.0.3 for now. Unfortunately, Jasmine is not working there due to another bug in the build tools. That's the main reason why I wanted to upgrade. But for now, I'm staying on 1.1.0.3 until the problems have been addressed.

@gadicc

This comment has been minimized.

Copy link
Contributor

@gadicc gadicc commented Oct 5, 2015

I noticed a massive build time difference depending on what's in private. In both cases below, I'm changing a single project file (.js) and leaving private/* untouched.

Rebuild time without private dir present: 786ms
Rebuild time with private dir present: 10,545ms (i.e. almost 15x longer)

Note, in this case the private dir is pretty big... but, why should untouched files influence rebuild time?

Rebuild App: 10545.0
|     compiler.compile(the app): 3665.3
|         files.readdir: 93.1
|         files.stat: 576.7
|         files.realpath: 170.2
|         files.readFile: 1288.6
|         sha1: 247.4
|         other compiler.compile(the app): 1287.0
|     bundler.bundle..makeClientTarget: 307.9
|         Target#make: 307.7
|             Target#_runCompilerPlugins: 77.2
|             Target#_emitResources: 163.1
|                 PackageSourceBatch#getResources: 159.5
|                     PackageSourceBatch#_linkJS: 157.5
|                         other PackageSourceBatch#_linkJS: 104.8
|     bundler.bundle..makeServerTarget: 432.8
|         Target#make: 432.6
|             Target#_runCompilerPlugins: 58.0
|             Target#_emitResources: 338.6
|                 PackageSourceBatch#getResources: 111.1
|                     PackageSourceBatch#_linkJS: 107.5
|                         other PackageSourceBatch#_linkJS: 60.7
|                 other Target#_emitResources: 227.6
|     bundler..writeSiteArchive: 6094.6
|         bundler..writeTargetToPath: 4880.7
|             ClientTarget#write: 145.5
|                 other ClientTarget#write: 52.5
|             ServerTarget#write: 4732.0
|                 JsImage#write: 4712.3
|                     files.mkdir: 64.9
|                     Builder#write: 2606.1
|                         Builder#_ensureDirectory: 180.6
|                         sha1: 149.0
|                         files.stat: 602.8
|                         files.writeFile: 725.8
|                         files.rename: 294.6
|                         other Builder#write: 653.3
|                     sha1: 503.5
|                     other JsImage#write: 1525.3
|         Builder#complete: 1201.9
|             files.rm_recursive: 1201.7
| 
| other JsImage#write: 1525.3
| files.readFile: 1376.6
| other compiler.compile(the app): 1287.0
| files.stat: 1202.9
| files.rm_recursive: 1202.8
| sha1: 940.2
| files.writeFile: 764.4
| other Builder#write: 675.6
| files.rename: 306.3
| other Target#_emitResources: 231.1
| Builder#_ensureDirectory: 183.4
| files.realpath: 170.2
| other PackageSourceBatch#_linkJS: 165.5
| files.readdir: 93.1
| Isopack#getUnibuildAtArch: 70.1
| files.mkdir: 65.8
| other Target#_runCompilerPlugins: 55.9
| other ClientTarget#write: 52.5
| Total: 10368.7

In both cases though package selection is still 2.5s - 5s :(

| Select Package Versions: 4619.8
|     Input#loadFromCatalog (sqlite): 4503.3
|     other Select Package Versions: 111.0
| Total: 4614.3

This is for the same change... i.e. no .meteor/packages or package.js or versions changes... so can't we just keep the package selection cached for these cases? (Note, I do have a lot of local packages present, but these aren't being changed...).

Running Meteor 1.2.0.2.

@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Oct 5, 2015

@gadicc this is an interesting observation. What kind of files do you have in private and what are the packages you are using?

When I was benchmarking one of the real apps, the build time was long because the private folder contained a lot of unused JSON files that were huge in size. And because there was some package that mindlessly was reading every JSON file, the build tool would "re-compile" huge JSON files without a reason.

@steph643

This comment has been minimized.

Copy link

@steph643 steph643 commented Oct 8, 2015

Note: a package we're using is installing cosmos:browserify as a dependency. We're in the process of removing that, so we'll see if that's the real culprit.

@aaronjudd, did you find who depends on cosmos:browserify? Did you succesfully remove the dependency?

@abernix

This comment has been minimized.

Copy link
Member

@abernix abernix commented Oct 8, 2015

@steph643 kadira:flow-router – which it looks like you're using – uses browserify.

@steph643

This comment has been minimized.

Copy link

@steph643 steph643 commented Oct 8, 2015

Yes, and manually updating to the latest version of browserify doesn't improve rebuild time.

@gadicc

This comment has been minimized.

Copy link
Contributor

@gadicc gadicc commented Oct 8, 2015

Re: (unchanged) contents of private/ affecting rebuild time

@Slava:

What kind of files do you have in private and what are the packages you are using?

No packages beyond the defaults from meteor create. It seems all file types affect it, but that big unhandled files are worse (unless there's a .txt handler I'm unaware of).

Each build contains 500 files in "site/private".
"Small" build files contain 1 line each.
"Big" build files contain 500 lines each.
To trigger the rebuild, a single file is modified in the APP.

Results (for "rebuild" step):

*    js-small: 3897.7 ms
*      js-big: 3969.7 ms
*   css-small: 3342.9 ms
*     css-big: 3467.4 ms
*   txt-small: 3586.6 ms
*     txt-big: 7445.6 ms

Repro and full logs: https://github.com/gadicc/meteor-private-bench

Note: I never actually checked if this was an issue pre 1.2, or checked the public dir (or tests which really shouldn't have any affect).

(And yeah, untamed packages can do some crazy things sometimes :)).

@abernix

This comment has been minimized.

Copy link
Member

@abernix abernix commented Oct 8, 2015

Btw, I have seen a noticeable increase in 1.2 as well – roughly guessing: Twice as slow, but I didn't know of the METEOR_PROFILE before, so I've run these tests now.

Lots of files in this project (290 .js, 160 .html, 23 .less – all the same as before 1.2, plus whatever the packages we use have in them), but on OS X, with a higher-than-average kern.maxfiles, and on what I consider to be a pretty fast Mac, I think it's still sluggish, and definitely slower than before.

Intial Startup File Change
1.1.0.3 3873.0 2054.6
1.2.0.2 9811.3 (153% greater) 3693.1 (80% greater)

Notes

  • /private is empty.
  • I am running Velocity tests (three mirrors), but they were enabled across all those tests so they're all fair comparisons. (The times are about 30% lower with Velocity off completely.)
  • The "File Change" test is changing a single js file in the main app.

Here are the outputs from my METEOR_PROFILE=50 both before and after 1.2, but I've shortened them up a lot to not flood this issue with long copy-pastas. I've left the larger numbers, and I've linked to the full outputs (here's the complete file).

Meteor 1.1.0.3

Initial Startup

full output

| Select Package Versions: 2634.9
| Input#loadFromCatalog (sqlite): 1030.5
| Total: 3047.4                         
| Rebuild App: 3580.0
|     bundler.bundle..makeClientTarget: 1179.0
|                 other ClientTarget#mergeCss: 904.6
|         bundler..writeTargetToPath: 348.5
|     other Rebuild App: 694.8
| other JsImage#load: 1155.9
| other ClientTarget#mergeCss: 904.6
| other Rebuild App: 694.8
| Total: 3873.0

On File Change

full output

| Select Package Versions: 1996.8
|     Input#loadFromCatalog (sqlite): 977.9
|     Solver#getAnswer: 936.5
| Rebuild App: 2054.2
|     bundler.bundle..makeClientTarget: 1199.9
|         Target#make: 1199.8
|             ClientTarget#mergeCss: 1044.3
|     bundler..writeTargetToPath: 246.2
|     other Rebuild App: 510.0
| ClientTarget#mergeCss: 1044.3
| other Rebuild App: 510.0
| other Unibuild#getResources: 108.9
| Total: 2054.6

Meteor 1.2.0.2

Initial Startup

full output

| Select Package Versions: 4164.6
|     Input#loadFromCatalog (sqlite): 2211.2
| Rebuild App: 9504.4
|     bundler.bundle..makeClientTarget: 4841.3
|     bundler.bundle..makeServerTarget: 2010.3
|     bundler..writeSiteArchive: 1398.8
| files.readFile: 3378.0
| other JsImage#load: 2134.6
| ClientTarget#minifyCss: 976.3
| Total: 9811.3

On File Change

full output

| Select Package Versions: 3818.8
|     Input#loadFromCatalog (sqlite): 3739.5
| files.writeFile: 1099.0
| Rebuild App: 2751.5
|     bundler.bundle..makeClientTarget: 2398.9
| files.writeFile: 1100.2
| ClientTarget#minifyCss: 870.0
| files.readFile: 442.1
| Total: 3693.1

So yea, whether it's a package doing something or not, it's definitely doing it slower in 1.2.
... for what it's all worth. 😸

Hope this helps.

@oliverlloyd

This comment has been minimized.

Copy link

@oliverlloyd oliverlloyd commented Oct 19, 2015

I've noticed that the problem is it's not entirely related to things being slower, but that it also slows down over time. If I stop and restart the meteor process things are markedly better.

Look at this CPU graph where I am repeatedly making small changes to trigger a build.
screen shot 2015-10-19 at 17 40 29
This graph shows 6 builds where the long plateaus are meteor building and the spikes at the end of each plateaux are chrome reloading things. Notice how the last two plateaus are much shorter? These were performed after a hard restart of meteor. The ones before that are after a day's worth of development and average about 34 seconds but after I restarted things that time dropped to about 12 seconds.

OSX v10.10.4 Meteor 1.2.0.2

@benweissmann

This comment has been minimized.

Copy link
Contributor

@benweissmann benweissmann commented Oct 19, 2015

I'm also seeing slow builds after upgrading to Meteor 1.2. I'm working on a large project that uses ~50 local packages and a number of external packages.

Here's my profiling output from making a small change to a client-side template and my .meteor/versions: https://gist.github.com/benweissmann/576b1453de226c33a10f

I'm running inside Vagrant. The guest machine is ubuntu 14.04; the host is OSX 10.10. Files are shared via NFS with cachefilesd running inside Vagrant.

@dotnetwise

This comment has been minimized.

Copy link

@dotnetwise dotnetwise commented Oct 26, 2015

Bummer! This hangs for us as well with approx same extra duration :(

Anyone from MDG already looking into this?

@rdewolff

This comment has been minimized.

Copy link

@rdewolff rdewolff commented Nov 13, 2015

Am having issues with this as well.

@bmustata

This comment has been minimized.

Copy link

@bmustata bmustata commented Nov 13, 2015

+1

@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Dec 1, 2015

For those of you on Windows, please try disabling your antivirus software and see if this helps to speed up anything. Posting this per #5691.

Also, to figure out if this is a problem on your OS/Hardware configuration or project, you can try cloning https://github.com/wekan/wekan which is fast on refreshes (per mquandalle). If that project is slow to rebuild on your machine, it could be something specific to your setup that we missed.

@mquandalle

This comment has been minimized.

Copy link
Contributor

@mquandalle mquandalle commented Dec 18, 2015

Well after all, Wekan isn’t that fast to refresh on my computer (I thought so because I have automatized the process of writing relatively large bunches of code, save all files at once, and wait a few seconds before looking at the browser). My complete reload time results are here and at first glance they are consistent with what other have observed.

@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Dec 21, 2015

@mquandalle I worked on more profiling on Wekan specifically, and I noticed that a big chunk of recomputation is spent on styl and i18n.json files. Those use old-style build plugins w/o caching:

|             legacyHandler i18n.json: 938.5
|                 sha1: 1.2
|                 other legacyHandler i18n.json: 937.3
|             legacyHandler styl: 5908.1

Update: this is like 45% of build time spent on a client-side file update on my machine

@markshust

This comment has been minimized.

Copy link

@markshust markshust commented Dec 21, 2015

Hmm, I have stylus plugin loaded also. Rebuild times keep growing perpetually until I need to restart server. There is a leak someplace.

@oliverlloyd

This comment has been minimized.

Copy link

@oliverlloyd oliverlloyd commented Dec 21, 2015

Perpetual growth over time is definitely the trend for us. A little more worryingly, I've started to notice the meteor node process hang at 100% cpu - properly hang, as in for 5 mins plus - while rebuilding requiring a kill -9 to get things running again. Happy to post more info as required, just ask.

@Slava

This comment has been minimized.

Copy link
Member

@Slava Slava commented Dec 21, 2015

Looking at Wekan, here are the things that stood out to me changing client-side file (running from checkout sha 482111f):

  • on every rebuild Meteor queries SQL to re-read the catalog (unnecessary, the merged patch a576bda didn't seem to improve anything here) - 4 seconds
  • Wekan uses custom stylus plugin (no caching) - 6 seconds
  • Wekan compiles translations even if they don't change (no caching) - 1 second
  • Wekan uses the jade plugin that is suspiciously taking a lot of time to compile one file (I suspect the caching is done incorrectly) - 1.3 seconds to process one file
  • sadly, due to how Meteor's build system is written, sourcemaps for every file are stringified on every run, and it takes extra 2 seconds
@mquandalle

This comment has been minimized.

Copy link
Contributor

@mquandalle mquandalle commented Dec 21, 2015

Didn’t realize the raw numbers of time spent the on legacy compiler API! I will work on that (and I have a pretty good incentive to do it quickly :-)).

@mquandalle

This comment has been minimized.

Copy link
Contributor

@mquandalle mquandalle commented Dec 21, 2015

Oh I guess the compileOneFile method here should return the actual file to be cached? (!)

@derwaldgeist

This comment has been minimized.

Copy link

@derwaldgeist derwaldgeist commented Dec 21, 2015

I've started to notice the meteor node process hang at 100% cpu - properly hang, as in for 5 mins plus - while rebuilding requiring a kill -9 to get things running again

+1 Can confirm this problem, having this once in a while. It usually happens if I do code changes in quick succession. Seems as if Meteor gets a hiccup then. Won't react on ^C any more, only killing the process helps.

mquandalle added a commit to wekan/wekan that referenced this issue Dec 26, 2015
Following a valuable comment from @Slava [0], this commit improves the
build and the reload time of Wekan. It does so by implementing the
following changes:

* Upgrade the meteor build tool to a version which includes a fix to
  an issue with the caching of the dependency resolution [1]. This fix
  will be included in Meteor 1.3, so we won't have to use a
  "special release" anymore;
* Change the stylus package from `mquandalle:stylus` to `stylus` as we
  don't use the libraries included with my (mquandalle) version like
  Jeet or Rupture, and the core package implement the new meteor build
  plugin API with caching. The generated CSS file is slighly different
  mostly mostly because we miss some autoprefixed values but even
  until meteor-core figure out a good way to configure CSS
  autoprefixing, the benefits (better compile time) outweights the
  cons. For record I attached a diff in the generated style [2];
* Upgrade `mquandalle:jade` to a version that implements the build
  plugin caching correctly.

These 3 changes decrease the reload time of about 50% on my computer.

[0]: meteor/meteor#5269 (comment)
[1]: meteor/meteor#5747
[2]: https://gist.github.com/mquandalle/e95198626767b56fc63a
@abernix

This comment has been minimized.

Copy link
Member

@abernix abernix commented Nov 1, 2016

I'm going to close this relatively old issue. I don't believe this issue is providing any value any more as it is as most conversation on this topic takes place in other issues now. Build times were a major focus on Meteor 1.4.2 and I believe they have improved in that release. I'm closing this in favor of the newer issues with more relevant reproductions and current use-cases.

@abernix abernix closed this Nov 1, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
You can’t perform that action at this time.