Slow prompt refresh

[shlajin]

Whenever I hit enter it takes ~400ms for the prompt to render. This is different from this issue #2961 that refers to the shell startup speed, as I'm referring specifically to prompt refresh inside the session.

I'm not sure at which point this started to happen – I installed quite a bunch of things in my shell and I always thought it's one of those new tools... apparently it's not.

I removed everything from my .zshrc and left only

eval "$($HOME/.local/bin/mise activate zsh)"

export MISE_TRACE=1 and hitting enter produces this:

TRACE  1 [src/cli/mod.rs:313] logger done
TRACE  1 [src/cli/mod.rs:314] migrate start
TRACE  1 [src/cli/mod.rs:314] migrate done
DEBUG  1 [src/cli/mod.rs:319] ARGS: /Users/shlajin/.local/bin/mise hook-env -s zsh
TRACE  1 [src/cli/mod.rs:325] run hook-env start
TRACE  1 [src/config/mod.rs:94] load start
TRACE  1 [src/backend/mod.rs:56] load_tools start
TRACE  7 [src/toolset/install_state.rs:99] init_tools ruby
TRACE  4 [src/toolset/install_state.rs:99] init_tools python
TRACE  3 [src/toolset/install_state.rs:99] init_tools node
TRACE  1 [src/registry.rs:35] disable_backends
TRACE  1 [src/registry.rs:39] disable_backends
TRACE  1 [src/backend/mod.rs:66] load_tools core
TRACE  1 [src/backend/mod.rs:77] load_tools install_state
TRACE  1 [src/backend/mod.rs:91] load_tools done
TRACE  1 [src/config/mod.rs:96] load idiomatic_files
TRACE  1 [src/config/mod.rs:102] load config_filenames
TRACE  1 [src/config/mod.rs:104] load config_paths
TRACE  1 [src/config/mod.rs:105] config_paths: []
TRACE  1 [src/config/mod.rs:107] load config_files
TRACE  1 [src/config/mod.rs:1072] load_vars start
TRACE  1 [src/config/mod.rs:1085] load_vars done
TRACE  1 [src/config/mod.rs:1087] EnvResults
TRACE  1 [src/config/mod.rs:1055] load_aliases: 0
TRACE  1 [src/config/mod.rs:707] project_root: None
TRACE  1 [src/config/mod.rs:1067] load_plugins: 0
TRACE  1 [src/config/mod.rs:135] load build
TRACE  1 [src/config/mod.rs:138] load validate
TRACE  1 [src/config/mod.rs:141] load all aliases
TRACE  1 [src/config/mod.rs:144] config: Config {
    Config Files: [],
}
TRACE  1 [src/config/mod.rs:150] load done
TRACE  1 [src/config/mod.rs:571] load_env start
TRACE  1 [src/config/mod.rs:587] load_env done
TRACE  1 [src/config/mod.rs:589] EnvResults
TRACE  1 [src/cli/hook_env.rs:44] hook-env
TRACE  1 [src/hook_env.rs:117] watch files unmodified
TRACE  1 [src/hook_env.rs:78] early-exit
TRACE  1 [src/cli/hook_env.rs:46] should_exit_early true
TRACE  1 [src/cli/mod.rs:325] run hook-env done
TRACE  1 [src/main.rs:83] main done

I verified the reason is _mise_hook/mise by running zmodload -> zprof without running any other commands.

shlajin@MBP-M1-Max / % zmodload zsh/zprof
shlajin@MBP-M1-Max / % zprof
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)   40       16252.06   406.30   83.16%  16252.06   406.30   83.16%  _mise_hook
 2)    7        3290.18   470.03   16.84%   3290.18   470.03   16.84%  mise

-----------------------------------------------------------------------------------

 1)   40       16252.06   406.30   83.16%  16252.06   406.30   83.16%  _mise_hook

-----------------------------------------------------------------------------------

 2)    7        3290.18   470.03   16.84%   3290.18   470.03   16.84%  mise

mise doctor

version: 2024.12.12 macos-arm64 (2d9d289 2024-12-16)
activated: yes
shims_on_path: no

build_info:
  Target: aarch64-apple-darwin
  Features: DEFAULT, NATIVE_TLS, OPENSSL
  Built: Mon, 16 Dec 2024 18:21:21 +0000
  Rust Version: rustc 1.83.0 (90b35a623 2024-11-26)
  Profile: release

shell:
  /bin/zsh
  zsh 5.9 (x86_64-apple-darwin23.0)

