Slow start time

[trungdq88]

Prettier reported "45ms" to pretty a file, but actually take ~420ms (on my machine) to complete the whole process (reported by time prettier --write app.js).

This may not be a problem when we manually use it in terminals, but can cause plugins like https://github.com/prettier/vim-prettier to have a significant delay for every save action.

Is there something we can do about it? Thanks.

[azz]

We should do some more precise timings to see what's eating that time.

Also, maybe check out https://github.com/josephfrazier/prettier_d?

[mitermayer]

I will see if I can find sometime to look on what is eating all this time within prettier

[karl]

There was some ineteresting discussions on startup time and performance last year:

#443

Not sure how relevant it is here, but could be interesting reading.

[fisker]

Is v8-compile-cache useful?

[j-f1]

It looks to be about half Node overhead and half Prettier overhead:

$ time prettier --version
2.0.5

________________________________________________________
Executed in  534.13 millis    fish           external 
   usr time  301.51 millis  109.00 micros  301.40 millis 
   sys time  337.69 millis  784.00 micros  336.91 millis 

$ time node -p '"2.0.5"'
2.0.5

________________________________________________________
Executed in  231.63 millis    fish           external 
   usr time  107.89 millis   98.00 micros  107.79 millis 
   sys time  165.88 millis  768.00 micros  165.11 millis 

[wchargin]

It looks to be about half Node overhead and half Prettier overhead:

On my machine, Prettier is ~16 times slower than Node startup:

$ hyperfine 'node ./node_modules/.bin/prettier --version' 'node -p "\"2.4.1\""'

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
node ./node_modules/.bin/prettier --version	616.0 ± 10.3	601.1	636.8	15.90 ± 0.74
node -p "\"2.4.1\""	38.7 ± 1.7	36.4	43.4	1.00

This adds substantial friction to a Prettier-on-save hook.

(Prettier 2.4.1 on Node v16.13.0 on Linux Mint 20.1 (like Ubuntu 20.04)
on a ThinkPad T440s (Intel i5-4300U).)

[stefan-toubia]

I wanted to understand why prettier startup time is so darn slow so I took a closer look. It appears that the vast majority of the startup time is spent initializing the parsers.

Here's the index.js build file. It appears that webpack is turning these requires into vars. So all parsers are always being loaded, even if they're never used.

var require$$0$2 = require("./parser-babel.js");

var require$$1$1 = require("./parser-flow.js");

var require$$2$1 = require("./parser-typescript.js");

var require$$3$1 = require("./parser-angular.js");

var require$$4$6 = require("./parser-espree.js");

var require$$5$3 = require("./parser-meriyah.js");

This is used in parsers.js.

prettier/src/language-js/parse/parsers.js

Lines 3 to 13 in 894f841

	module.exports = {
	// JS - Babel
	get babel() {
	return require("./babel.js").parsers.babel;
	},
	get "babel-flow"() {
	return require("./babel.js").parsers["babel-flow"];
	},
	get "babel-ts"() {
	return require("./babel.js").parsers["babel-ts"];
	},

I did a quick test to try loading dynamically:

console.timeLog("index.js", "Load parsers start");

var require$$0$2 = () => require("./parser-babel.js");

var require$$1$1 = () => require("./parser-flow.js");

var require$$2$1 = () => require("./parser-typescript.js");

var require$$3$1 = () => require("./parser-angular.js");

var require$$4$6 = () => require("./parser-espree.js");

var require$$5$3 = () => require("./parser-meriyah.js");

console.timeLog("index.js", "End load parsers");

var parsers$d = {
  // JS - Babel
  get babel() {
    return require$$0$2().parsers.babel;
  },

  get "babel-flow"() {
    return require$$0$2().parsers["babel-flow"];
  },

  get "babel-ts"() {
    return require$$0$2().parsers["babel-ts"];
  },

before:

$ time prettier -v
index.js: 37.526ms Load parsers start
index.js: 387.069ms End load parsers
2.5.1
prettier -v  0.54s user 0.08s system 105% cpu 0.591 total

after:

$ time prettier -v
index.js: 39.605ms Load parsers start
index.js: 42.479ms End load parsers
2.5.1
prettier -v  0.18s user 0.11s system 64% cpu 0.457 total

My assumption is this is webpack's doing, but I'm not familiar with the rest of the build tooling being used here so don't quote me on that. Hopefully somebody more familiar could chime in whether this is easy to solve? I have a similar issue where I'd like to use prettier as a pre-commit hook, but am not very satisfied with the slow startup time.

[fisker]

@stefan-toubia Check #12261

[stefan-toubia]

Oh, thanks @fisker! That's definitely much better.

$ time ./dist/bin-prettier.js -v
2.6.0-dev
./dist/bin-prettier.js -v  0.18s user 0.03s system 92% cpu 0.230 total

[Ddystopia]

> time prettier --version
2.5.1

CPU	105%
total	0.865
user	0.855
system	0.060

[charlespwd]

I ran a profile with --inspect-brk on my plugin because I thought I was the culprit. parser-flow and parser-typescript account for 200ms of load time.

I only had the time to briefly look into this, but lazy loading those in node_modules/prettier/index.js was enough to slash that boot time in two.

const lazy = (fn) => {
  let cache = null
  return () => {
    if (!cache) cache = fn();
    return cache;
  }
}

var require$$0$2 = lazy(() => require("./parser-babel.js"));

var require$$1$1 = lazy(() => require("./parser-flow.js"));

var require$$2$1 = lazy(() => require("./parser-typescript.js"));

var require$$3$1 = lazy(() => require("./parser-angular.js"));

var require$$4$6 = lazy(() => require("./parser-espree.js"));

var require$$5$3 = lazy(() => require("./parser-meriyah.js"));

var parsers$d = {
  // JS - Babel
  get babel() {
    return require$$0$2().parsers.babel;
  },

  get "babel-flow"() {
    return require$$0$2().parsers["babel-flow"];
  },

  get "babel-ts"() {
    return require$$0$2().parsers["babel-ts"];
  },

  get json() {
    return require$$0$2().parsers.json;
  },

  get json5() {
    return require$$0$2().parsers.json5;
  },

  get "json-stringify"() {
    return require$$0$2().parsers["json-stringify"];
  },

  get __js_expression() {
    return require$$0$2().parsers.__js_expression;
  },

  get __vue_expression() {
    return require$$0$2().parsers.__vue_expression;
  },

  get __vue_event_binding() {
    return require$$0$2().parsers.__vue_event_binding;
  },

  // JS - Flow
  get flow() {
    return require$$1$1().parsers.flow;
  },

  // JS - TypeScript
  get typescript() {
    return require$$2$1().parsers.typescript;
  },

  // JS - Angular Action
  get __ng_action() {
    return require$$3$1().parsers.__ng_action;
  },

  // JS - Angular Binding
  get __ng_binding() {
    return require$$3$1().parsers.__ng_binding;
  },

  // JS - Angular Interpolation
  get __ng_interpolation() {
    return require$$3$1().parsers.__ng_interpolation;
  },

  // JS - Angular Directive
  get __ng_directive() {
    return require$$3$1().parsers.__ng_directive;
  },

  // JS - espree
  get espree() {
    return require$$4$6().parsers.espree;
  },

  // JS - meriyah
  get meriyah() {
    return require$$5$3().parsers.meriyah;
  },

  // JS - Babel Estree
  get __babel_estree() {
    return require$$0$2().parsers.__babel_estree;
  }

};

And this is what I got:

The 400ms boot turned into 220ms. If someone can look into the build step and lazy load those we'd double the speed of a every cold boot.