search

denoland / deno

A modern runtime for JavaScript and TypeScript.
https://deno.com
MIT License
93.98k stars 5.23k forks source link

Horrible performances with some npm packages (but fine on other runtimes) ? #25240

Open lowlighter opened 2 weeks ago

lowlighter commented 2 weeks ago

I'm trying to use unified/remark/rehype to render markdown and the performances on deno specifically are horrible. As demonstrated below, it's 17.5s for startup time on deno, while bun only take 1.2s and node (not using ts) 2.3s.

The 8x-17x time factor between deno and other runtimes seems really abnormal.

  vscode ➜ /workspaces/libs/markdown $ time bun test.ts 
  ok

+ real    0m1.210s
  user    0m0.119s
  sys     0m0.172s
  vscode ➜ /workspaces/libs/markdown $ time deno test.ts 
  ok

- real    0m17.546s
  user    0m0.126s
  sys     0m0.646s
  vscode ➜ /workspaces/libs/markdown $ time node --experimental-modules test.mjs
  ok

! real    0m2.342s
  user    0m0.257s
  sys     0m0.124s

Note that running the same through https://esm.sh imports yields extremely good result (even when deps are not cached):

  vscode ➜ /workspaces/libs/markdown $ time deno run esm_test.ts 
  ok

+ real    0m1.326s
  user    0m0.138s
  sys     0m0.016s
  vscode ➜ /workspaces/libs/markdown $ time deno run esm_test.ts 
  ok

+ real    0m0.057s
  user    0m0.038s
  sys     0m0.029s

Version:

vscode ➜ /workspaces/libs/markdown $ deno --version
deno 1.46.1 (stable, release, x86_64-unknown-linux-gnu)
v8 12.9.202.2-rusty
typescript 5.5.2

Reproduction:

test.ts ```ts import { unified, type Processor as _Processor } from "unified" import remarkRehype from "remark-rehype" import remarkParse from "remark-parse" import rehypeRaw from "rehype-raw" import rehypeStringify from "rehype-stringify" // Prevent tree-shaking if ((unified && remarkRehype && remarkParse && rehypeRaw && rehypeStringify)) { console.log("ok") } ```
deno.jsonc ```json { "imports": { "unified":"npm:unified@11", "rehype-raw":"npm:rehype-raw@7", "rehype-stringify":"npm:rehype-stringify@10", "remark-parse":"npm:remark-parse@11", "remark-rehype":"npm:remark-rehype@11", }, } ```
devsnek commented 2 weeks ago

Do you have any more information about the environment you're running this in? The provided test script completes in milliseconds for me on all runtimes.

lowlighter commented 2 weeks ago

After testing on other environments, it seems indeed to vary

The devcontainer docker file is this one, but honestly it doesn't have anything special in it. I tried to recreate the container locally too but the issue still persist.

It may be more an issue about the combo Windows 11 + Docker + VS code devcontainers + Deno + Node modules, rather than just Deno...

I'm not sure but to run the script after switching between either windows / the debian container, I need to clean out node_modules because there's some symlinks issues that seems to occur. So I wonder if the performance issue is actually linked to having a "cross-os" environment that introduce some fs delays/incompatibilities, but then I don't understand why i'd only happens on deno. GitHub codespaces probably run on linux hosts, so the lack of perf issues seems to implies that the mix between windows/linux env is somehow responsible

Is there any way to run deno in verbose to see where it gets stuck ?

lucacasonato commented 2 weeks ago

Can you try run with --no-code-cache? You can run with -Ldebug to get very verbose debug logs.

lowlighter commented 2 weeks ago

Seems --no-code-cache yields about the same result

As for -Ldebug, it doesn't really seems stuck but it does take more time to resolve/load each dependency when using npm modifiers (about 30-50ms between each line):

[02:28:09.712868] DEBUG RS - deno::npm::managed:551 - Resolved hast-util-whitespace from file:///workspaces/libs/markdown/node_modules/.deno/hast-util-to-html@9.0.2/node_modules/hast-util-to-html/lib/omission/util/siblings.js to /workspaces/libs/markdown/node_modules/.deno/hast-util-whitespace@3.0.0/node_modules/hast-util-whitespace
[02:28:09.740208] DEBUG RS - deno::npm::managed:551 - Resolved hast-util-whitespace from file:///workspaces/libs/markdown/node_modules/.deno/hast-util-to-html@9.0.2/node_modules/hast-util-to-html/lib/omission/opening.js to /workspaces/libs/markdown/node_modules/.deno/hast-util-whitespace@3.0.0/node_modules/hast-util-whitespace
[02:28:09.799658] DEBUG RS - deno::npm::managed:551 - Resolved stringify-entities from file:///workspaces/libs/markdown/node_modules/.deno/hast-util-to-html@9.0.2/node_modules/hast-util-to-html/lib/handle/text.js to /workspaces/libs/markdown/node_modules/.deno/stringify-entities@4.0.4/node_modules/stringify-entities
[02:28:09.826675] DEBUG RS - deno_runtime::worker:528 - V8 code cache hit for script: file:///workspaces/libs/markdown/node_modules/.deno/extend@3.0.2/node_modules/extend/index.js, [15001781486801369526]
[02:28:09.832745] ok

But when using https specifier, it's nearly instant (usually less than 1ms between lines):

[02:27:35.028418] DEBUG RS - deno::module_loader:355 - V8 code cache hit for ES module: https://esm.sh/v135/micromark-factory-label@2.0.0/denonext/micromark-factory-label.mjs, [14832778344109875392]
[02:27:35.028434] DEBUG RS - deno::module_loader:355 - V8 code cache hit for ES module: https://esm.sh/v135/micromark-factory-title@2.0.0/denonext/micromark-factory-title.mjs, [1788333852662994816]
[02:27:35.028449] DEBUG RS - deno::module_loader:355 - V8 code cache hit for ES module: https://esm.sh/v135/micromark-factory-whitespace@2.0.0/denonext/micromark-factory-whitespace.mjs, [16121474031587361772]
[02:27:35.028465] DEBUG RS - deno::module_loader:355 - V8 code cache hit for ES module: https://esm.sh/v135/micromark-util-html-tag-name@2.0.0/denonext/micromark-util-html-tag-name.mjs, [13637068493040486849]
[02:27:35.028481] DEBUG RS - deno::module_loader:355 - V8 code cache hit for ES module: https://esm.sh/v135/hast-util-parse-selector@4.0.0/denonext/hast-util-parse-selector.mjs, [9064187408373764031]
[02:27:35.037725] ok

Both npm/https specifiers prints about 500-600 lines per run, so I assume they're actually loading the same number of files.

Without that much expertise in the internals of deno, I can't say whether it's an I/O issue related to docker, or if it could be some slowness that may be introduced somehow in the deps resolution, so feel free to close this issue if you think it's probably not deno related