dirs:
  cache: ~/Library/Caches/mise
  config: ~/.config/mise
  data: ~/.local/share/mise
  shims: ~/.local/share/mise/shims
  state: ~/.local/state/mise

config_files:

backends:
  aqua
  asdf
  cargo
  core
  gem
  go
  npm
  pipx
  spm
  ubi
  vfox

plugins:

toolset:

path:
  ~/.local/bin
  /usr/local/bin
  /System/Cryptexes/App/usr/bin
  /usr/bin
  /bin
  /usr/sbin
  /sbin
  /var/run/com.apple.security.cryptexd/codex.system/bootstrap/usr/local/bin
  /var/run/com.apple.security.cryptexd/codex.system/bootstrap/usr/bin
  /var/run/com.apple.security.cryptexd/codex.system/bootstrap/usr/appleinternal/bin
  /opt/X11/bin
  /Library/Apple/usr/bin
  /Applications/Little Snitch.app/Contents/Components
  ~/.cargo/bin
  ~/.orbstack/bin

env_vars:
  MISE_SHELL=zsh
  MISE_TRACE=0

settings:

No problems found

Additionally, I used fairly old mise installation (beginning 2024-early) when decided to investigate why it's slow. The doctor suggested me to self-update to the latest version, which I did, and it didn't help.

[jdx]

MISE_TIMINGS=1 might give more visibility

[shlajin]

Weirdly enough, MISE_TIMINGS=1 report just a few ms...

%
[TIME] 1 mise::cli::hande_shim 9µs
[TIME] 6 mise::toolset::install_state::init_plugins 26µs
[TIME] 3 mise::toolset::install_state::init_tools 589µs
[TIME] 6 mise::cli::install_state 651µs
[TIME] 8 mise::cli::get_matches_from 755µs
[TIME] 1 mise::cli::pre_settings 1.2ms
[TIME] 1 mise::cli::add_cli_matches 2µs
[TIME] 1 mise::cli::settings 569µs
[TIME] 1 mise::cli::logger 4µs
[TIME] 1 mise::cli::migrate 126µs
[TIME] 1 mise::cli::run hook-env 1.9ms
[TIME] 1 mise::main 4.0ms

[jdx]

i'd probably run mise activate zsh and try running different commands from there like in _mise_hook to figure out what is slow

[jdx]

I don't think this is a general issue so moving to troubleshooting

[shlajin]

I poked around and apparently it's not the command produced by mise is slow on my machine. It's mise itself!

I commented my whole .zshrc and did this:

% time /Users/shlajin/.local/bin/mise
The front-end to your dev env
...
/Users/shlajin/.local/bin/mise  0.01s user 0.01s system 2% cpu 0.493 total

almost half a second of startup time! My first thought would be I'm running wrong arch (rosetta), but I'm not (I'm on Macbook M1):

file /Users/shlajin/.local/bin/mise
/Users/shlajin/.local/bin/mise: Mach-O 64-bit executable arm64

[shlajin]

I removed my installation and reinstalled it with homebrew. On a good run it's x3 fast.

time /opt/homebrew/bin/mise --version
2024.12.13 macos-arm64 (2024-12-17)
/opt/homebrew/bin/mise --version  0.01s user 0.01s system 10% cpu 0.159 total

While it's a substantial performance increase, it still looks a little off to me. 150ms just to print a version feels a little too much – likely something else is happening :/

[syhol]

I'm getting about 30ms on a cold start and 17ms on warm starts, and I'm also on macos-arm64.

Would you mind also testing in an sh shell.

~
❯ sh
sh-3.2$ time mise --version
2024.12.14 macos-arm64 (ac3079c 2024-12-18)

real    0m0.020s
user    0m0.010s
sys     0m0.019s
sh-3.2$ time mise --version
2024.12.14 macos-arm64 (ac3079c 2024-12-18)

real    0m0.017s
user    0m0.010s
sys     0m0.016s
sh-3.2$

I'm wondering if its a zsh specific issue you're facing.

[shlajin]

At this point I have no idea. Yesterday I noticed that running node or bun (even outside of mise installations) also took a good 200-400ms to boot up. Certainly not something what happened before. Other tools/languages didn't have this unknown penalty at all. And today it suddenly started working blazingly fast... no reboots, no restarts – even the same tmux session!

This suggests the problem is indeed not related to mise (or rather not unique to mise) and happens only under certain circumstances that I'm still trying to figure out. I will get back to this thread if/when I start observing the behaviour again.

Thanks!