`proto` causes `starship` terminal script to execute slowly #229

lzm0x219 · 2023-10-11T07:22:14Z

When I use proto to manage nodejs, the execution time of starship's script to query the nodejs version becomes extremely slow.

As shown in the picture:

milesj · 2023-10-11T16:47:20Z

Does the PROTO_LOG=trace node ... logs show anything useful? Perhaps which line is taking the most time.

If it was an initial run, there's always a small hit where we have to download the WASM code.

lzm0x219 · 2023-10-12T02:02:46Z

The more than 600 milliseconds here refers to the time lost by starship to query the nodejs version used by the current project. When using the nodejs version managed by n, starship takes very little time. I can provide the steps to reproduce for reference.

lzm0x219 · 2023-10-12T02:07:56Z

Reproduction steps:

Install starship.
Create a project using moon and specify a nodejs version.
Execute in terminal: starship timings.

lzm0x219 · 2023-10-12T02:09:15Z

This is the nodejs version I installed with n:

milesj · 2023-10-12T02:10:36Z

proto detects the version dynamically at runtime, it's not fixed like other version managers.

There's going to be some kind of hit, but I won't know where the slowdown is happening without the logs.

lzm0x219 · 2023-10-12T02:19:11Z

[TRACE] - (starship::utils): Creating Command for binary "node"
[TRACE] - (starship::utils): Using "/Users/liuziming/.proto/bin/node" as "node"
[TRACE] - (starship::utils): stdout: "v18.18.0\n", stderr: "[DEBUG 2023-10-12 10:17:20] proto  Running proto v0.19.3 \n[TRACE 10:17:20] starbase::app  Running startup phase with 1 systems \n[TRACE 10:17:20] starbase::app  Running analyze phase with 1 systems \n[TRACE 10:17:20] starbase::app  Running execute phase with 2 systems \n[DEBUG 10:17:20] proto_core::tool_loader:run  Traversing upwards to find a configured plugin  tool=\"node\"\n[TRACE 10:17:21] warpgate::loader:run  Creating plugin loader  cache_dir=\"/Users/liuziming/.proto/plugins\"\n[TRACE 10:17:21] warpgate::loader:run  Loading plugin node  plugin=\"node\" locator=\"source:https://github.com/moonrepo/node-plugin/releases/latest/download/node_plugin.wasm\"\n[TRACE 10:17:21] starbase_utils::fs:run  Reading file metadata  file=\"/Users/liuziming/.proto/plugins/node-latest-1e6c749ee740e9937b99d790309463dd34a7fd7dffbe6deb06bdac58119c97c2.wasm\"\n[TRACE 10:17:21] warpgate::loader:run  Plugin already downloaded and cached  plugin=\"node\" path=\"/Users/liuziming/.proto/plugins/node-latest-1e6c749ee740e9937b99d790309463dd34a7fd7dffbe6deb06bdac58119c97c2.wasm\"\n[DEBUG 10:17:21] proto_core::tool_loader:run  Loading WASM plugin  source=\"/Users/liuziming/.proto/plugins/node-latest-1e6c749ee740e9937b99d790309463dd34a7fd7dffbe6deb06bdac58119c97c2.wasm\"\n[TRACE 10:17:21] proto_core::tool_loader:run  Storing tool identifier  id=\"node\"\n[TRACE 10:17:21] proto_core::tool_loader:run  Storing user configuration  config={\"auto_clean\":false,\"auto_install\":false,\"node_intercept_globals\":true}\n[TRACE 10:17:21] proto_core::tool_loader:run  Storing proto environment  env={\"arch\":\"x64\",\"os\":\"macos\",\"home_dir\":{\"path\":\"/home/\",\"virtual_prefix\":\"/home\",\"real_prefix\":\"/Users/liuziming\"},\"proto_dir\":{\"path\":\"/home/.proto\",\"virtual_prefix\":\"/home\",\"real_prefix\":\"/Users/liuziming\"}}\n[DEBUG 10:17:21] proto_core::tool:run  Creating tool node and instantiating plugin \n[DEBUG 10:17:21] proto_core::tool_manifest:run:load  Loading manifest.json  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[TRACE 10:17:21] starbase_utils::fs:run:load  Opening file  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:run:load  Locking file  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:run:load  Unlocking file  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[DEBUG 10:17:21] proto_core::tool:run  Created tool node and its WASM runtime \n[TRACE 10:17:21] warpgate::plugin:run  Calling plugin function register_tool  plugin=\"node\" input={\"id\":\"node\"}\n[TRACE 10:17:21] warpgate::plugin:run  Called plugin function register_tool  plugin=\"node\" output={\"env_vars\":[\"NODE_OPTIONS\",\"NODE_PATH\"],\"inventory\":{\"disable_progress_bars\":false},\"name\":\"Node.js\",\"plugin_version\":\"0.3.1\",\"type_of\":\"Language\"}\n[TRACE 10:17:21] proto_core::version_detector:run  Attempting to find local version from config files  tool=\"node\"\n[TRACE 10:17:21] proto_core::version_detector:run  Checking directory  tool=\"node\" dir=\"/Users/liuziming/Company/salescloud-admin-web\"\n[TRACE 10:17:21] warpgate::plugin:run  Calling plugin function detect_version_files  plugin=\"node\" input={}\n[TRACE 10:17:21] warpgate::plugin:run  Called plugin function detect_version_files  plugin=\"node\" output={\"files\":[\".nvmrc\",\".node-version\",\"package.json\"]}\n[TRACE 10:17:21] proto_core::tool:run  Attempting to detect a version from directory  tool=\"node\" dir=\"/Users/liuziming/Company/salescloud-admin-web\"\n[TRACE 10:17:21] starbase_utils::fs:run  Reading file  file=\"/Users/liuziming/Company/salescloud-admin-web/package.json\"\n[TRACE 10:17:21] warpgate::plugin:run  Calling plugin function parse_version_file  plugin=\"node\" input={\"content\":\"{\\n  \\\"name\\\": \\\"salescloud-admin-web\\\",\\n  \\\"version\\\": \\\"0.0.0\\\",\\n  \\\"type\\\": \\\"module\\\",\\n  \\\"scripts\\\": {\\n    \\\"build\\\": \\\"vite build\\\",\\n    \\\"dev\\\": \\\"vite --host\\\",\\n    \\\"lint\\\": \\\"tsc\\\",\\n    \\\"prepare\\\": \\\"is-ci || husky install\\\",\\n    \\\"preview\\\": \\\"vite preview\\\"\\n  },\\n  \\\"dependencies\\\": {\\n    \\\"@ant-design/icons\\\": \\\"5.2.6\\\",\\n    \\\"ahooks\\\": \\\"3.7.8\\\",\\n    \\\"ali-oss\\\": \\\"6.18.1\\\",\\n    \\\"antd\\\": \\\"5.10.0\\\",\\n    \\\"antd-style\\\": \\\"3.5.0\\\",\\n    \\\"dayjs\\\": \\\"1.11.10\\\",\\n    \\\"file-saver\\\": \\\"2.0.5\\\",\\n    \\\"react\\\": \\\"18.2.0\\\",\\n    \\\"react-dom\\\": \\\"18.2.0\\\",\\n    \\\"react-router-dom\\\": \\\"6.16.0\\\",\\n    \\\"superjson\\\": \\\"2.0.0\\\",\\n    \\\"tilg\\\": \\\"0.1.1\\\",\\n    \\\"umi-request\\\": \\\"1.4.0\\\"\\n  },\\n  \\\"devDependencies\\\": {\\n    \\\"@total-typescript/ts-reset\\\": \\\"0.5.1\\\",\\n    \\\"@types/ali-oss\\\": \\\"6.16.9\\\",\\n    \\\"@types/file-saver\\\": \\\"2.0.5\\\",\\n    \\\"@types/node\\\": \\\"20.8.4\\\",\\n    \\\"@types/react\\\": \\\"18.2.28\\\",\\n    \\\"@types/react-dom\\\": \\\"18.2.13\\\",\\n    \\\"@vitejs/plugin-react-swc\\\": \\\"3.4.0\\\",\\n    \\\"husky\\\": \\\"8.0.3\\\",\\n    \\\"is-ci\\\": \\\"3.0.1\\\",\\n    \\\"lightningcss\\\": \\\"1.22.0\\\",\\n    \\\"lint-staged\\\": \\\"14.0.1\\\",\\n    \\\"prettier\\\": \\\"3.0.3\\\",\\n    \\\"prettier-plugin-packagejson\\\": \\\"2.4.6\\\",\\n    \\\"sort-package-json\\\": \\\"2.6.0\\\",\\n    \\\"turbo\\\": \\\"1.10.15\\\",\\n    \\\"typescript\\\": \\\"5.2.2\\\",\\n    \\\"vite\\\": \\\"4.4.11\\\",\\n    \\\"vite-plugin-mkcert\\\": \\\"1.16.0\\\",\\n    \\\"vite-tsconfig-paths\\\": \\\"4.2.1\\\"\\n  }\\n}\",\"file\":\"package.json\"}\n[TRACE 10:17:21] warpgate::plugin:run  Called plugin function parse_version_file  plugin=\"node\" output={}\n[TRACE 10:17:21] proto_core::version_detector:run  Checking directory  tool=\"node\" dir=\"/Users/liuziming/Company\"\n[TRACE 10:17:21] proto_core::tool:run  Attempting to detect a version from directory  tool=\"node\" dir=\"/Users/liuziming/Company\"\n[TRACE 10:17:21] proto_core::version_detector:run  Checking directory  tool=\"node\" dir=\"/Users/liuziming\"\n[TRACE 10:17:21] proto_core::tool:run  Attempting to detect a version from directory  tool=\"node\" dir=\"/Users/liuziming\"\n[TRACE 10:17:21] proto_core::version_detector:run  Checking directory  tool=\"node\" dir=\"/Users\"\n[TRACE 10:17:21] proto_core::tool:run  Attempting to detect a version from directory  tool=\"node\" dir=\"/Users\"\n[TRACE 10:17:21] proto_core::version_detector:run  Checking directory  tool=\"node\" dir=\"/\"\n[TRACE 10:17:21] proto_core::tool:run  Attempting to detect a version from directory  tool=\"node\" dir=\"/\"\n[TRACE 10:17:21] proto_core::version_detector:run  Attempting to use global version from manifest  tool=\"node\"\n[DEBUG 10:17:21] proto_core::version_detector:run  Detected global version from manifest  tool=\"node\" version=\"18.18.0\" file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[DEBUG 10:17:21] proto_core::tool:run  Resolving a semantic version or alias  tool=\"node\" initial_version=\"18.18.0\"\n[DEBUG 10:17:21] proto_core::tool:run  Loading available versions  tool=\"node\"\n[TRACE 10:17:21] starbase_utils::fs:run  Reading file metadata  file=\"/Users/liuziming/.proto/tools/node/remote-versions.json\"\n[DEBUG 10:17:21] proto_core::tool:run  Loading from local cache  tool=\"node\" cache=\"/Users/liuziming/.proto/tools/node/remote-versions.json\"\n[TRACE 10:17:21] starbase_utils::fs:run  Opening file  file=\"/Users/liuziming/.proto/tools/node/remote-versions.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:run  Locking file  file=\"/Users/liuziming/.proto/tools/node/remote-versions.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:run  Unlocking file  file=\"/Users/liuziming/.proto/tools/node/remote-versions.json\"\n[TRACE 10:17:21] warpgate::plugin:run  Calling plugin function resolve_version  plugin=\"node\" input={\"context\":{\"env_vars\":{},\"tool_dir\":{\"path\":\"/home/.proto/tools/node/latest\",\"virtual_prefix\":\"/home\",\"real_prefix\":\"/Users/liuziming\"},\"version\":\"latest\"},\"initial\":\"18.18.0\"}\n[TRACE 10:17:21] warpgate::plugin:run  Called plugin function resolve_version  plugin=\"node\" output={}\n[DEBUG 10:17:21] proto_core::tool:run  Resolved to 18.18.0  tool=\"node\" version=\"18.18.0\"\n[DEBUG 10:17:21] proto_core::tool:run  Checking if tool is installed  tool=\"node\" install_dir=\"/Users/liuziming/.proto/tools/node/18.18.0\"\n[DEBUG 10:17:21] proto_core::tool:run  Tool has already been installed, locating binaries and shims  tool=\"node\" install_dir=\"/Users/liuziming/.proto/tools/node/18.18.0\"\n[DEBUG 10:17:21] proto_core::tool:run  Locating binaries for tool  tool=\"node\"\n[TRACE 10:17:21] warpgate::plugin:run  Calling plugin function locate_bins  plugin=\"node\" input={\"context\":{\"env_vars\":{},\"tool_dir\":{\"path\":\"/home/.proto/tools/node/18.18.0\",\"virtual_prefix\":\"/home\",\"real_prefix\":\"/Users/liuziming\"},\"version\":\"18.18.0\"}}\n[TRACE 10:17:21] warpgate::plugin:run  Called plugin function locate_bins  plugin=\"node\" output={\"bin_path\":\"bin/node\",\"fallback_last_globals_dir\":true,\"globals_lookup_dirs\":[\"$PROTO_ROOT/tools/node/globals/bin\"]}\n[DEBUG 10:17:21] proto_core::tool:run  Found a potential binary  tool=\"node\" bin_path=\"/Users/liuziming/.proto/tools/node/18.18.0/bin/node\"\n[TRACE 10:17:21] warpgate::plugin:run  Calling plugin function create_shims  plugin=\"node\" input={\"context\":{\"env_vars\":{},\"tool_dir\":{\"path\":\"/home/.proto/tools/node/18.18.0\",\"virtual_prefix\":\"/home\",\"real_prefix\":\"/Users/liuziming\"},\"version\":\"18.18.0\"}}\n[TRACE 10:17:21] warpgate::plugin:run  Called plugin function create_shims  plugin=\"node\" output={\"no_primary_global\":false,\"global_shims\":{\"npx\":{\"bin_path\":\"bin/npx\"}},\"local_shims\":{}}\n[DEBUG 10:17:21] proto::commands::run:run  Running Node.js  bin=\"/Users/liuziming/.proto/tools/node/18.18.0/bin/node\" args=[\"--version\"]\n[TRACE 10:17:21] starbase::app  Running shutdown phase with 1 systems \n[DEBUG 10:17:21] proto_core::tool_manifest:save  Saving manifest  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:save  Locking file exclusively  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:save  Writing file  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n[TRACE 10:17:21] starbase_utils::fs_lock:save  Unlocking file exclusively  file=\"/Users/liuziming/.proto/tools/node/manifest.json\"\n", exit code: "Some(0)", took 511.813997ms

