search

Myriad-Dreamin / tinymist

Tinymist [ˈtaɪni mɪst] is an integrated language service for Typst [taɪpst].
https://myriad-dreamin.github.io/tinymist
Apache License 2.0
710 stars 30 forks source link

LSP Server doesn't play well with polylux with regard to memory usage #513

Open memeplex opened 2 months ago

memeplex commented 2 months ago

Describe the bug

This is a continuation of https://github.com/Myriad-Dreamin/tinymist/issues/419

I'm attaching a document that, when previewing, quickly scales tinymist memory usage from 500MB up to, sometimes, 5GB.

The issue is very easy to reproduce for me: just work a bit with the document. But, anyway, I'm providing precise reproduction steps for one instance:

There is nothing too specific to this line, many other changes produce the same or worse effects. Also, refreshing on type accelerates the ramp up.

I've provided more information in #419 from this comment downward.

Archive.zip

Package/Software version:

VSCode version(Help -> About):

Version: 1.92.0 (Universal)
Commit: b1c0a14de1414fcdaa400695b4db1c0799bc3124
Date: 2024-07-31T23:26:45.634Z (1 wk ago)
Electron: 30.1.2
ElectronBuildId: 9870757
Chromium: 124.0.6367.243
Node.js: 20.14.0
V8: 12.4.254.20-electron.0
OS: Darwin arm64 23.4.0

tinymist extension version: v0.11.0. Get it by tinymist --version in terminal.

tinymist 
Build Timestamp:     2024-08-04T19:30:39.635429000Z
Build Git Describe:  v0.11.18
Commit SHA:          fb0a300bc2ef8cfb74a62100441fa4a3f648f4b2
Commit Date:         None
Commit Branch:       None
Cargo Target Triple: aarch64-apple-darwin
Typst Version:       0.11.1

Logs:

tinymist server log(Output Panel -> tinymist):

[2024-08-08T16:14:53Z INFO  tinymist] starting LSP server: LspArgs {
        mirror: MirrorArgs {
            mirror: "",
            replay: "",
        },
        font: CompileFontArgs {
            font_paths: [],
            ignore_system_fonts: false,
        },
    }
[2024-08-08T16:14:53Z INFO  sync_lsp] handling initialize - (0) at Instant { tv_sec: 1694186, tv_nsec: 498865000 }
[2024-08-08T16:14:53Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "onEnterEvent": Bool(true), "outputPath": String(""), "preferredTheme": String("light"), "preview": Object {"cursorIndicator": Bool(false), "fontPaths": Array [], "invertColors": Null, "partialRendering": Bool(true), "pinPreviewFile": Bool(false), "refresh": String("onSave"), "scrollSync": String("onSelectionChangeByMouse"), "showInActivityBar": Bool(false), "sysInputs": Object {}, "systemFonts": Bool(true)}, "previewFeature": String("enable"), "semanticTokens": String("enable"), "systemFonts": Bool(true), "trace": Object {"server": String("off")}, "typstExtraArgs": Array []}
[2024-08-08T16:14:53Z INFO  tinymist::server] LanguageState: initialized with config Config { compile: CompileConfig { roots: ["/Users/carlos/Documents/Repos/ucema-pood"], output_path: PathPattern(""), export_pdf: Never, root_path: None, font_opts: CompileFontArgs { font_paths: [], ignore_system_fonts: false }, system_fonts: Some(true), font_paths: [], fonts: OnceCell(Uninit), notify_status: true, periscope_args: None, typst_extra_args: Some(CompileExtraOpts { root_dir: None, entry: None, inputs: {}, font: CompileFontArgs { font_paths: [], ignore_system_fonts: false }, creation_timestamp: None }), preferred_theme: Some("light"), has_default_entry_path: false, lsp_inputs: {"x-preview": "{\"version\":1,\"theme\":\"light\"}"} }, semantic_tokens: Enable, formatter: Disable, formatter_print_width: 120 }
[2024-08-08T16:14:53Z INFO  tinymist::server] LanguageState: initialized with const_config ConstConfig { position_encoding: Utf16, cfg_change_registration: true, tokens_dynamic_registration: true, tokens_overlapping_token_support: false, tokens_multiline_token_support: false, doc_line_folding_only: true, doc_fmt_dynamic_registration: true }
[2024-08-08T16:14:53Z INFO  tinymist::actor] TypstActor: creating server for primary, entry: Workspace { root: "/Users/carlos/Documents/Repos/ucema-pood", main: None }, inputs: {"x-preview": "{\"version\":1,\"theme\":\"light\"}"}
[2024-08-08T16:14:53Z INFO  tinymist::init] creating SharedFontResolver with CompileFontArgs { font_paths: [], ignore_system_fonts: false }
[2024-08-08T16:14:53Z INFO  sync_lsp] handled  initialize - (0) in 45.11ms
[2024-08-08T16:14:53Z INFO  sync_lsp] notifying initialized - at Instant { tv_sec: 1694186, tv_nsec: 545306666 }
[2024-08-08T16:14:53Z INFO  tinymist::server] server initialized
[2024-08-08T16:14:53Z INFO  sync_lsp] notifing initialized succeeded in 3.65ms
[2024-08-08T16:14:53Z INFO  sync_lsp] handling workspace/executeCommand - (1) at Instant { tv_sec: 1694186, tv_nsec: 548954083 }
[2024-08-08T16:14:53Z INFO  sync_lsp] handled  workspace/executeCommand - (1) in 17.08ms
[2024-08-08T16:14:53Z INFO  sync_lsp] handling workspace/executeCommand - (2) at Instant { tv_sec: 1694186, tv_nsec: 566056083 }
[2024-08-08T16:14:53Z INFO  tinymist::actor::typ_client] the entry file of TypstActor(primary) is changing to Workspace { root: "/Users/carlos/Documents/Repos/ucema-pood", main: Some(/Clase 2 - Intro Proba/slides.typ) }
[2024-08-08T16:14:53Z INFO  tinymist::tool::preview] PreviewTask(4ismcx): arguments: PreviewCliArgs {
        preview: PreviewArgs {
            data_plane_host: "127.0.0.1:0",
            control_plane_host: "",
            enable_partial_rendering: true,
            invert_colors: "never",
            task_id: "4ismcx",
            refresh_style: OnSave,
        },
        compile: CompileOnceArgs {
            input: Some(
                "/Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ",
            ),
            root: None,
            inputs: [],
            font: CompileFontArgs {
                font_paths: [],
                ignore_system_fonts: false,
            },
            creation_timestamp: None,
        },
        preview_mode: Document,
        static_file_host: "127.0.0.1:0",
        not_as_primary: false,
        dont_open_in_browser: false,
    }
