Keystone-classic: Keystone is crazy slow to start

Created on 12 May 2016  Β·  35Comments  Β·  Source: keystonejs/keystone-classic

This is an umbrella issue to track startup performance. It should be possible to get startup perf <100ms because there just isn't that much code!

console.time('keystone');
var keystone = require('keystone');
console.timeEnd('keystone');
$ node server.js 
keystone: 3297.995ms
bug critical

Most helpful comment

Without knowledge of keystone's internals, some obvious candidates for lazy / optional module loading:

  • lib/email (670ms)
  • browserify (612ms). The keystone admin UI javascript should be compiled in an npm postinstall script.

Alone those two changes would decrease startup time by >50% (to about 1 second on my mba).

All 35 comments

Perf at the top level (I've elided everything <20ms).

sephsmac:keyplay josephg$ node server.js 
  ┣ keystone (2412ms)
  β”— []
    ┣ lodash (78ms)
    ┣ express (113ms)
    ┣ grappling-hook (46ms)
    ┣ keystone-utils (22ms)
    ┣ ./lib/core/render (303ms)
    ┣ []
    ┃ β”— jade (302ms)
    ┣ mongoose (281ms)
    ┣ ./admin/server (725ms)
    ┣ []
    ┃ ┣ ./app/createDynamicRouter (57ms)
    ┃ ┣ []
    ┃ ┃ β”— multer (56ms)
    ┃ ┣ ./app/createStaticRouter (668ms)
    ┃ β”— []
    ┃   ┣ ../middleware/browserify (612ms)
    ┃   ┣ []
    ┃   ┃ ┣ babelify (357ms)
    ┃   ┃ ┣ browserify (136ms)
    ┃   ┃ ┣ fs-extra (29ms)
    ┃   ┃ ┣ moment (22ms)
    ┃   ┃ β”— watchify (68ms)
    ┃   β”— less-middleware (55ms)
    ┣ ./lib/email (670ms)
    ┣ []
    ┃ ┣ mailgun-js (342ms)
    ┃ β”— juice (319ms)
    β”— ./fields/types/Type (117ms)

Generated with this code, then putting this at the top of heavy JS files (before the require calls):

require = wr(require);

Without knowledge of keystone's internals, some obvious candidates for lazy / optional module loading:

  • lib/email (670ms)
  • browserify (612ms). The keystone admin UI javascript should be compiled in an npm postinstall script.

Alone those two changes would decrease startup time by >50% (to about 1 second on my mba).

Also interesting: My production app (as opposed to my sample project) also has this line: ../../client/utils/packages (4196ms)

... As part of the server's static router. As far as I can tell this should all go away if we run browserify during npm install, not server startup.

No idea why this shows up on one project but not another.

Afaik Browserify runs at startup because we want to bundle a users custom fields in. (/cc @JedWatson who might have a comment about this)

@mxstbr If the bundle is dependant on the which fields are actually used, that begs the question of why all the default fields get bundled in every time regardless. But there's a bunch of better ways of solving that problem; the simplest being just bundling the user's fields into another JS file. (We're already loading 8 JS bundles or something in the admin UI anyway.. :/ )

I'm the maintainer on Juice, I've never really looked at startup time on it before. If you have any suggestions, let me know. I'll open an issue over on that repo for investigation if startup is consistently that slow.

@jrit We have to go deeper:

      ┃  ┣ juice (414ms)
      ┃  β”— []
      ┃     ┣ ./lib/utils (143ms)
      ┃     ┣ []
      ┃     ┃  β”— cheerio (124ms)
      ┃     β”— web-resource-inliner (269ms)

I don't know anything about juice or those libraries. If one (or both) is optional, it might be worth lazy-loading them.

There's a pretty high timing variance between runs (sometimes its 250ms). YMMV.

(So to read that, almost all the time spent loading juice is spent in turn in juice's dependancies.)

I've just deferred loading browserify and babelify until the first Admin UI script; that drops the startup time down another half a second on my machine. Getting there.

I should be able to trim at least 30% off of Juice, still working on it. When I eventually get to a release I'll open a PR to Keystone.

Awesome - looking forward to it!

I'd like to +1 on this. I'm on a 2011 macbook pro, and am having 1.5 minute startup times. Sucks to work on things!!!

@askdesigners have you tried using the master branch directly, rather than 0.3.x from npm? I've done a _lot_ of work on it to speed up the startup, it's a lot faster for me but I'm on a fully spec'd 2015 macbook pro so I'm really interested to know how it is for you.

@josephg I would like to make the browserify go away by creating a bundle offline, but it will need to be with Webpack and https://github.com/webpack/react-proxy-loader so that only the fields you use get downloaded. The wysiwyg editor is pretty heavy.

Totally off-topic: @askdesigners do you have a HDD? The best upgrade you can give your system is an SSD…

@wmertens πŸ‘ Sounds great. Ideally I'd like to build that bundle in an npm prepublish script and then we can remove the dependancies on webpack / etc from keystone itself.

This might not work, see e.g. #3035. (haven't 100% thought this through though, so might be wrong)

@wmertens @josephg a lot of the time spent here is actually babel, not browserify. Not to detract from the fact that I'd like to switch over to webpack, if we were to pre-transpile the fields and Admin UI it would:

  • make npm install lighter, babel and friends would move to devDependencies
  • reduce the standard keystone install size
  • make startup time faster
  • reduce memory usage
  • make the Admin UI load much faster on first use

... which is a lot of win, and a much easier target.

When we get 0.4 published to npm, we can use prepublish to do the build, and if you're running linked from a git checkout we can have an npm script that does the build (including watchify for dev)

Until then though, when testing the alpha with your package.json pointed at git, to continue supporting that we'd need to have transpiled versions in our main repo, which is sucky. I'm not sure it's _more_ sucky than our current startup times, but it'll introduce a lot of churn (we currently do this in the sense that I pre-build _all_ our common packages and check that in when they're updated in keystone's package.json, but that happens a lot less frequently than keystone's Admin UI is updated)

Basically this is a trade-off between speed to boot and "it works like you expect, first time, every time".

Thoughts?

I also keep wanting to try server hot reloading: https://github.com/ericclemmons/webpack-hot-server-example

So when you change your API calls, they are replaced instead of the server restarted.

Then, since you're building your server with Webpack anyway, you can use ES2015, even for node 0.12, and give a minified build to node to improve startup speed slightly.

For the git checkouts, keystone could be the webpack hot reload version, and the npm versions are the built ones.

Oh, there's also https://www.npmjs.com/package/postinstall-build obviating the need for checked-in builds for git installs.

@mxstbr that #3035 issue will in fact be helped by a pure-data-schema driven UI approach, since all you need to do is amend the schema and the admin UI would follow suit.

@josephg so in the webpackify branch, the prebuilding is done. Since it is on latest master, email is also out of it.

Would be cool if you could run your test again πŸ˜€

You don't need me to re-run the test @wmertens! Fire it up

Without knowledge of keystone's internals, some obvious candidates for lazy / optional module loading: lib/email (670ms)

lib/email is not a thing anymore, we now use the external keystone-email module which is only used if the user has it installed! Should make startup _a lot_ faster.

@josephg @mxstbr much nicer :)

$ node time.js
  ┣ keystone (958ms)
  β”— []
    ┣ lodash (72ms)
    ┣ express (112ms)
    ┣ grappling-hook (36ms)
    ┣ keystone-utils (23ms)
    ┣ ./lib/core/initExpressSession (24ms)
    ┣ mongoose (283ms)
    ┣ ./admin/server (156ms)
    ┣ ./fields/types/Type (107ms)
    β”— ./lib/storage (50ms)
$ KEYSTONE_BUILD=prod node time.js 
  ┣ keystone (910ms)
  β”— []
    ┣ lodash (65ms)
    ┣ express (101ms)
    ┣ grappling-hook (34ms)
    ┣ mongoose (225ms)
    ┣ ./admin/server (196ms)
    ┣ ./fields/types/Type (103ms)
    β”— ./lib/storage (51ms)

Since webpack is loaded only once keystone is started, that doesn't impact this startup…

Problem:
Loading the Admin UI for the first time (after the server restarts) takes way too long (1min), and unfortunately slows down my productivity a lot.

Cause:
fields.js and admin.js take > 1 min to be generated

Proof:
Proof

Details:
Lately, more than ever, this is something I have been struggling with.
I don't want to be picky about it because having an auto-generated admin UI, even if slowly generated at first, is far better than not having one and it's the first reason for me to use KeystoneJS.
But unfortunately, since I'me developing my biggest project so far, I have to take a lot of consideration into how the Admin UI displays the data and enables any user to manage it = which translates in restarting the server all the time and checking the changes.

Is it something I'm doing wrong?
Any tips on how to decrease this, or is it already fixed and it's waiting for a PR?
I suppose it has to do with reading all the Models structure and translating to React.js components/etc (I have no experience with reactjs yet).

@ghuroo I have a PoC up at https://github.com/keystonejs/keystone/pull/3842 that handles some of this issues. The very first run will still be slow, but after that it will write the files to disk and serve them from your public folder so it doesn't have to rebuild them on every boot.

It's still a WIP though I'm hoping to get it into good enough shape in the next week or so. Would that solve your problem here?

@bassjacob I appreciate a lot your effort. Can you provide it? Currently I am working heavily on Models / Admin UI and that would save me a lot of time and patience :p

it should be enabled in 4.0.0-beta-5, so if you upgrade your keystone 4 app it should just work out of the box (it's enabled by default). The first time you build it will still be slow, but it should cache the build between server restarts after that.

@bassjacob There is/was a prebuildAdminUI or similar environment variable that could be set at some point which would build the admin UI at server start rather than at first page view correct?

Does this still exist, and if so does it play nicely with your changes? I.e. does it bundle the admin ui to disk at startup rather than on first page view when enabled?

It wasn't a part of the task I undertook, but if it used https://github.com/keystonejs/keystone/blob/5cf3e6a534165f79faf644bbd886615b92b93681/admin/server/middleware/browserify.js to generate the files then it should work as you describe.

@bassjacob thank you :) already upgraded to beta 5. to make sure this is the supposed behaviour: it caches and loads the files from disk IF you didn't change your Models, right?

Because if not, it's still building the fields.js and admin.js (taking 1.6 min).

Still, it surely helps a lot :) there's no rebuild of those two .js when the Models stay intact.

@bassjacob I just want to let you know that the merge in beta5 has made development so much faster :) even when some Models change (schema virtuals, etc.), restarting and loading the admin ui is now a breeze.

Damn it feels good :man_dancing:

That's great news :smile: There are some more improvements coming down the line, and if you have any ideas on where things can be made better please post them here :+1:

I think we're safe to close this, now we've hit dancing man status πŸ˜„

Seriously, we've done heaps to improve the startup and first response time of Keystone and will continue to do this. It's a core focus. I also think closing issues when we've made major progress is good for the soul.

Thanks to everyone who helped push this forward, including @josephg for bring it front and centre sooner than I was planning to start chipping away at it as aggressively as we have!

image

I am very sorry guys I read almost everything here but I still don't get why fields.js and admin.js takes 21 seconds to load, what am I doing wrong? can someone please explain to me simply what should I do to fix it?

Thanks a lot

I'm pretty sure it's being compiled at runtime. It only happens the first
time you hit the app after a server restart though. Subsequent page loads
should be much faster.

Ryan Cole, Ask designers


-
Vlastina 11 l 161 00 Prague 6 l Czech Republic


-
[email protected] l www.askdesigners.eu


-
CZ tel + 420 725 649 938 l skype: askdesigners


-

On Tue, May 15, 2018 at 6:11 AM, alielkhateeb notifications@github.com
wrote:

[image: image]
https://user-images.githubusercontent.com/20101678/40036240-dd322640-5838-11e8-95e1-c34b9e2c17ef.png

I am very sorry guys I read almost everything here but I still don't get
why fields.js and admin.js takes 21 seconds to load, what am I doing wrong?
can someone please explain to me simply what should I do to fix it?

Thanks a lot

β€”
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/keystonejs/keystone/issues/2824#issuecomment-389036980,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACwewb-vTF25ArEgKoryXsUnOU4pSiqgks5tylVtgaJpZM4IcnR8
.

Was this page helpful?
0 / 5 - 0 ratings