pkgx: tea --magic is slow 🐢 when run in shell startup

tea --magic adds about 100ms of extra latency to my shell startup, which is a lot to me c:

❯ hyperfine --warmup=3 "~/.tea/tea.xyz/v0.21.0/bin/tea --magic"
Benchmark 1: ~/.tea/tea.xyz/v0.21.0/bin/tea --magic
  Time (mean ± σ):     157.7 ms ±  60.6 ms    [User: 97.5 ms, System: 22.9 ms]
  Range (min … max):   103.6 ms … 345.7 ms    25 runs

If I may give my 2¢, while I’m as big a Deno lover as the next guy it’s just not suitable for the sub-100ms startup times maniacs like myself crave for our terminal.

As a best-case scenario I measured the fastest possible time the magic could run

#!/usr/bin/env deno run
// magic.ts
console.log(`add-zsh-hook -Uz chpwd() {
  if [ "\${TEA_MAGIC:-}" != 0 -a -x "/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea ]; then
    source <("/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea +tea.xyz/magic -Esk --chaste env)
  fi
}

# if the user put tea in eg. /usr/local/bin then don’t pollute their PATH
if ! tea --prefix 2>&1 >/dev/null; then
  export PATH="/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin:$PATH"
fi

function command_not_found_handler {
  if [ "\${TEA_MAGIC:-}" != 0 -a -x "/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea ]; then
    "/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea -- $*
  fi
}
`)

❯ hyperfine --warmup=3 ./magic.ts
Benchmark 1: ./magic.ts
  Time (mean ± σ):      63.6 ms ±   7.6 ms    [User: 37.2 ms, System: 17.8 ms]
  Range (min … max):    57.3 ms …  88.6 ms    40 runs

compared to something like

package main
// magic.go

import "fmt"

func main() {
	fmt.Println(
		`add-zsh-hook -Uz chpwd() {
  if [ "${TEA_MAGIC:-}" != 0 -a -x "/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea ]; then
    source <("/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea +tea.xyz/magic -Esk --chaste env)
  fi
}

# if the user put tea in eg. /usr/local/bin then don’t pollute their PATH
if ! tea --prefix 2>&1 >/dev/null; then
  export PATH="/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin:$PATH" fi

function command_not_found_handler {
  if [ "${TEA_MAGIC:-}" != 0 -a -x "/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea ]; then
    "/Users/m0c0j7y/.tea/tea.xyz/v0.21.0/bin"/tea -- $*
  fi
}`)
}

❯ hyperfine --warmup=3 ./magic
Benchmark 1: ./magic
  Time (mean ± σ):      10.5 ms ±   9.2 ms    [User: 1.5 ms, System: 3.0 ms]
  Range (min … max):     0.0 ms …  36.9 ms    160 runs

  Warning: Command took less than 5 ms to complete. Note that the results might be inaccurate because hyperfine can not calibrate the shell startup time much more precise than this limit. You can try to use the `-N`/`--shell=none` option to disable the shell completely.

The difference is even starker when run “e2e”

About this issue

Original URL
State: closed
Created a year ago
Reactions: 1
Comments: 21 (21 by maintainers)

Most upvoted comments

Yeah 100ms is not acceptable for sure. Once we are 1.0.0 I plan to rewrite in Rust. But until then deno is much faster for dev.

Having said this, I’m surprised it is this much since --magic is a pretty hot path.

I can see a few quick fixes, make tea a shell script that handles some of the options fast and then delegates the rest. Unfortunately shell magic involves calling tea so that is every cd. Possibly we could cache that though.

I’ll give it some thought. Thanks for the (very) detailed report!

mxcl on Jan 25, 2023

$ hyperfine --warmup 3 "./compiled-single-console-log"
Benchmark 1: ../brewkit/foo
  Time (mean ± σ):      12.4 ms ±   0.6 ms    [User: 9.4 ms, System: 2.6 ms]
  Range (min … max):    11.7 ms …  15.0 ms    206 runs
  
$ hyperfine "./compiled-tea-exit-after-imports"
Benchmark 1: ./tea
  Time (mean ± σ):      23.6 ms ±   0.6 ms    [User: 19.4 ms, System: 3.4 ms]
  Range (min … max):    22.8 ms …  26.5 ms    111 runs

$ hyperfine --warmup 3 "tea --magic"
Benchmark 1: tea --magic
  Time (mean ± σ):      36.6 ms ±   0.3 ms    [User: 32.8 ms, System: 4.1 ms]
  Range (min … max):    36.1 ms …  38.0 ms    76 runs

$ hyperfine --warmup 3 "tea -E"
Benchmark 1: tea -E
  Time (mean ± σ):      43.9 ms ±   0.5 ms    [User: 41.9 ms, System: 5.3 ms]
  Range (min … max):    43.1 ms …  46.8 ms    64 runs

So parsing our imports seems to be ~11ms.
Then our argument parsing logic seems to be ~13ms (this is bad)
Then parsing a dev-env is 7ms

The last one would be what I’d expect to be the most taxing but it isn’t.

Thoughts

We have a fairly minimal set of imports, but perhaps we can do some pruning
The code that runs between imports and evaluating --magic (which is just a long console.log) should really not take so long
The dev-env parsing will always take compute but an sqlite cache for the pantry would probs make it much faster

mxcl on Jul 31, 2023

That’s good news. If we can get startup down 50% - 80% then a rewrite in rust may never be necessary.

mxcl on Feb 3, 2023

deno compile should transpile and vendor the code (internally) by itself. I’m a little surprised that such a simple import adds so much delay? Could you share a benchmark or a reproc for this?

sure thing. I’ll set something up.

mxcl on Aug 1, 2023

pure rust is a slight improvement:

$ hyperfine --warmup=3 "tea --magic" 
Benchmark 1: tea --magic
  Time (mean ± σ):      47.5 ms ±   1.3 ms    [User: 43.3 ms, System: 3.4 ms]
  Range (min … max):    46.2 ms …  53.8 ms    60 runs
 
$ hyperfine --warmup=3 "./tea-magic zsh"
Benchmark 1: ./tea-magic zsh
  Time (mean ± σ):       0.6 ms ±   0.5 ms    [User: 0.3 ms, System: 0.2 ms]
  Range (min … max):     0.2 ms …   9.4 ms    1084 runs
 
  Warning: Command took less than 5 ms to complete. Note that the results might be inaccurate because hyperfine can not calibrate the shell startup time much more precise than this limit. You can try to use the `-N`/`--shell=none` option to disable the shell completely.
  Warning: Statistical outliers were detected. Consider re-running this benchmark on a quiet PC without any interferences from other programs. It might help to use the '--warmup' or '--prepare' options.

jhheider on Feb 4, 2023

Deno recently merged a PR to allow for snapshotting of ES modules (https://github.com/denoland/deno/pull/17460). When/if this gets extended for use in deno compile, we should see a pretty hefty perf improvement. In my (rather limited) understanding, it essentially converts typescript from a JIT language to a compiled language by doing the compile step ahead of time.

While this obviously will not “solve” the problem of typescript being slower than rust, it should alleviate a lot of the pain for users in the mean-time.

lino-levan on Jan 29, 2023