[2024-08-08T16:14:53Z INFO  sync_lsp] notifying textDocument/didOpen - at Instant { tv_sec: 1694186, tv_nsec: 567480541 }
[2024-08-08T16:14:53Z INFO  tinymist::server] did open Url { scheme: "file", cannot_be_a_base: false, username: "", password: None, host: None, port: None, path: "/Users/carlos/Documents/Repos/ucema-pood/Clase%202%20-%20Intro%20Proba/slides.typ", query: None, fragment: None }
[2024-08-08T16:14:53Z INFO  typst_preview] Previewer: typst actor spawned
[2024-08-08T16:14:53Z INFO  typst_preview] Data plane server listening on: 127.0.0.1:54008
[2024-08-08T16:14:53Z DEBUG typst_preview::actor::typst] TypstActor: waiting for message
[2024-08-08T16:14:54Z INFO  tinymist::tool::preview] PreviewTask(4ismcx): static file server listening on: 127.0.0.1:54009
[2024-08-08T16:14:54Z INFO  sync_lsp] handled  workspace/executeCommand - (2) in 51.74ms
[2024-08-08T16:14:54Z INFO  tinymist::server] create source: "/Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ"
[2024-08-08T16:14:54Z INFO  sync_lsp] notifing textDocument/didOpen succeeded in 50.53ms
[2024-08-08T16:14:54Z INFO  sync_lsp] handling workspace/executeCommand - (3) at Instant { tv_sec: 1694186, tv_nsec: 618019583 }
[2024-08-08T16:14:54Z INFO  tinymist::cmd] first manual focusing is coming
[2024-08-08T16:14:54Z INFO  sync_lsp] handled  workspace/executeCommand - (3) in 99.31ms
[2024-08-08T16:14:54Z INFO  sync_lsp] handling workspace/executeCommand - (4) at Instant { tv_sec: 1694186, tv_nsec: 717348250 }
[2024-08-08T16:14:54Z INFO  sync_lsp] handled  workspace/executeCommand - (4) in 2.27ms
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/codeAction - (5) at Instant { tv_sec: 1694186, tv_nsec: 719883208 }
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/documentColor - (6) at Instant { tv_sec: 1694186, tv_nsec: 724743333 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/cancelRequest - at Instant { tv_sec: 1694186, tv_nsec: 839363291 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/cancelRequest
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/codeAction - (7) at Instant { tv_sec: 1694186, tv_nsec: 841114333 }
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/foldingRange - (8) at Instant { tv_sec: 1694186, tv_nsec: 867296750 }
[2024-08-08T16:14:54Z INFO  tinymist_query::syntax::lexical_hierarchy] lexical hierarchy analysis took 22.474375ms
[2024-08-08T16:14:54Z INFO  sync_lsp] handled  textDocument/foldingRange - (8) in 93.04ms
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/setTrace - at Instant { tv_sec: 1694187, tv_nsec: 402875125 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/setTrace
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying workspace/didChangeConfiguration - at Instant { tv_sec: 1694187, tv_nsec: 403457833 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifing workspace/didChangeConfiguration succeeded in 23.17ms
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/setTrace - at Instant { tv_sec: 1694187, tv_nsec: 426658666 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/setTrace
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying workspace/didChangeConfiguration - at Instant { tv_sec: 1694187, tv_nsec: 430168125 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifing workspace/didChangeConfiguration succeeded in 65.54µs
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/cancelRequest - at Instant { tv_sec: 1694187, tv_nsec: 430241708 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/cancelRequest
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/codeAction - (9) at Instant { tv_sec: 1694187, tv_nsec: 433354500 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/cancelRequest - at Instant { tv_sec: 1694187, tv_nsec: 434215083 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/cancelRequest
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/codeAction - (10) at Instant { tv_sec: 1694187, tv_nsec: 445348000 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/setTrace - at Instant { tv_sec: 1694187, tv_nsec: 446161916 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/setTrace
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying workspace/didChangeConfiguration - at Instant { tv_sec: 1694187, tv_nsec: 446269166 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifing workspace/didChangeConfiguration succeeded in 145.04µs
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying $/setTrace - at Instant { tv_sec: 1694187, tv_nsec: 446424375 }
[2024-08-08T16:14:54Z WARN  sync_lsp] unhandled notification: $/setTrace
[2024-08-08T16:14:54Z INFO  sync_lsp] notifying workspace/didChangeConfiguration - at Instant { tv_sec: 1694187, tv_nsec: 446533041 }
[2024-08-08T16:14:54Z INFO  sync_lsp] notifing workspace/didChangeConfiguration succeeded in 23.54µs
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/semanticTokens/full - (11) at Instant { tv_sec: 1694187, tv_nsec: 446561500 }
[2024-08-08T16:14:54Z INFO  typst_preview] Peer address: 127.0.0.1:54014
[2024-08-08T16:14:54Z INFO  typst_preview] New WebSocket connection: 127.0.0.1:54014
[2024-08-08T16:14:54Z INFO  sync_lsp] handled  textDocument/semanticTokens/full - (11) in 27.62ms
[2024-08-08T16:14:54Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "fontPaths": Null, "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "hoverPeriscope": Null, "outputPath": String(""), "preferredTheme": String("light"), "rootPath": Null, "semanticTokens": String("enable"), "systemFonts": Bool(true), "typstExtraArgs": Array []}
[2024-08-08T16:14:54Z INFO  tinymist::server] new settings applied
[2024-08-08T16:14:54Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "fontPaths": Null, "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "hoverPeriscope": Null, "outputPath": String(""), "preferredTheme": String("light"), "rootPath": Null, "semanticTokens": String("enable"), "systemFonts": Bool(true), "typstExtraArgs": Array []}
[2024-08-08T16:14:54Z INFO  tinymist::server] new settings applied
[2024-08-08T16:14:54Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "fontPaths": Null, "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "hoverPeriscope": Null, "outputPath": String(""), "preferredTheme": String("light"), "rootPath": Null, "semanticTokens": String("enable"), "systemFonts": Bool(true), "typstExtraArgs": Array []}
[2024-08-08T16:14:54Z INFO  tinymist::server] new settings applied
[2024-08-08T16:14:54Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "fontPaths": Null, "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "hoverPeriscope": Null, "outputPath": String(""), "preferredTheme": String("light"), "rootPath": Null, "semanticTokens": String("enable"), "systemFonts": Bool(true), "typstExtraArgs": Array []}
[2024-08-08T16:14:54Z INFO  tinymist::server] new settings applied
[2024-08-08T16:14:54Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:54Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:54Z DEBUG typst_preview::actor::render] RenderActor: has_full_render: true
[2024-08-08T16:14:54Z INFO  typst_preview::actor::render] RenderActor: document is not ready
[2024-08-08T16:14:54Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:54Z DEBUG typst_preview::actor::render] OutlineRenderActor: received message: RenderFullLatest
[2024-08-08T16:14:54Z INFO  typst_preview::actor::render] OutlineRenderActor: document is not ready
[2024-08-08T16:14:54Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:54Z INFO  sync_lsp] handling textDocument/codeLens - (12) at Instant { tv_sec: 1694187, tv_nsec: 491468666 }
[2024-08-08T16:14:55Z INFO  sync_lsp] notifying $/setTrace - at Instant { tv_sec: 1694188, tv_nsec: 27277083 }
[2024-08-08T16:14:55Z WARN  sync_lsp] unhandled notification: $/setTrace
[2024-08-08T16:14:55Z INFO  sync_lsp] notifying workspace/didChangeConfiguration - at Instant { tv_sec: 1694188, tv_nsec: 27308083 }
[2024-08-08T16:14:55Z INFO  sync_lsp] notifing workspace/didChangeConfiguration succeeded in 63.25µs
[2024-08-08T16:14:55Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "fontPaths": Null, "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "hoverPeriscope": Null, "outputPath": String(""), "preferredTheme": String("light"), "rootPath": Null, "semanticTokens": String("enable"), "systemFonts": Bool(true), "typstExtraArgs": Array []}
[2024-08-08T16:14:55Z INFO  tinymist::server] new settings applied
[2024-08-08T16:14:56Z INFO  tinymist::actor::editor] received status request(primary) Compiling
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/documentColor - (6) in 1.96s
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeAction - (7) in 1.85s
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeAction - (10) in 1.24s
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeAction - (5) in 1.98s
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeAction - (9) in 1.27s
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeLens - (12) in 1.23s
[2024-08-08T16:14:56Z INFO  sync_lsp] handling textDocument/codeAction - (13) at Instant { tv_sec: 1694188, tv_nsec: 833884583 }
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeAction - (13) in 752.75µs
[2024-08-08T16:14:56Z INFO  typst_preview::actor::webview] WebviewActor: received non-text message from websocket: Close(Some(CloseFrame { code: Away, reason: "" }))
[2024-08-08T16:14:56Z INFO  typst_preview::actor::webview] WebviewActor: exiting
[2024-08-08T16:14:56Z INFO  sync_lsp] handling workspace/executeCommand - (14) at Instant { tv_sec: 1694189, tv_nsec: 184149791 }
[2024-08-08T16:14:56Z INFO  tinymist::cmd] file pinned: None
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  workspace/executeCommand - (14) in 23.13µs
[2024-08-08T16:14:56Z INFO  sync_lsp] handling workspace/executeCommand - (15) at Instant { tv_sec: 1694189, tv_nsec: 184180833 }
[2024-08-08T16:14:56Z INFO  tinymist::actor::preview] PreviewTask(4ismcx): killing
[2024-08-08T16:14:56Z INFO  tinymist::actor::preview] PreviewTask(4ismcx): wait for previewer to stop
[2024-08-08T16:14:56Z INFO  tinymist::tool::preview] Static file server joined
[2024-08-08T16:14:56Z INFO  typst_preview] Data plane server shutdown
[2024-08-08T16:14:56Z INFO  typst_preview::actor::editor] EditorActor: received exit message
[2024-08-08T16:14:56Z INFO  typst_preview::actor::editor] EditorActor: editor disconnected
[2024-08-08T16:14:56Z INFO  typst_preview] Control plane client shutdown
[2024-08-08T16:14:56Z INFO  tinymist::tool::preview] PreviewTask(4ismcx): response channel closed
[2024-08-08T16:14:56Z INFO  tinymist::actor::preview] PreviewTask(4ismcx): wait for static server to stop
[2024-08-08T16:14:56Z INFO  tinymist::actor::preview] PreviewTask(4ismcx): killed
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  workspace/executeCommand - (15) in 1.19ms
[2024-08-08T16:14:56Z INFO  sync_lsp] handling textDocument/codeAction - (16) at Instant { tv_sec: 1694189, tv_nsec: 321557291 }
[2024-08-08T16:14:56Z INFO  sync_lsp] handling textDocument/documentSymbol - (17) at Instant { tv_sec: 1694189, tv_nsec: 321637791 }
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/codeAction - (16) in 7.98ms
[2024-08-08T16:14:56Z INFO  tinymist_query::syntax::lexical_hierarchy] lexical hierarchy analysis took 9.881667ms
[2024-08-08T16:14:56Z INFO  sync_lsp] handled  textDocument/documentSymbol - (17) in 25.33ms
[2024-08-08T16:14:56Z INFO  sync_lsp] notifying $/setTrace - at Instant { tv_sec: 1694189, tv_nsec: 346983875 }
[2024-08-08T16:14:56Z WARN  sync_lsp] unhandled notification: $/setTrace
[2024-08-08T16:14:56Z INFO  sync_lsp] notifying workspace/didChangeConfiguration - at Instant { tv_sec: 1694189, tv_nsec: 361129000 }
[2024-08-08T16:14:56Z INFO  sync_lsp] notifing workspace/didChangeConfiguration succeeded in 29.38µs
[2024-08-08T16:14:56Z INFO  tinymist::init] preferred theme: Some("light") {"compileStatus": String("enable"), "exportPdf": String("never"), "fontPaths": Null, "formatterMode": String("disable"), "formatterPrintWidth": Number(120), "hoverPeriscope": Null, "outputPath": String(""), "preferredTheme": String("light"), "rootPath": Null, "semanticTokens": String("enable"), "systemFonts": Bool(true), "typstExtraArgs": Array []}
[2024-08-08T16:14:56Z INFO  tinymist::server] new settings applied
[2024-08-08T16:14:58Z INFO  sync_lsp] handling workspace/executeCommand - (18) at Instant { tv_sec: 1694190, tv_nsec: 633002375 }
[2024-08-08T16:14:58Z INFO  tinymist::tool::preview] PreviewTask(lm8a1f): arguments: PreviewCliArgs {
        preview: PreviewArgs {
            data_plane_host: "127.0.0.1:0",
            control_plane_host: "",
            enable_partial_rendering: true,
            invert_colors: "never",
            task_id: "lm8a1f",
            refresh_style: OnSave,
        },
        compile: CompileOnceArgs {
            input: Some(
                "/Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ",
            ),
            root: None,
            inputs: [],
            font: CompileFontArgs {
                font_paths: [],
                ignore_system_fonts: false,
            },
            creation_timestamp: None,
        },
        preview_mode: Document,
        static_file_host: "127.0.0.1:0",
        not_as_primary: false,
        dont_open_in_browser: false,
    }
[2024-08-08T16:14:58Z INFO  typst_preview] Previewer: typst actor spawned
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::typst] TypstActor: waiting for message
[2024-08-08T16:14:58Z INFO  typst_preview] Data plane server listening on: 127.0.0.1:54044
[2024-08-08T16:14:58Z INFO  tinymist::tool::preview] PreviewTask(lm8a1f): static file server listening on: 127.0.0.1:54045
[2024-08-08T16:14:58Z INFO  sync_lsp] handled  workspace/executeCommand - (18) in 3.12ms
[2024-08-08T16:14:58Z INFO  sync_lsp] handling workspace/executeCommand - (19) at Instant { tv_sec: 1694190, tv_nsec: 688287500 }
[2024-08-08T16:14:58Z INFO  sync_lsp] handled  workspace/executeCommand - (19) in 34.33µs
[2024-08-08T16:14:58Z INFO  typst_preview] Peer address: 127.0.0.1:54046
[2024-08-08T16:14:58Z INFO  typst_preview] New WebSocket connection: 127.0.0.1:54046
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::render] RenderActor: has_full_render: true
[2024-08-08T16:14:58Z INFO  typst_preview::actor::render] RenderActor: document is not ready
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::render] OutlineRenderActor: received message: RenderFullLatest
[2024-08-08T16:14:58Z INFO  typst_preview::actor::render] OutlineRenderActor: document is not ready
[2024-08-08T16:14:58Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:59Z INFO  typst_ts_compiler::diag::console] Some(/Clase 2 - Intro Proba/slides.typ): compilation succeeded in 2.989453s
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received diagnostics from primary:5: diag(Some(0))
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received status request(primary) CompileSuccess
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] RenderActor: has_full_render: false
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: received message: RenderIncremental
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: sending outline
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received status request(primary) Compiling
[2024-08-08T16:14:59Z INFO  tinymist::task::cache] CacheEvictTask: evict cache in 171.972ms
[2024-08-08T16:14:59Z INFO  typst_ts_compiler::diag::console] Some(/Clase 2 - Intro Proba/slides.typ): compilation succeeded in 251.414ms
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received diagnostics from primary:6: diag(Some(0))
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received status request(primary) CompileSuccess
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: received message: RenderIncremental
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: sending outline
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] RenderActor: has_full_render: false
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received status request(primary) Compiling
[2024-08-08T16:14:59Z INFO  tinymist::task::cache] CacheEvictTask: evict cache in 5.644708ms
[2024-08-08T16:14:59Z INFO  typst_ts_compiler::diag::console] Some(/Clase 2 - Intro Proba/slides.typ): compilation succeeded in 221.859ms
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received diagnostics from primary:7: diag(Some(0))
[2024-08-08T16:14:59Z INFO  tinymist::actor::editor] received status request(primary) CompileSuccess
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: received message: RenderIncremental
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] RenderActor: has_full_render: false
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: sending outline
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] OutlineRenderActor: waiting for message
[2024-08-08T16:14:59Z DEBUG typst_preview::actor::render] RenderActor: waiting for message
[2024-08-08T16:14:59Z INFO  tinymist::task::cache] CacheEvictTask: evict cache in 6.830584ms
[2024-08-08T16:15:00Z INFO  sync_lsp] handling workspace/executeCommand - (20) at Instant { tv_sec: 1694193, tv_nsec: 439417625 }
[2024-08-08T16:15:00Z INFO  sync_lsp] handled  workspace/executeCommand - (20) in 144.96µs
[2024-08-08T16:15:00Z INFO  sync_lsp] handling workspace/executeCommand - (21) at Instant { tv_sec: 1694193, tv_nsec: 462308166 }
[2024-08-08T16:15:00Z INFO  sync_lsp] handled  workspace/executeCommand - (21) in 969.67µs
[2024-08-08T16:15:00Z DEBUG typst_preview::actor::editor] EditorActor: received message from editor: SrcToDocJumpRequest { filepath: "/Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ", line: 126, character: 16 }
[2024-08-08T16:15:00Z DEBUG typst_preview::actor::typst] TypstActor: processing src2doc: SrcToDocJumpRequest { filepath: "/Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ", line: 126, character: 16 }
[2024-08-08T16:15:00Z INFO  tinymist::actor::editor] received status request(primary) Compiling
[2024-08-08T16:15:01Z INFO  sync_lsp] handling textDocument/codeAction - (22) at Instant { tv_sec: 1694193, tv_nsec: 741220125 }
[2024-08-08T16:15:01Z INFO  sync_lsp] handled  textDocument/codeAction - (22) in 380.04µs
[2024-08-08T16:15:01Z INFO  typst_ts_compiler::diag::console] Some(/Clase 2 - Intro Proba/slides.typ): compilation succeeded in 310.612ms
[2024-08-08T16:15:01Z INFO  tinymist::actor::typ_client] TypstActor: already notified for revision 7 <= 7
[2024-08-08T16:15:02Z INFO  sync_lsp] handling textDocument/codeLens - (23) at Instant { tv_sec: 1694194, tv_nsec: 704961125 }
[2024-08-08T16:15:02Z INFO  sync_lsp] handled  textDocument/codeLens - (23) in 281.92µs
[2024-08-08T16:15:02Z INFO  sync_lsp] handling workspace/executeCommand - (24) at Instant { tv_sec: 1694194, tv_nsec: 882566875 }
[2024-08-08T16:15:02Z INFO  sync_lsp] handled  workspace/executeCommand - (24) in 33.92µs

tinymist client log(Help -> Toggle Developer Tools -> Console):

workbench.desktop.main.js:sourcemap:660  INFO Started local extension host with pid 36181.
2workbench.desktop.main.js:sourcemap:97 [Extension Host] determineVscodeTheme 1
workbench.desktop.main.js:sourcemap:97 [Extension Host] vscodeVariables test: Object
workbench.desktop.main.js:sourcemap:97 [Extension Host] validate /Users/carlos/.vscode/extensions/myriad-dreamin.tinymist-0.11.18-darwin-arm64/out/tinymist args Array(1)
workbench.desktop.main.js:sourcemap:97 [Extension Host] deserializeWebviewPanel Object
workbench.desktop.main.js:sourcemap:97 [Extension Host] Preview Command /Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ
workbench.desktop.main.js:sourcemap:97 [Extension Host] Launched preview, data plane port:54008, static server port:54009
workbench.desktop.main.js:sourcemap:1509 An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing.
mountTo @ workbench.desktop.main.js:sourcemap:1509
8workbench.desktop.main.js:sourcemap:97 [Extension Host] determineVscodeTheme 1
workbench.desktop.main.js:sourcemap:660  WARN Semantic token with invalid length detected at lineNumber 2, column 1
workbench.desktop.main.js:sourcemap:660  WARN Overlapping semantic tokens detected at lineNumber 107, column 51
2workbench.desktop.main.js:sourcemap:97 [Extension Host] determineVscodeTheme 1
workbench.desktop.main.js:sourcemap:97 [Extension Host] killed preview services
workbench.desktop.main.js:sourcemap:97 [Extension Host] No dispose function found for task 4ismcx
y @ workbench.desktop.main.js:sourcemap:97
2workbench.desktop.main.js:sourcemap:97 [Extension Host] determineVscodeTheme 1
workbench.desktop.main.js:sourcemap:660  INFO [perf] Render performance baseline is 18ms
workbench.desktop.main.js:sourcemap:97 [Extension Host] Preview Command /Users/carlos/Documents/Repos/ucema-pood/Clase 2 - Intro Proba/slides.typ
workbench.desktop.main.js:sourcemap:97 [Extension Host] Launched preview, data plane port:54044, static server port:54045
workbench.desktop.main.js:sourcemap:1509 An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing.
mountTo @ workbench.desktop.main.js:sourcemap:1509
VM12:12 state eyJtb2RlIjoiZG9jIiwiYXNQcmltYXJ5IjpmYWxzZSwidXJpIjoiZmlsZTovLy9Vc2Vycy9jYXJsb3MvRG9jdW1lbnRzL1JlcG9zL3VjZW1hLXBvb2QvQ2xhc2UlMjAyJTIwLSUyMEludHJvJTIwUHJvYmEvc2xpZGVzLnR5cCJ9
VM12:16 vscode_state Object
VM13:5842 plugin initialized, build info: Object
VM13:5728 WebSocket connection opened WebSocket
VM13:5763 batch 2 messages
VM13:5784 recv partial-rendering 22
VM13:5821 Experimental feature: partial rendering enabled
VM13:5784 recv invert-colors 19
VM13:5827 Experimental feature: invert colors strategy taken: never
VM13:5763 batch 2 messages
VM13:5784 recv diff-v1 1181356
VM13:5784 recv diff-v1 1180
VM13:1387 render_in_window with partial rendering enabled window 1.3134025776070106 0 34.148467017782274 840.5776496684869 593.6579650783688 , patch scale 174644
VM13:368 parse 10.10 ms, rerender 17.00 ms, total 27.10 ms
VM13:1830 updateCanvas start
VM13:1862 updateCanvas one miss undefined cMphHzh72sHE7Cticoyk8u0
VM13:1862 updateCanvas one miss undefined c5Ccgscw4bkoJFHfAKCenIY
VM13:1862 updateCanvas one miss undefined cWj8PnyKDbssBCwa+FnNpgw
VM13:1862 updateCanvas one miss undefined c5JO94mfeNU8OZzvQd6Rcks
VM13:1862 updateCanvas one miss undefined cK5B8RVf7NNoMvsGW+A/YjE
VM13:1862 updateCanvas one miss undefined cQTXreka19zImCaygRHeBNY
VM13:1862 updateCanvas one miss undefined cgwyv++uFnJQLkhTLzIBZ7M
VM13:1862 updateCanvas one miss undefined cINgxPy05utEMli1sXfuZ2Q
VM13:1862 updateCanvas one miss undefined cGQ9nbssnHncOOoyyTHftEk
VM13:1862 updateCanvas one miss undefined cHMG1E1wjl+UBABZTtv4vw8
VM13:5763 batch 1 messages
VM13:5784 recv diff-v1 1180
VM13:1387 render_in_window with partial rendering enabled window 1.313572542901716 0 34.152886115444616 840.6864274570983 593.7347893915756 , patch scale 8719
VM13:1666 cancel canvas rendering
VM13:368 parse 0.20 ms, rerender 4.70 ms, total 4.90 ms
VM13:1845 updateCanvas cancelled 179.70000004768372
VM13:1830 updateCanvas start
VM13:1862 updateCanvas one miss undefined cakK2tU0Y4gUVj14f9HgnkQ
VM13:1862 updateCanvas one miss undefined cCmcIZzNAYAcG8eU+6NDknE
VM13:1862 updateCanvas one miss undefined c/3KGXfp80X8SkWtGHo6y/I
VM13:1862 updateCanvas one miss undefined ci34qkdegmYkZHfmCpdX1NA
VM13:1862 updateCanvas one miss undefined cyyR1WZSG2lozh9C7QfAczo
VM13:1862 updateCanvas one miss undefined c53YEjl7oeTsFTIkCZS/BlM
VM13:1862 updateCanvas one miss undefined clPdoKK7AGDc3pFZVkqFhMQ
VM13:1862 updateCanvas one miss undefined cbRBl2JUOvM4bVnwoIuxcBI
VM13:1862 updateCanvas one miss undefined cbLo3rztPQTAl3fJgtclVsU
VM13:1862 updateCanvas one miss undefined cciA4CTVWVqEZDViwaluCZ8
VM13:1862 updateCanvas one miss undefined ce2hf7D/NOVcmeOqHLr9ANY
VM13:1862 updateCanvas one miss undefined c7b+Pj7dl24k93nP8HTVK9I
VM13:1862 updateCanvas one miss undefined c1oYHrVmDZIwUXAdGxUBoaw
VM13:1862 updateCanvas one miss undefined cpmsXLXUgM3U5jpsX7S8TCA
VM13:1862 updateCanvas one miss undefined ctoQFUcTrJ2IlrK8OVr3GQ8
VM13:1862 updateCanvas one miss undefined cldDfC2jEXzwokDfDUBWGF8
VM13:1862 updateCanvas one miss undefined cK5XIMHJQ50QRVpNz+09cwE
VM13:1862 updateCanvas one miss undefined cHtcpZkMGU3801YaVzOdp84
VM13:1862 updateCanvas one miss undefined cy9DawkfqvugFlY5d6h32Bg
VM13:1862 updateCanvas one miss undefined c6v+zkY7WXyMQ2RuF5K//k0
VM13:1862 updateCanvas one miss undefined cwI78lyWmmoMXFs4J700TmM
VM13:1862 updateCanvas one miss undefined cVe65U7XTi0AGM7r6nzqQz0
VM13:1862 updateCanvas one miss undefined cf8g+eUeSynczjkuvnYIPn4
VM13:1862 updateCanvas one miss undefined chdDbde7oZEQSNAWEAmhq7M
VM13:1862 updateCanvas one miss undefined ctCxzZGl1euk/0RgwQtY3b0
VM13:1862 updateCanvas one miss undefined cTLfWrISPaGwIzC9mjlV8rE
VM13:1862 updateCanvas one miss undefined ceAxNCH8gNMUruPkGC51eIs
VM13:1862 updateCanvas one miss undefined cauW4NEZ7Jbg1wYUWUezYqY
VM13:1862 updateCanvas one miss undefined cuXmrEQ5JXnc1CTkQQ9XvFc
VM13:1862 updateCanvas one miss undefined cBbGQGDdYhvkSfD8pDl/jXc
VM13:1870 updateCanvas done 759.0999999046326
2workbench.desktop.main.js:sourcemap:97 [Extension Host] skip extension-output file extension-output-myriad-dreamin.tinymist-#1-Tinymist Typst Language Server
VM13:1387 render_in_window with partial rendering enabled window 2.319559228650138 0 60.308539944903586 839.6804407713499 1048.4407713498624 , patch scale 132317
VM13:368 parse 0.10 ms, rerender 19.20 ms, total 19.30 ms
VM13:1830 updateCanvas start
memeplex commented 2 months ago

I've been investigating this. I'm quite sure the problem is in Polylux, specifically in #let polylux-slide(max-repetitions: 10, body) in logic.typ. Just change the number of iterations first to 1 and then to 100 and you will see the opposite reactions in terms of memory usage. Perhaps it's memoizing a lot of stuff because of the frequent state updates (and maybe you need some cache eviction policy or something like that). And this while I'm not using any dynamic feature at all! Also, from a cursory look, logical-slide.step() seems to be ever increasing.

memeplex commented 2 months ago

It may be that when adding/removing one slide, specially one near the top, the logical-slide count increases/decreases for all the following ones (since there is one more/less state update above them), so a large part of the document gets invalidated, and each one of the slides there has to do the ten iterations dance again. An effect like this will be particularly evident when refreshing the preview on type, I guess, since the document is changing and broken half of the time, although other parts of the LSP may be as well affected. This is arguably not desirable, but if possible tinymist should deal with the situation in a more robust fashion (without scaling memory usage to quite a few GB).

Myriad-Dreamin commented 2 months ago

Thanks for investigation. Both can do better from the result.

Alternative solution: From view of performance, touying should do much better, though I haven't use it. I only maintained some deadly-simple polylux slides so I didn't go in depth of optimizing lsp for polylux.

memeplex commented 2 months ago

Ok, thanks, I'm already looking into touying or just a "hand-made" slideshow template. So, to recap, the most reliable way to reproduce this is to change max-repetitions to 100 in logic.typ, restart the extension host and boom. You don't even need to open the previewer. I guess having that multiplier there is equivalent to having a large document with page numbers in the footer, the would require almost full renumbering if you added or removed a line from a page near the beginning. One can't blame polylux on keeping the logical-slide count, although the way it then iterates over each slide certainly doesn't seem to help a memoization strategy. Even worse, a long-running, incremental one, that may be keeping lots of stale data from one moment to the next. Moreover, the fact that each slide is wrapped inside a polylux function that is wrapped inside a theme function that is wrapped inside an end-user function, may be hard on the caching strategy if it works at the function call level, but I'm just guessing.

memeplex commented 2 months ago

Also be aware that in the development branch they removed the max-iterations logic and are now iterating as required for each slide https://github.com/andreasKroepelin/polylux/blob/main/logic.typ. Although according to the commit history the motivation for the change was not optimization but getting rid of an artificial limit. So please use the same polylux version than me in order to reproduce the issue, which is the current stable one.

mattyoung101 commented 2 months ago

I don't think the problem is limited to Polylux. Tinymist is currently using 8.9 GB of RAM for a relatively simple 19 slide presentation designed with Touying, and I've seen it reach ~5 GB for standard non-presentation documents as well.

This is on Tinymist v0.11.19, Neovim v0.10.1, Arch Linux, all default settings, installed using Mason/lspconfig.

Let me know if you need any extra specs/logs. I would like to profile this, but I don't have any Rust memory profiling experience or a lot of time unfortunately. Would Valgrind be the go?

memeplex commented 2 months ago

It would be great to track this down to a minimal document without external dependencies. I didn't have the time yet but the example of polylux with regard to the number of iterations may be a good lead.

Enter-tainer commented 2 months ago

Another take is that we may want to know who's fault it is in this case. If it already takes a lot of RAM when using typst watch, tinymist cannot do much to prevent this.

mattyoung101 commented 2 months ago

Still working on a reliable way to reproduce this - on my laptop which has the exact same software config as my desktop, I can't reliably get a Touying presentation to trigger the RAM usage issue. However, I was able to use another document (~17 pages) to use ~4 GB of RAM using Tinymist, whereas typst watch uses only ~108 MB.

Using /usr/bin/time -v typst watch <document>.typ to report max resident RAM, I get:

        Command being timed: "typst watch <document>.typ"
        User time (seconds): 0.86
        System time (seconds): 0.22
        Percent of CPU this job got: 2%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:42.94
        Average shared text size (kbytes): 0
        Average unshared data size (kbytes): 0
        Average stack size (kbytes): 0
        Average total size (kbytes): 0
        Maximum resident set size (kbytes): 108156
        Average resident set size (kbytes): 0
        Major (requiring I/O) page faults: 0
        Minor (reclaiming a frame) page faults: 26842
        Voluntary context switches: 254
        Involuntary context switches: 19
        Swaps: 0
        File system inputs: 0
        File system outputs: 3736
        Socket messages sent: 0
        Socket messages received: 0
        Signals delivered: 0
        Page size (bytes): 4096
        Exit status: 0

So typst watch uses ~108 MB of RAM, whereas Tinymist uses ~4 GB.

edit: I should also note this is with previewing disabled in the Tinymist LSP config.

Zeratoxx commented 2 months ago

yup, I'm sitting here with 10.8 GB RAM usage of tinymist, only change I did was configuring "onSave" trigger instead of "onType"..

image

I miss an option to configure the delay for the LSP update.. I don't want to fire an update with EACH character I type

Myriad-Dreamin commented 1 month ago

I have checked it again and find nothing new. I performed following steps:

  1. clear caches, memory goes to 400MB ~ 500MB.
  2. negate some editions repeatedly, memory keeps in 600MB ~ 1000MB.
  3. clear caches, memory goes to 400MB ~ 500MB.

https://github.com/user-attachments/assets/783943a3-5e78-4982-9acb-2fbb4c165dff

The only difference between typst-cli and tinymist I can remeber soonly is this arguments, the max age of cache. This number won't be exported as setting, to prevent bad settings. But If somebody have interest, they could build tinymist from source and turns down the number for experiment. For performance concerning tinymist definitely needs higher max age, but it is arguable. Btw, tinymist was petty laggy when I followed the setting of typst-cli.

https://github.com/Myriad-Dreamin/tinymist/blob/main/crates/tinymist/src/task/cache.rs#L14

memeplex commented 1 month ago

I still have building a minimal example in my TODO list, but have you tried increasing the number of repetitions of polylux as described in https://github.com/Myriad-Dreamin/tinymist/issues/513#issuecomment-2279680018? That's a reliable way of moving into the zone of a handful of GB.

Myriad-Dreamin commented 1 month ago

but have you tried increasing the number of repetitions of polylux as described in https://github.com/Myriad-Dreamin/tinymist/issues/513#issuecomment-2279680018?

I have increased it, and this is the result.

DHAT Viewer - dhat-heap.json - Total (blocks).zip

  1. 20% of memory are used by allocating std::Vec<T>. When tinymist uses most memory, 43% of memory (1.5GB) are held by std::Vec<T>.
  2. 71% of memory are directly allocated by typst::compile and about 6% of memory is directly allocated by tinymist_query.
Zeratoxx commented 1 month ago

For anyone who is wondering on what max-repetitions is about:

You may want to create slides in which the content gets revealed one by one (for example). Because polylux bases on typst which produces PDF results, this cannot be animated, instead, there need to be a separated PDF page per "step", so called subslides.

The maximum amount of these subslides can be configured by max-repetitions, the default is 10. This setting tells the compiler, how many times it should repeat the compilation for each slide.

Source: Polylux Docs: Dynamic Slides - Internals

TL;DR: max-repetitions sets the maximum amount of so called subslides