milesj · 2023-10-12T02:58:20Z

Thanks, will look into.

Rel1cx · 2023-10-16T03:41:02Z

Same problem, running with proto is significantly slower.

Rel1cx · 2023-10-16T04:17:18Z

Found a workaround to bypass the version detection.

# proto
export PROTO_HOME="$HOME/.proto"
export PATH="$PROTO_HOME/bin:$PATH"

# manual add proto tools's bin to path, use `proto pin <tool-name> <version>` to switch version
export PATH="$PATH:$(dirname $(proto bin node))"
export PATH="$PATH:$(dirname $(proto bin bun))"
# ...

chmod -x ~/.proto/bin/*
chmod +x ~/.proto/bin/proto

lzm0x219 · 2023-10-16T06:41:53Z

this doesn't work for me

milesj · 2023-10-16T15:53:34Z

I'll have some improvements for this in the next version.

milesj · 2023-10-19T01:16:25Z

A few changes in this PR should help with this: #238

milesj · 2023-10-20T23:23:03Z

Release v0.20 with these perf improvements. It'll probably only net like 100ms worth though.

However, this version now supports symlinks alongside shims, so you can use those instead of the shims for the native speed.

More info: https://moonrepo.dev/blog/proto-v0.20

Mehdi-Hp · 2023-11-05T11:02:08Z

I'm on 0.21.1, and I still have this issue. Unless I'm doing something wrong?

milesj · 2023-11-05T19:32:58Z

@Mehdi-Hp Is it that long on every run? When not hitting the cache, we make some http calls, so that would explain the slowdown. But that shouldn't happen every run.

You can also not use the shims, and just use the binaries directly. https://moonrepo.dev/docs/proto#how-does-it-work

Mehdi-Hp · 2023-11-06T05:47:52Z

@milesj
Seems like it's because of the http call, because I had a bad connection yesterday and it's kinda better today. But it happens on every run. Is there anyway I can make sure the cache is working?

milesj · 2023-11-06T06:21:12Z

Can you paste the --log trace output? I have a feeling it's the calls we make to detect whether there's an internet connection or not.

Mehdi-Hp · 2023-11-06T07:47:23Z

Can you paste the --log trace output?

Umm, I'm lost. What's the full command here?

milesj · 2023-11-06T17:47:39Z

@Mehdi-Hp Sorry that can be passed to any proto command, but if you're running like node directory, you can do PROTO_LOG=trace.

milesj · 2023-11-06T23:39:46Z

This should help even more: #274

Mehdi-Hp · 2023-11-07T06:41:35Z

@milesj
This is the result for PROTO_LOG=trace node -v && starship timings

🔗 Colored screenshot

[DEBUG 2023-11-07 10:02:00] proto  Running proto v0.21.1  args=["proto", "run", "node", "--", "-v"]
[TRACE 10:02:00] starbase::app  Running startup phase with 1 systems
[TRACE 10:02:00] starbase::app  Running analyze phase with 1 systems
[TRACE 10:02:00] starbase::app  Running execute phase with 2 systems
[DEBUG 10:02:00] proto_core::user_config:run  Loading config.toml  file="/Users/mehdi/.proto/config.toml"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file  file="/Users/mehdi/.proto/config.toml"
[DEBUG 10:02:00] proto_core::tool_loader:run  Traversing upwards to find a configured plugin  tool="node"
[DEBUG 10:02:00] proto_core::tools_config:run  Loading .prototools  file="/Users/mehdi/Projects/.../.prototools"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file  file="/Users/mehdi/Projects/.../.prototools"
[TRACE 10:02:00] warpgate::loader:run  Creating plugin loader  cache_dir="/Users/mehdi/.proto/plugins"
[TRACE 10:02:00] proto_core::helpers:run:is_offline  Checking for an internet connection  timeout=750
[TRACE 10:02:00] proto_core::helpers  Resolving 1.1.1.1:53
[TRACE 10:02:00] proto_core::helpers:run:is_offline  Online!
[TRACE 10:02:00] warpgate::loader:run  Loading plugin node  plugin="node" locator="source:https://github.com/moonrepo/node-plugin/releases/latest/download/node_plugin.wasm"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file metadata  file="/Users/mehdi/.proto/plugins/node-latest-9abaf7827dc5c777e7479e8e9fab106de7af78d69303b6cbeb8d1b104741f368.wasm"
[TRACE 10:02:00] warpgate::loader:run  Plugin already downloaded and cached  plugin="node" path="/Users/mehdi/.proto/plugins/node-latest-9abaf7827dc5c777e7479e8e9fab106de7af78d69303b6cbeb8d1b104741f368.wasm"
[DEBUG 10:02:00] proto_core::tool_loader:run  Loading WASM plugin  source="/Users/mehdi/.proto/plugins/node-latest-9abaf7827dc5c777e7479e8e9fab106de7af78d69303b6cbeb8d1b104741f368.wasm"
[TRACE 10:02:00] proto_core::tool_loader:run  Storing tool identifier  id="node"
[TRACE 10:02:00] proto_core::tool_loader:run  Storing user configuration  config={"auto_clean":true,"auto_install":true,"node_intercept_globals":true}
[TRACE 10:02:00] proto_core::tool_loader:run  Storing proto environment  env={"arch":"arm64","os":"macos","home_dir":{"path":"/userhome/","virtual_prefix":"/userhome","real_prefix":"/Users/mehdi"},"proto_dir":{"path":"/proto/","virtual_prefix":"/proto","real_prefix":"/Users/mehdi/.proto"}}
[DEBUG 10:02:00] proto_core::tool:run  Creating tool node and instantiating plugin
[DEBUG 10:02:00] proto_core::tool_manifest:run:load  Loading manifest.json  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs:run:load  Opening file  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs_lock:run:load  Locking file  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs_lock:run:load  Unlocking file  file="/Users/mehdi/.proto/tools/node/manifest.json"
[DEBUG 10:02:00] proto_core::tool:run  Created tool node and its WASM runtime
[TRACE 10:02:00] warpgate::plugin:run  Calling plugin function register_tool  plugin="node" input={"id":"node"}
[TRACE 10:02:00] warpgate::plugin:run  Called plugin function register_tool  plugin="node" output={"inventory":{"disable_progress_bars":false},"name":"Node.js","plugin_version":"0.4.3","self_upgrade_commands":[],"type":"Language"}
[TRACE 10:02:00] proto_core::version_detector:run  Attempting to find local version from config files  tool="node"
[TRACE 10:02:00] proto_core::version_detector:run  Checking directory  tool="node" dir="/Users/mehdi/Projects/..."
[DEBUG 10:02:00] proto_core::tools_config:run  Loading .prototools  file="/Users/mehdi/Projects/.../.prototools"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file  file="/Users/mehdi/Projects/.../.prototools"
[DEBUG 10:02:00] proto_core::version_detector:run  Detected version from .prototools file  tool="node" version=Version(Version { major: 20, minor: 9, patch: 0 }) file="/Users/mehdi/Projects/.../.prototools"
[DEBUG 10:02:00] proto_core::user_config:run  Loading config.toml  file="/Users/mehdi/.proto/config.toml"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file  file="/Users/mehdi/.proto/config.toml"
[DEBUG 10:02:00] proto_core::tool:run  Resolving a semantic version or alias  tool="node" initial_version="20.9.0"
[DEBUG 10:02:00] proto_core::tool:run  Loading available versions  tool="node"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file metadata  file="/Users/mehdi/.proto/tools/node/remote-versions.json"
[DEBUG 10:02:00] proto_core::tool:run  Loading from local cache  tool="node" cache="/Users/mehdi/.proto/tools/node/remote-versions.json"
[TRACE 10:02:00] starbase_utils::fs:run  Reading file  file="/Users/mehdi/.proto/tools/node/remote-versions.json"
[TRACE 10:02:00] starbase_utils::json:run  Parsing JSON  file="/Users/mehdi/.proto/tools/node/remote-versions.json"
[TRACE 10:02:00] warpgate::plugin:run  Calling plugin function resolve_version  plugin="node" input={"initial":"20.9.0"}
[TRACE 10:02:00] warpgate::plugin:run  Called plugin function resolve_version  plugin="node" output={}
[DEBUG 10:02:00] proto_core::tool:run  Resolved to 20.9.0  tool="node" version="20.9.0"
[DEBUG 10:02:00] proto_core::tool:run  Checking if tool is installed  tool="node" install_dir="/Users/mehdi/.proto/tools/node/20.9.0"
[DEBUG 10:02:00] proto_core::tool:run  Tool has already been installed, locating binaries and shims  tool="node" install_dir="/Users/mehdi/.proto/tools/node/20.9.0"
[DEBUG 10:02:00] proto_core::tool:run  Locating binaries for tool  tool="node"
[TRACE 10:02:00] warpgate::plugin:run  Calling plugin function locate_bins  plugin="node" input={"context":{"tool_dir":{"path":"/proto/tools/node/20.9.0","virtual_prefix":"/proto","real_prefix":"/Users/mehdi/.proto"},"version":"20.9.0"}}
[TRACE 10:02:00] warpgate::plugin:run  Called plugin function locate_bins  plugin="node" output={"bin_path":"bin/node","fallback_last_globals_dir":true,"globals_lookup_dirs":["$PROTO_HOME/tools/node/globals/bin"]}
[DEBUG 10:02:00] proto_core::tool:run  Found a binary  tool="node" bin_path="/Users/mehdi/.proto/tools/node/20.9.0/bin/node"
[TRACE 10:02:00] warpgate::plugin:run  Calling plugin function create_shims  plugin="node" input={"context":{"tool_dir":{"path":"/proto/tools/node/20.9.0","virtual_prefix":"/proto","real_prefix":"/Users/mehdi/.proto"},"version":"20.9.0"}}
[TRACE 10:02:00] warpgate::plugin:run  Called plugin function create_shims  plugin="node" output={"no_primary_global":false,"global_shims":{"npx":{"bin_path":"bin/npx"}},"local_shims":{}}
[DEBUG 10:02:00] proto::commands::run:run  Running Node.js  bin="/Users/mehdi/.proto/tools/node/20.9.0/bin/node" args=["-v"]
v20.9.0
[TRACE 10:02:00] starbase::app  Running shutdown phase with 1 systems
[DEBUG 10:02:00] proto_core::tool_manifest:save  Saving manifest  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs:save  Creating file without truncating  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs_lock:save  Locking file exclusively  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs_lock:save  Writing file  file="/Users/mehdi/.proto/tools/node/manifest.json"
[TRACE 10:02:00] starbase_utils::fs_lock:save  Unlocking file exclusively  file="/Users/mehdi/.proto/tools/node/manifest.json"

 Here are the timings of modules in your prompt (>=1ms or output):
 nodejs          -  499ms  -   "via  v20.9.0 "
 git_status      -    8ms  -   "[⇡] "
 directory       -   <1ms  -   "... "
 git_branch      -   <1ms  -   "on  fix/bugs "
 docker_context  -   <1ms  -   "via  orbstack "
 line_break      -   <1ms  -   "\n"
 character       -   <1ms  -   "❯ "

Mehdi-Hp · 2023-11-07T06:48:45Z

@milesj I run it again and got 1296ms for nodejs. I think this is my bottleneck:

milesj · 2023-11-07T08:01:56Z

Yah agreed. This should go away for the most part in that PR I posted.

Mehdi-Hp · 2023-11-12T11:40:48Z

I can say that version 0.22.1 is okay for me. I get ~250ms for nodejs now.

milesj · 2023-11-13T04:25:47Z

Nice! I'll keep working on getting that lower. Aiming for 100ms give or take.

muuvmuuv · 2024-10-29T09:22:48Z

Close to under 100ms, nice. I just want to add my output in any case it helps pushing it further down. Also added "time" command.

Seems that the HTTP client cost a lot:

[DEBUG 10:20:31.041] warpgate::client  Creating HTTP client
[DEBUG 10:20:31.152] warpgate::client  Created HTTP client

[DEBUG 2024-10-29 10:20:31.040] proto  Running proto v0.41.7  bin="/opt/homebrew/Cellar/proto/0.41.7/libexec/bin/proto" args=["run", "node", "--", "-v"] shim="node" shim_bin="/Users/marvin/.proto/shims/node" pid=30004
[TRACE 10:20:31.040] starbase::app  Running startup phase
[DEBUG 10:20:31.040] proto_core::proto  Creating proto environment, detecting store  store="/Users/marvin/.proto" home="/Users/marvin"
[TRACE 10:20:31.040] starbase::app  Running analyze phase
[DEBUG 10:20:31.040] proto::systems  Loading configuration in upwards-global mode  working_dir="/Developer"
[DEBUG 10:20:31.040] proto_core::proto_config  Loading .prototools  file="/Developer/.prototools"
[TRACE 10:20:31.041] starbase_utils::fs  Reading file  file="/Developer/.prototools"
[TRACE 10:20:31.041] schematic::config::loader  Loading partial configuration  config="ProtoConfig"
[TRACE 10:20:31.041] schematic::config::loader  Creating layer from source  config="ProtoConfig" source="<code>"
[TRACE 10:20:31.041] schematic::config::loader  Merging partial layers into a final result  config="ProtoConfig"
[DEBUG 10:20:31.041] proto_core::proto_config  Loading .prototools  file="/Users/marvin/.proto/.prototools"
[TRACE 10:20:31.041] starbase_utils::fs  Opening file  file="/Users/marvin/.proto/.prototools"
[TRACE 10:20:31.041] starbase_utils::fs_lock  Locking file  file="/Users/marvin/.proto/.prototools"
[TRACE 10:20:31.041] starbase_utils::fs_lock  Unlocking file  file="/Users/marvin/.proto/.prototools"
[TRACE 10:20:31.041] schematic::config::loader  Loading partial configuration  config="ProtoConfig"
[TRACE 10:20:31.041] schematic::config::loader  Creating layer from source  config="ProtoConfig" source="<code>"
[TRACE 10:20:31.041] schematic::config::loader  Merging partial layers into a final result  config="ProtoConfig"
[DEBUG 10:20:31.041] proto_core::proto_config  Merging loaded configs with global
[DEBUG 10:20:31.041] proto_core::proto_config  Merged 2 configs
[DEBUG 10:20:31.041] proto_core::proto_config  Merging loaded configs without global
[DEBUG 10:20:31.041] proto_core::proto_config  Merged 1 configs
[TRACE 10:20:31.041] starbase::app  Running execute phase
[DEBUG 10:20:31.041] proto_core::tool_loader  Finding a configured plugin  tool="node"
[DEBUG 10:20:31.041] proto_core::tool_loader  Using a built-in plugin  plugin="https://github.com/moonrepo/tools/releases/download/node_tool-v0.12.2/node_tool.wasm"
[TRACE 10:20:31.041] warpgate::loader  Creating plugin loader  cache_dir="/Users/marvin/.proto/plugins"
[TRACE 10:20:31.041] warpgate::loader  Loading plugin node  id="node" locator="https://github.com/moonrepo/tools/releases/download/node_tool-v0.12.2/node_tool.wasm"
[TRACE 10:20:31.041] starbase_utils::fs  Reading file metadata  file="/Users/marvin/.proto/plugins/node-2c6c77c45d1bdb8f047e79502196bb8fd995504ce5c4c03a9d26b1f7c8b15d59.wasm"
[TRACE 10:20:31.041] warpgate::loader  Plugin already downloaded and cached  id="node" path="/Users/marvin/.proto/plugins/node-2c6c77c45d1bdb8f047e79502196bb8fd995504ce5c4c03a9d26b1f7c8b15d59.wasm"
[DEBUG 10:20:31.041] proto_core::tool_loader  Loading WASM plugin  source="/Users/marvin/.proto/plugins/node-2c6c77c45d1bdb8f047e79502196bb8fd995504ce5c4c03a9d26b1f7c8b15d59.wasm"
[TRACE 10:20:31.041] warpgate::plugin  Storing plugin identifier  id="node"
[TRACE 10:20:31.041] warpgate::plugin  Storing host environment  id="node" env={"arch":"arm64","libc":"gnu","os":"macos","home_dir":{"path":"/userhome/","virtual_prefix":"/userhome","real_prefix":"/Users/marvin"}}
[DEBUG 10:20:31.041] proto_core::tool  Creating tool node and instantiating plugin
[DEBUG 10:20:31.041] warpgate::client  Creating HTTP client
[DEBUG 10:20:31.152] warpgate::client  Created HTTP client
[TRACE 10:20:31.152] warpgate::plugin  Creating plugin container  id="node"
[TRACE 10:20:31.157] warpgate::plugin  Created plugin container  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939"
[DEBUG 10:20:31.157] proto_core::tool  Created tool node and its WASM runtime
[TRACE 10:20:31.157] warpgate::plugin  Calling guest function register_tool  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939" input={"id":"node"}
[TRACE 10:20:31.157] warpgate::plugin  Called guest function register_tool  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939" output={"config_schema":{"name":"NodePluginConfig","ty":{"type":"Struct","fields":{"bundled-npm":{"schema":{"ty":{"type":"Boolean"}},"hidden":false,"nullable":false,"optional":true,"read_only":false,"write_only":false},"dist-url":{"schema":{"ty":{"type":"String"}},"hidden":false,"nullable":false,"optional":true,"read_only":false,"write_only":false}},"partial":false}},"inventory":{},"name":"Node.js","plugin_version":"0.12.2","type":"Language"}
[DEBUG 10:20:31.157] proto_core::tool_manifest  Loading manifest.json  file="/Users/marvin/.proto/tools/node/manifest.json"
[TRACE 10:20:31.157] starbase_utils::fs  Opening file  file="/Users/marvin/.proto/tools/node/manifest.json"
[TRACE 10:20:31.157] starbase_utils::fs_lock  Locking file  file="/Users/marvin/.proto/tools/node/manifest.json"
[TRACE 10:20:31.157] starbase_utils::fs_lock  Unlocking file  file="/Users/marvin/.proto/tools/node/manifest.json"
[TRACE 10:20:31.157] proto_core::version_detector  Attempting to find version from .prototools files  tool="node"
[DEBUG 10:20:31.157] proto_core::version_detector  Detected version from .prototools file  tool="node" version="~22" file="/Developer/.prototools"
[DEBUG 10:20:31.157] proto_core::flow::resolve  Resolving a semantic version or alias  tool="node" initial_version="~22"
[DEBUG 10:20:31.157] proto_core::flow::resolve  Loading available versions  tool="node"
[TRACE 10:20:31.157] starbase_utils::fs  Reading file metadata  file="/Users/marvin/.proto/tools/node/remote-versions.json"
[TRACE 10:20:31.157] starbase_utils::fs  Reading file  file="/Users/marvin/.proto/tools/node/remote-versions.json"
[TRACE 10:20:31.157] starbase_utils::json  Reading JSON file  file="/Users/marvin/.proto/tools/node/remote-versions.json"
[TRACE 10:20:31.158] warpgate::plugin  Calling guest function resolve_version  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939" input={"initial":"~22"}
[TRACE 10:20:31.158] warpgate::plugin  Called guest function resolve_version  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939" output={}
[TRACE 10:20:31.158] proto_core::version_resolver  Resolving a version with manifest  candidate="~22"
[TRACE 10:20:31.158] proto_core::version_resolver  Found a requirement, resolving further  requirement="~22"
[TRACE 10:20:31.158] proto_core::version_resolver  Resolved to locally installed version  version="22.10.0"
[DEBUG 10:20:31.158] proto_core::flow::resolve  Resolved to 22.10.0  tool="node" version="22.10.0"
[DEBUG 10:20:31.158] proto_core::flow::setup  Checking if tool is installed  tool="node" install_dir="/Users/marvin/.proto/tools/node/22.10.0"
[DEBUG 10:20:31.158] proto_core::flow::setup  Tool has already been installed, locating binaries and shims  tool="node" install_dir="/Users/marvin/.proto/tools/node/22.10.0"
[TRACE 10:20:31.158] warpgate::plugin  Calling guest function locate_executables  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939" input={"context":{"proto_version":"0.41.7","tool_dir":{"path":"/proto/tools/node/22.10.0","virtual_prefix":"/proto","real_prefix":"/Users/marvin/.proto"},"version":"22.10.0"}}
[TRACE 10:20:31.158] warpgate::plugin  Called guest function locate_executables  id="node" plugin="93e4a6cd-9918-49dd-ae36-fce36c673939" output={"exes_dir":"bin","globals_lookup_dirs":["$PROTO_HOME/tools/node/globals/bin"],"primary":{"exe_path":"bin/node"}}
[DEBUG 10:20:31.158] proto_core::flow::locate  Locating primary executable for tool  tool="node"
[DEBUG 10:20:31.158] proto_core::flow::locate  Found an executable  tool="node" exe_path="/Users/marvin/.proto/tools/node/22.10.0/bin/node"
[DEBUG 10:20:31.158] proto::commands::run  Running Node.js  bin="/Users/marvin/.proto/tools/node/22.10.0/bin/node" args=["-v"] pid=30004
[TRACE 10:20:31.158] starbase_utils::fs  Writing file  file="/Users/marvin/.proto/tools/node/22.10.0/.last-used"
v22.10.0

________________________________________________________
Executed in  160.60 millis    fish           external
   usr time   72.79 millis    0.19 millis   72.60 millis
   sys time    7.19 millis    1.13 millis    6.05 millis


 Here are the timings of modules in your prompt (>=1ms or output):
 nodejs       -  131ms  -   "via  v22.10.0 "
 custom.warp  -   27ms  -   ""
 git_status   -    7ms  -   "[!?6] "
 directory    -   <1ms  -   "/Developer"
 git_branch   -   <1ms  -   "on  main "
 line_break   -   <1ms  -   "\n"
 package      -   <1ms  -   "is 󰏗 v1.19.0 "
 time         -   <1ms  -   "at 10:20:31"

milesj · 2024-10-29T22:26:31Z

Yeah I've been looking into the http client stuff, but it's a 3rd party lib (reqwest -> hyper -> rustls). I think the slowdown is loading http certs, but I'm not positive yet.

The client is also only loaded when we need make requests, so for most calls it shouldn't be a perf hit.

milesj closed this as completed Oct 20, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`proto` causes `starship` terminal script to execute slowly #229

`proto` causes `starship` terminal script to execute slowly #229

lzm0x219 commented Oct 11, 2023

milesj commented Oct 11, 2023

lzm0x219 commented Oct 12, 2023

lzm0x219 commented Oct 12, 2023

lzm0x219 commented Oct 12, 2023

milesj commented Oct 12, 2023

lzm0x219 commented Oct 12, 2023

milesj commented Oct 12, 2023

Rel1cx commented Oct 16, 2023 •

edited

Loading

Rel1cx commented Oct 16, 2023 •

edited

Loading

lzm0x219 commented Oct 16, 2023

milesj commented Oct 16, 2023

milesj commented Oct 19, 2023

milesj commented Oct 20, 2023 •

edited

Loading

Mehdi-Hp commented Nov 5, 2023

milesj commented Nov 5, 2023

Mehdi-Hp commented Nov 6, 2023

milesj commented Nov 6, 2023

Mehdi-Hp commented Nov 6, 2023 •

edited

Loading

milesj commented Nov 6, 2023

milesj commented Nov 6, 2023

Mehdi-Hp commented Nov 7, 2023

Mehdi-Hp commented Nov 7, 2023

milesj commented Nov 7, 2023

Mehdi-Hp commented Nov 12, 2023

milesj commented Nov 13, 2023

muuvmuuv commented Oct 29, 2024 •

edited

Loading

milesj commented Oct 29, 2024 •

edited

Loading

proto causes starship terminal script to execute slowly #229

proto causes starship terminal script to execute slowly #229

Comments

lzm0x219 commented Oct 11, 2023

milesj commented Oct 11, 2023

lzm0x219 commented Oct 12, 2023

lzm0x219 commented Oct 12, 2023

lzm0x219 commented Oct 12, 2023

milesj commented Oct 12, 2023

lzm0x219 commented Oct 12, 2023

milesj commented Oct 12, 2023

Rel1cx commented Oct 16, 2023 • edited Loading

Rel1cx commented Oct 16, 2023 • edited Loading

lzm0x219 commented Oct 16, 2023

milesj commented Oct 16, 2023

milesj commented Oct 19, 2023

milesj commented Oct 20, 2023 • edited Loading

Mehdi-Hp commented Nov 5, 2023

milesj commented Nov 5, 2023

Mehdi-Hp commented Nov 6, 2023

milesj commented Nov 6, 2023

Mehdi-Hp commented Nov 6, 2023 • edited Loading

milesj commented Nov 6, 2023

milesj commented Nov 6, 2023

Mehdi-Hp commented Nov 7, 2023

Mehdi-Hp commented Nov 7, 2023

milesj commented Nov 7, 2023

Mehdi-Hp commented Nov 12, 2023

milesj commented Nov 13, 2023

muuvmuuv commented Oct 29, 2024 • edited Loading

milesj commented Oct 29, 2024 • edited Loading

`proto` causes `starship` terminal script to execute slowly #229

`proto` causes `starship` terminal script to execute slowly #229

Rel1cx commented Oct 16, 2023 •

edited

Loading

Rel1cx commented Oct 16, 2023 •

edited

Loading

milesj commented Oct 20, 2023 •

edited

Loading

Mehdi-Hp commented Nov 6, 2023 •

edited

Loading

muuvmuuv commented Oct 29, 2024 •

edited

Loading

milesj commented Oct 29, 2024 •

edited

Loading