Closed Enivex closed 9 months ago
Been getting this on the latest versions too. I don't know exactly how to reproduce it, but it seems to only happen sometimes, apparently while I'm still typing something (and thus while there might be syntax errors for a very brief period), but I'm not too sure. Here's a larger stack trace:
thread 'main' panicked at 'span should be in source since we got it using the span', src/lsp_typst_boundary.rs:240:14
stack backtrace:
0: rust_begin_unwind
at /rustc/eb26296b556cef10fb713a38f3d16b9886080f26/library/std/src/panicking.rs:593:5
1: core::panicking::panic_fmt
at /rustc/eb26296b556cef10fb713a38f3d16b9886080f26/library/core/src/panicking.rs:67:14
2: core::panicking::panic_display
at /rustc/eb26296b556cef10fb713a38f3d16b9886080f26/library/core/src/panicking.rs:150:5
3: core::panicking::panic_str
at /rustc/eb26296b556cef10fb713a38f3d16b9886080f26/library/core/src/panicking.rs:134:5
4: core::option::expect_failed
at /rustc/eb26296b556cef10fb713a38f3d16b9886080f26/library/core/src/option.rs:1932:5
5: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
6: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
7: <S as futures_core::stream::TryStream>::try_poll_next
8: <futures_util::stream::stream::map::Map<St,F> as futures_core::stream::Stream>::poll_next
9: <futures_util::stream::stream::filter_map::FilterMap<St,Fut,F> as futures_core::stream::Stream>::poll_next
10: <futures_util::stream::stream::collect::Collect<St,C> as core::future::future::Future>::poll
11: typst_lsp::server::typst_compiler::<impl typst_lsp::server::TypstServer>::eval_source::{{closure}}::{{closure}}
12: typst_lsp::server::typst_compiler::<impl typst_lsp::server::TypstServer>::eval_source::{{closure}}
13: typst_lsp::server::document::<impl typst_lsp::server::TypstServer>::on_source_changed::{{closure}}
14: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
15: typst_lsp::server::lsp::<impl tower_lsp::LanguageServer for typst_lsp::server::TypstServer>::did_change::{{closure}}
16: tower_lsp::jsonrpc::router::Router<S,E>::method::{{closure}}::{{closure}}::{{closure}}
17: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
18: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
19: <core::pin::Pin<P> as core::future::future::Future>::poll
20: <core::pin::Pin<P> as core::future::future::Future>::poll
21: <tower_lsp::service::LspService<S> as tower_service::Service<tower_lsp::jsonrpc::request::Request>>::call::{{closure}}
22: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
23: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as futures_core::stream::Stream>::poll_next
24: <futures_util::stream::stream::buffer_unordered::BufferUnordered<St> as futures_core::stream::Stream>::poll_next
25: <futures_util::stream::stream::filter_map::FilterMap<St,Fut,F> as futures_core::stream::Stream>::poll_next
26: <futures_util::stream::stream::forward::Forward<St,Si,Item> as core::future::future::Future>::poll
27: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
28: <futures_util::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
29: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
30: tokio::runtime::park::CachedParkThread::block_on
31: tokio::runtime::context::runtime::enter_runtime
32: tokio::runtime::runtime::Runtime::block_on
33: typst_lsp::main
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Still crashing, but I also got a new error
[Info - 1:58:55 PM] src\workspace\package\external\manager.rs:58 { message = got external package cache; cache = LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }; }
[Info - 1:58:55 PM] src\workspace\package\external\manager.rs:48 { message = got user external package directory; user = LocalProvider { root: "C:\\Users\\krist\\AppData\\Roaming\\typst/packages/" }; }
[Info - 1:58:55 PM] src\workspace\package\manager.rs:42 { message = initialized package manager; current = {Url { scheme: "file", cannot_be_a_base: false, username: "", password: None, host: None, port: None, path: "/c%3A/Users/krist/Documents/GitHub/Thesis-reports", query: None, fragment: None }: Package { root: "file:///c%3A/Users/krist/Documents/GitHub/Thesis-reports" }}; external = ExternalPackageManager { providers: [LocalProvider { root: "C:\\Users\\krist\\AppData\\Roaming\\typst/packages/" }, LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }], cache: Some(LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }), repo: Some(RemoteRepoProvider { base_url: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("packages.typst.org")), port: None, path: "/", query: None, fragment: None }, client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"}, timeout: 30s } }) }; }
thread '<unnamed>' panicked at 'called `Option::unwrap()` on a `None` value', C:\Users\runneradmin\.cargo\git\checkouts\typst-6808799b0d8fdaa9\da8367e\crates\typst\src\model\content.rs:444:29
stack backtrace:
[Info - 1:58:55 PM] src\server\lsp.rs:185 { message = server initialized; }
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: RecvError(())', src\workspace\world\typst_thread.rs:71:24
stack backtrace:
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
[Error - 1:58:55 PM] The Typst Language Server server crashed 5 times in the last 3 minutes. The server will not be restarted. See the output for more information.
I'm not sure why there's a "C:\Users\runneradmin" there. No such user exists
Still crashing, but I also got a new error
[Info - 1:58:55 PM] src\workspace\package\external\manager.rs:58 { message = got external package cache; cache = LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }; } [Info - 1:58:55 PM] src\workspace\package\external\manager.rs:48 { message = got user external package directory; user = LocalProvider { root: "C:\\Users\\krist\\AppData\\Roaming\\typst/packages/" }; } [Info - 1:58:55 PM] src\workspace\package\manager.rs:42 { message = initialized package manager; current = {Url { scheme: "file", cannot_be_a_base: false, username: "", password: None, host: None, port: None, path: "/c%3A/Users/krist/Documents/GitHub/Thesis-reports", query: None, fragment: None }: Package { root: "file:///c%3A/Users/krist/Documents/GitHub/Thesis-reports" }}; external = ExternalPackageManager { providers: [LocalProvider { root: "C:\\Users\\krist\\AppData\\Roaming\\typst/packages/" }, LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }], cache: Some(LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }), repo: Some(RemoteRepoProvider { base_url: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("packages.typst.org")), port: None, path: "/", query: None, fragment: None }, client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"}, timeout: 30s } }) }; } thread '<unnamed>' panicked at 'called `Option::unwrap()` on a `None` value', C:\Users\runneradmin\.cargo\git\checkouts\typst-6808799b0d8fdaa9\da8367e\crates\typst\src\model\content.rs:444:29 stack backtrace: [Info - 1:58:55 PM] src\server\lsp.rs:185 { message = server initialized; } note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace. thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: RecvError(())', src\workspace\world\typst_thread.rs:71:24 stack backtrace: note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace. [Error - 1:58:55 PM] The Typst Language Server server crashed 5 times in the last 3 minutes. The server will not be restarted. See the output for more information.
I'm not sure why there's a "C:\Users\runneradmin" there. No such user exists
Did you encounter the panic below when typing the name of a function or a keyword (leading to incomplete and undefined symbol) ?
[Info - 23:02:07] src\server\lsp.rs:185 { message = server initialized; }
thread 'main' panicked at 'span should be in source since we got it using the span', src\lsp_typst_boundary.rs:240:14
stack backtrace:
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
[Info - 23:02:08] Connection to server got closed. Server will restart.
Did you encounter the panic below when typing the name of a function or a keyword (leading to incomplete and undefined symbol) ?
Yes
(Which means the LSP crashes almost immediately)
Still crashing, but I also got a new error
[Info - 1:58:55 PM] src\workspace\package\external\manager.rs:58 { message = got external package cache; cache = LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }; } [Info - 1:58:55 PM] src\workspace\package\external\manager.rs:48 { message = got user external package directory; user = LocalProvider { root: "C:\\Users\\krist\\AppData\\Roaming\\typst/packages/" }; } [Info - 1:58:55 PM] src\workspace\package\manager.rs:42 { message = initialized package manager; current = {Url { scheme: "file", cannot_be_a_base: false, username: "", password: None, host: None, port: None, path: "/c%3A/Users/krist/Documents/GitHub/Thesis-reports", query: None, fragment: None }: Package { root: "file:///c%3A/Users/krist/Documents/GitHub/Thesis-reports" }}; external = ExternalPackageManager { providers: [LocalProvider { root: "C:\\Users\\krist\\AppData\\Roaming\\typst/packages/" }, LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }], cache: Some(LocalProvider { root: "C:\\Users\\krist\\AppData\\Local\\typst/packages/" }), repo: Some(RemoteRepoProvider { base_url: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("packages.typst.org")), port: None, path: "/", query: None, fragment: None }, client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"}, timeout: 30s } }) }; } thread '<unnamed>' panicked at 'called `Option::unwrap()` on a `None` value', C:\Users\runneradmin\.cargo\git\checkouts\typst-6808799b0d8fdaa9\da8367e\crates\typst\src\model\content.rs:444:29 stack backtrace: [Info - 1:58:55 PM] src\server\lsp.rs:185 { message = server initialized; } note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace. thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: RecvError(())', src\workspace\world\typst_thread.rs:71:24 stack backtrace: note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace. [Error - 1:58:55 PM] The Typst Language Server server crashed 5 times in the last 3 minutes. The server will not be restarted. See the output for more information.
I'm not sure why there's a "C:\Users\runneradmin" there. No such user exists
It is probably the user name of GitHub CI :D.
Looking at the code, it looks like there are multiple await points between compilation and conversion of Typst spans into LSP ranges. I have no idea whether this is actually the problem, but I wonder whether the source file could change during those awaits, leading to a lookup of an invalidated span.
The traceback also shows the error occuring in eval_source
, where the diagnostics conversion happen outside of run
(and thus in a different thread than compilation) whereas in compile_source
the conversion happens inside of run2
(and thus in the compiler thread). This seems strange to me.
I think I have identified the cause of the upstream Typst issue #2035. It's quite probable that this is also the root cause of this issue.
I am unsure whether the upstream issue is really the same as this one since this here panics within the LSP's code. I fixed the upstream bug and made the interfaces more type-safe so that you can't get a FileId
from a detached span anymore. This means that some errors might not have range information (only in rare cases) and compiler consumers must be prepared to handle that.
I don't think this can be a race condition, since it should hold a read lock for all files throughout the entire process. Nothing should be able to change, even across await points. I'll investigate to see if the upstream issue is related.
@Enivex I think your error has a different cause, or is at least a very different manifestation of the cause. This panic is coming from Typst's item!
macro, which panics on unwrapping a LANG_ITEMS
OnceLock
which presumably is unset when that macro is invoked. Right now, that code lives here. I don't know the Typst internals well enough to say why, but something is probably not being initialized correctly.
I do believe now that this is related to typst/typst#2035. The language server builds a new world for each compilation, and I think our panic caused by an expect
on the same function that caused the panic in Typst.
@nvarner What made me unsure again is the following: The upstream panic came from within the track proc macros, which leads me to believe that it happened during validation within comemo. That made sense as the panic message was within Source::range
, which can be called by comemo to validate the World::range
function.
Here, however, the panic is within the LSP's code. That means it is not during constraint validation. Unless the upstream issue was something else, this would mean it is different.
I don't have a good mental model for comemo (is there a technical writeup on how it works?) so your understanding is better than mine, but I do think these are related. The upstream panic stack trace shows expect
called from Source::range
called from World::range
, so I don't think this was comemo calling Source::range
directly.
I would guess that something (possibly comemo) called World::range
with an invalid span, whose ID was forwarded to Source::range
, which then called Source::find
, which itself returned None
. The language server calls Source::find
directly, but (theoretically) with the same arguments, and also panics when it returns None
. Does that sound possible?
I've patched in a partial fix that will stop missing spans from causing panics. Instead, missing spans will be given a default, empty span at the start of the document. I'll prepare a release now, so the fix should be available within a few hours.
Comemo indeed calls World::range
, which then calls Source::range
. What I mean is that it would make sense that comemo calls World::range
with an invalid span that is not detached while doing constraint validation -- because it attempts to compare a new world against constraints generated for an old one.
Typst LSP, on the contrary, might call this function with detached spans (if Typst produces them), but not with invalid non-detached spans. Detached spans should produce a different error message though: "span does not point into any source file" rather than "span does not point into this source file".
Under what circumstances would Typst produce a detached span? The only place in typst-lsp
that I create detached files is in tests.
It happens very rarely, but it can happen if an error occurs for a generated element without a span. There is just no type system level guarantee that it can't happen.
Since my fix for the upstream issue, it also happens for the "layout did not converge within five attempts" warning because that one doesn't have a good span.
In the upstream fix, I made some changes so that trying to get a FileId from a span returns an Option so that consumers can't just ignore the possibility of a detached span.
Under what circumstances would Typst produce a detached span? The only place in
typst-lsp
that I create detached files is in tests.
In the current release and the freshly build of master
branch on my local machine, the panic emerges again under the following circumstances:
#figure() // Good when input, panic when the complete function name present
When the file is in a non-compiling state (for example, at least one function lacks an mandatory parameter) the LSP begins to panic. Sometimes the LSP only panickes once, but the #figure()
often drives the LSP to panic repeatedly (like in 0.9.4
). All the related panickes comes with the following log output:
[Info - 07:15:33] src\server\lsp.rs:237 { message = server initialized; }
thread '<unnamed>' panicked at C:\Users\Falke\.cargo\git\checkouts\typst-6808799b0d8fdaa9\da8367e\crates\typst\src\diag.rs:213:37:
span does not point into this source file
stack backtrace:
0: std::panicking::begin_panic_handler
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\std\src\panicking.rs:617
1: core::panicking::panic_fmt
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\core\src\panicking.rs:67
2: core::panicking::panic_display
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\core\src\panicking.rs:150
3: core::panicking::panic_str
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\core\src\panicking.rs:134
4: core::option::expect_failed
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\core\src\option.rs:1988
5: typst_syntax::source::Source::range
6: typst::World::range
7: <core::result::Result<T,alloc::boxed::Box<alloc::vec::Vec<typst::diag::SourceDiagnostic>>> as typst::diag::Trace<T>>::trace
8: <typst_syntax::ast::FuncCall as typst::eval::Eval>::eval
9: <typst_syntax::ast::Expr as typst::eval::Eval>::eval
10: typst::eval::eval_markup
11: typst::eval::eval_markup
12: typst::eval::eval_markup
13: typst::eval::eval_markup
14: typst::eval::eval_markup
15: comemo::cache::memoized
16: typst::eval::eval
17: core::ops::function::FnOnce::call_once{{vtable.shim}}
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'main' panicked at src\workspace\world\typst_thread.rs:71:24:
called `Result::unwrap()` on an `Err` value: RecvError(())
stack backtrace:
0: std::panicking::begin_panic_handler
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\std\src\panicking.rs:617
1: core::panicking::panic_fmt
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\core\src\panicking.rs:67
2: core::result::unwrap_failed
at /rustc/180dffba142c47240ca0d93096ce90b9fd97c8d7/library\core\src\result.rs:1652
3: typst_lsp::workspace::world::typst_thread::TypstThread::run::{{closure}}::{{closure}}
4: typst_lsp::workspace::world::typst_thread::TypstThread::run_with_world::{{closure}}::{{closure}}
5: typst_lsp::server::typst_compiler::<impl typst_lsp::server::TypstServer>::eval_source::{{closure}}::{{closure}}
6: typst_lsp::server::typst_compiler::<impl typst_lsp::server::TypstServer>::compile_source::{{closure}}::{{closure}}
7: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
8: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
9: typst_lsp::server::lsp::<impl tower_lsp::LanguageServer for typst_lsp::server::TypstServer>::did_open::{{closure}}
10: tower_lsp::jsonrpc::router::Router<S,E>::method
11: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
12: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
13: <core::pin::Pin<P> as core::future::future::Future>::poll
14: <core::pin::Pin<P> as core::future::future::Future>::poll
15: <tower_lsp::service::LspService<S> as tower_service::Service<tower_lsp::jsonrpc::request::Request>>::call::{{closure}}
16: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
17: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as futures_core::stream::Stream>::poll_next
18: <futures_util::stream::stream::buffer_unordered::BufferUnordered<St> as futures_core::stream::Stream>::poll_next
19: <futures_util::stream::stream::filter_map::FilterMap<St,Fut,F> as futures_core::stream::Stream>::poll_next
20: <futures_util::stream::stream::forward::Forward<St,Si,Item> as core::future::future::Future>::poll
21: <futures_util::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
22: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
23: typst_lsp::workspace::package::external::manager::ExternalPackageManager::new
24: typst_lsp::workspace::package::external::manager::ExternalPackageManager::new
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
[Error - 07:15:33] The Typst Language Server server crashed 5 times in the last 3 minutes. The server will not be restarted. See the output for more information.
This panic, however, emerges only with an special document (bad_file.zip). The ZIP archive contains the whole working directory and the verbose log including stack trace.
I tested typst-lsp v0.9.5
with some other documents (good_file.zip) contains the same #let
bindings and #set
rules, only replaced the text with CJK lorem, the panic magically disappears and no longer emerged.
Directory structure:
typst-test
├── error_log_1.txt
├── file.assets
│ ├── 20230825215737.png
│ └── 20230831080945.png
├── file.pdf
└── file.typ
Common headers and document structrure/pattern:
#let text_base_size=10pt
#let text_h1_size=20pt
#let header_size_increment=3pt
#set page(
paper: "a4",
header: align(right)[
Multi-purpose Combat Chassis [FALKEN]
],
numbering: "1",
margin: (x:20mm, y:12.7mm)
)
#set par(justify: true)
#set text(
font: "LXGW WenKai",
size: text_base_size,
lang: "zh",
)
#let emp_block(body,fill:luma(230),stroke:orange) = {
block(
width:100%,
fill: fill,
inset: 8pt,
radius: 0pt,
stroke: (left:(stroke+3pt),right:(luma(200)+3pt)),
body,
)
}
#let booktab() = {
block(
width: 100%,
[
#line(length: 100%,stroke: 3pt+luma(140))
#move(line(length: 100%), dx: 0pt, dy: -9pt)
]
)
v(0pt, weak: true)
}
#show heading: it => block[
#let heading_size=text_h1_size - (it.level - 1) * header_size_increment
#set text(size: heading_size, font: "HarmonyOS Sans SC")
#emph(it.body)
]
// text ...
#let images_pistol=("20230831080945.png","20230825215737.png")
#let cell = rect.with(
inset: 8pt,
fill: rgb("e4e5ea"),
width: 100%,
radius: 6pt
)
#grid(
columns: (1fr,1fr),
rows: (),
gutter: 3pt,
..images_pistol.map(n=>align(center)[#image("test.assets/"+n, width:20%)])
)
// text ...
#let images_rkg3=("20230831080945.png","20230831083112.png")
#align(center)[
#stack(
dir: ltr,
..images_rkg3.map(n=>align(center)[#image("falken_refined.assets/"+n, height:15%)])
)
]
That panic seems to be coming from Typst itself. I'll need to look into it more.
That panic seems to be coming from Typst itself. I'll need to look into it more.
Some large changes on the typst-lsp
code might be mandatory so that the LSP adapts to the upstream fix to the unknown span panic. This commit make some breaking changes on the internal types, results in building failure with current master
branch.
That panic seems to be coming from Typst itself. I'll need to look into it more.
Update: Testing in the original workspace turned out that the panic is caused by some bad file and directory names, rather than file content.
typst(test)/
└── test_test.typ
With this directory name and file name scheme(for example foo(bar)/bad_file.typ
), errors like missing body
emitted from incomplete function calls (like a single #figure()
/#float()
/etc. ) always results in an typst\src\diag.rs:213:37:span does not point into this source file
panic, which is firstly pointed here.
The bad directory and file name scheme that triggers the panic is quite harsh:
foo(bar)/badfile.typ -> calm
foo_bar/bad_file.typ -> calm
foo(bar)/bad_file.typ -> panic
I've not encountered this in a while, so it could possibly be closed @nvarner
@Enivex good to hear! I'm hoping this was fixed by those Typst changes. If anyone encounters this again, please open a new issue
Issue
The LSP crashes extremely often (essentially every time the file is in a non-compiling state), giving me the following error:
thread 'main' panicked at 'span should be in source since we got it using the span', src\lsp_typst_boundary.rs:240:14
Since vscode doesn't like this, it'll disable the lsp after 5 attempts, and I have to reload the window.