zls
zls copied to clipboard
zigtools
Redundant work when checking large files
This is the experience I get when I type something in TigerBeetle's replica.zig
https://github.com/user-attachments/assets/b3b36e10-0b28-4cf1-ad48-d38d1b472979
Note how the red squiggly "chases" my cursor, because I can type faster than the time it takes to update the error.
The fact that update takes longer than typing is expected --- that's one large file.
What is problematic though, is the useless work. Because the squiggly moves character-by-character, it means that ZLS fully analyzes every intermediate state, but that's hugely wasteful. It should directly jump to the latest version, coalescing intermediate upgrades. That is, I expect that first there should be one-character wide squiggly, which than immediately jumps to cover the entire word.
Note that what is needed not debouncing, but just coalescing. That is, the analyze should kick in immediately after the user starts typing. However, when the analysis finishes, it should be restarted keeping all of the accumulated changes so far.
Here:
https://github.com/zigtools/zls/blob/bcc5d9fd67d815613cce0294a0d45b0d76cecd88/src/Server.zig#L2239-L2246
I think we should add a logic for "if there's already the same job in the queue, don't add it"
The given explanation for why ZLS is performing slowly here does not really align with how ZLS is implemented. In contrast to other LSPs, ZLS performs no analysis of a document ahead of receiving a request from the client.
The only potentially time consuming task that is done on each edit is to parse the AST of the document. This can be noticeable in larger files but when I tested replica.zig it was running much smoother for me than depicted in the video. Even Zig's Sema.zig has been working reasonable well for me since the last time I looked into performance issues on large files.
The reason why ZLS doesn't immediately jump to the latest state of the document is because it is processing all requests on the state of the document until moving on to the next state. This ensures correctness according to the LSP spec but isn't necessarily very efficient. If a request takes too long to handle then it can stall ZLS from processing more requests. If ZLS were to perform some kind of background code analysis that is occasionally updated by a thread in the background then there would be less cost to handling the individual requests which could potential mitigate this issue. But this isn't how ZLS works right now. :(
To better understand the cause of this issue, I would appreciate some extra information so I can try to investigate further:
- ZLS version
- Zig version
- which editor is being used
- If ZLS has been built from source: The optimization mode that has been used to build ZLS
- the ZLS log output. Ideally with debug logs enabled so that it reports how long it took to handle each request. The log level can be set by supplying the
--log-level debugflag when running ZLS.
In contrast to other LSPs, ZLS performs no analysis of a document ahead of receiving a request from the client.
I don't think so?
fn changeDocumentHandler(server: *Server, _: std.mem.Allocator, notification: types.DidChangeTextDocumentParams) Error!void {
...
try server.document_store.refreshDocument(handle.uri, new_text);
if (server.client_capabilities.supports_publish_diagnostics) {
try server.pushJob(.{ // <- this one right here!
.generate_diagnostics = try server.allocator.dupe(u8, handle.uri),
});
}
}
might be wrong here, haven't tried compiling from source
Yeah, I am wrong. The job queue is always empty at the time we are enquiring a diagnostic. I think this is because our overall loop is setup such that we wait for previous diagnostics to compute before we process document change events:
pub fn loop(server: *Server) !void {
std.debug.assert(server.transport != null);
while (server.keepRunning()) {
const json_message = try server.transport.?.readJsonMessage(server.allocator);
defer server.allocator.free(json_message);
try server.sendJsonMessage(json_message);
while (server.job_queue.readItem()) |job| {
if (zig_builtin.single_threaded) {
server.processJob(job, null);
continue;
}
switch (job.syncMode()) {
.exclusive => {
server.waitAndWork();
server.processJob(job, null);
},
.shared => {
server.wait_group.start();
errdefer job.deinit(server.allocator);
try server.thread_pool.spawn(processJob, .{ server, job, &server.wait_group });
},
.atomic => {
errdefer job.deinit(server.allocator);
try server.thread_pool.spawn(processJob, .{ server, job, null });
},
}
}
}
}
The sequence of events is as follows:
On the client side, the editor sends us a bunch of individual textDocument/didChange events
On the server side, we:
- grab one tD/dC from transport
- add it to our job_queue
- process it in
.exclusivemode - which adds a
.generate_diagnositicsjob - which we fork off in background (
shared) - and procede to the next iteration of the
while (server.keepRunning)loop - where we grab another td/Dc
- and then we wait
.exclusive => server.waitAndWork();until the diagnostic finish - and we enqueue more
generate_diagnositics
So this needs to be more involved, we need to batch updates.
We need step 8.5: after we finished waiting for diagnostics, we need to grab all messages from the transport which are already there, and process them all at the same time, kicking diagnostics at the end. So something like this:
loop {
transport.blockUntilHaveAtLeastOneMessage();
while (transport.readJSONMessageNonBlocking()) |message| {
server.process(message);
}
for (server.changedFiles) |file| {
server.pushJob(.{ . generate_diagnositics = file });
}
server.changedFiles.clear()
}
which editor is being used
VS Code
ZLS version Zig version
0.13
Yeah, the following diff seems to fix it for me. Not production ready, but I think big picture is correct here:
diff --git a/src/Server.zig b/src/Server.zig
index c7a30ee8..263dd8ef 100644
--- a/src/Server.zig
+++ b/src/Server.zig
@@ -1727,10 +1727,45 @@ pub fn waitAndWork(server: *Server) void {
pub fn loop(server: *Server) !void {
std.debug.assert(server.transport != null);
+
+ const Q = struct {
+ mutex: std.Thread.Mutex,
+ items: std.ArrayListUnmanaged([]const u8),
+ transport: *Transport,
+ allocator: std.mem.Allocator,
+
+ fn run(q: *@This()) !void {
+ while (true) { // FIXME
+ const message = try q.transport.readJsonMessage(q.allocator);
+ q.mutex.lock();
+ defer q.mutex.unlock();
+
+ try q.items.append(q.allocator, message);
+ }
+ }
+ };
+
+ var q: Q = .{
+ .mutex = .{},
+ .items = .{},
+ .transport = server.transport.?,
+ .allocator = server.allocator,
+ };
+
+ const t = try std.Thread.spawn(.{}, Q.run, .{&q});
+ t.detach(); // FIXME
+
while (server.keepRunning()) {
- const json_message = try server.transport.?.readJsonMessage(server.allocator);
- defer server.allocator.free(json_message);
- try server.sendJsonMessage(json_message);
+ {
+ q.mutex.lock();
+ defer q.mutex.unlock();
+
+ for (q.items.items) |json_message| {
+ defer server.allocator.free(json_message);
+ try server.sendJsonMessage(json_message);
+ }
+ q.items.clearRetainingCapacity();
+ }
while (server.job_queue.readItem()) |job| {
if (zig_builtin.single_threaded) {
@@ -2063,6 +2098,25 @@ fn handleResponse(server: *Server, response: types.Message.Response) Error!void
fn pushJob(server: *Server, job: Job) error{OutOfMemory}!void {
server.job_queue_lock.lock();
defer server.job_queue_lock.unlock();
+
+ if (job == .generate_diagnostics) {
+ for (0..server.job_queue.count) |offset| {
+ const existing = server.job_queue.peekItem(offset);
+ if (existing == .generate_diagnostics) {
+ const same_file = std.mem.eql(
+ u8,
+ job.generate_diagnostics,
+ existing.generate_diagnostics,
+ );
+ if (same_file) {
+ job.deinit(server.allocator);
+ std.debug.print("skipping, job-count={}\n", .{server.job_queue.count});
+ return;
+ }
+ }
+ }
+ }
+
server.job_queue.writeItem(job) catch |err| {
job.deinit(server.allocator);
return err;
I don't intend to send a PR this time ^^
In contrast to other LSPs, ZLS performs no analysis of a document ahead of receiving a request from the client.
I don't think so?
My apologies, I should have mentioned that diagnostics are generated on each edit. I didn't really consider it part of what makes up analysis in ZLS but it can still contribute to the behavior you have encountered.
Yeah, the following diff seems to fix it for me. Not production ready, but I think big picture is correct here:
I appreciate the effort that has been put into this but I would first like to make sure that we have precisely identified what exactly is causing this performance issue before trying to come up with a solution. Since you suspect diagnostics might be the issue, could you log how long it took to generate them so that we can be sure about this? This would also be a good opportunity to get the ZLS debug logs which should be very easy in VS Code by enabling the zig.zls.debugLog setting and then navigating to the Bottom Panel -> Output -> Zig Language Server.
To dig a little deeper into this, I ran ZLS with the Tracy profiler (zig build -Doptimize=ReleaseSafe -Denable-tracy -Denable-tracy-allocation=false) while performing similar editing in replica.zig. I went to the same location in the document and held down the 'a' key to type something like routing: aaaaaaaaaaaaaaaa and this is what I got:
Show Trace
The main thread takes care of updating the document source text and parsing the ast while most of the other requests are processed on the thread pool.
Here is a zoomed in view of the same trace:
Since the file always has syntax errors, no zig ast-check is run which usually takes the most time when generating diagnostics. Parsing the document takes about 6.5ms with more than enough time until the next text edit is received.
If you wish to go the extra step, I would greatly appreciate if you'd collect a trace as well. It should be verify handy at telling us what exactly is causing this issue.
Here's a baseline log where I observe caret racing with my typing behavior:
debug: (server): Took 6ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 614ms to process request-7-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 1127ms to process request-8-textDocument/completion on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 691ms to process request-9-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1435ms to process request-10-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-12-textDocument/inlayHint on Thread 40491847
debug: (server): Took 1254ms to process request-11-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491849
debug: (server): Took 0ms to process request-16-textDocument/willSaveWaitUntil on Thread 40491847
debug: (server): Took 0ms to process notification-textDocument/willSave on Thread 40491847
debug: (server): Took 0ms to process request-15-textDocument/inlayHint on Thread 40491850
debug: (server): Took 113ms to process request-13-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 115ms to process request-14-textDocument/semanticTokens/full on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-17-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-18-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-19-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 5ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 7ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-21-textDocument/inlayHint on Thread 40491848
debug: (server): Took 3ms to process request-20-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 9ms to process request-22-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-24-textDocument/inlayHint on Thread 40491849
debug: (server): Took 2ms to process request-23-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-26-textDocument/inlayHint on Thread 40491849
debug: (server): Took 2ms to process request-25-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491851
debug: (server): Took 4ms to process request-27-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-28-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-29-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 6ms to process request-30-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491850
debug: (server): Took 0ms to process request-33-textDocument/inlayHint on Thread 40491849
debug: (server): Took 6ms to process request-32-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 7ms to process request-31-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491850
debug: (server): Took 2ms to process request-34-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-35-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process request-37-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 15ms to process request-36-textDocument/completion on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process request-38-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-39-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 5ms to process request-40-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-42-textDocument/inlayHint on Thread 40491848
debug: (server): Took 4ms to process request-41-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-43-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process request-44-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 5ms to process request-45-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-46-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-48-textDocument/inlayHint on Thread 40491849
debug: (server): Took 2ms to process request-47-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-49-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 0ms to process notification-textDocument/didSave on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-50-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-51-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 5ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-54-textDocument/willSaveWaitUntil on Thread 40491851
debug: (server): Took 0ms to process notification-textDocument/willSave on Thread 40491851
debug: (server): Took 1ms to process request-53-textDocument/inlayHint on Thread 40491851
debug: (server): Took 4ms to process request-52-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 6ms to process request-55-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-56-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process request-57-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-58-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-60-textDocument/inlayHint on Thread 40491851
debug: (server): Took 2ms to process request-59-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 6ms to process request-61-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-62-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 7ms to process request-63-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-65-textDocument/inlayHint on Thread 40491848
debug: (server): Took 2ms to process request-64-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process request-66-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-67-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-68-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-69-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-71-textDocument/inlayHint on Thread 40491847
debug: (server): Took 3ms to process request-70-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-72-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-73-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-74-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-76-textDocument/inlayHint on Thread 40491850
debug: (server): Took 2ms to process request-75-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 6ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-77-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-78-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process request-80-textDocument/inlayHint on Thread 40491851
debug: (server): Took 1ms to process request-79-textDocument/documentSymbol on Thread 40491849
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491850
debug: (server): Took 2ms to process request-81-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-82-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-83-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 2ms to process request-84-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process request-85-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 0ms to process notification-textDocument/didSave on Thread 40491847
debug: (server): Took 0ms to process request-86-textDocument/inlayHint on Thread 40491850
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491847
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 3ms to process request-87-textDocument/documentSymbol on Thread 40491847
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 1ms to process request-88-textDocument/documentSymbol on Thread 40491851
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40491847
debug: (server): Took 0ms to process notification-textDocument/willSave on Thread 40491849
debug: (server): Took 0ms to process request-91-textDocument/willSaveWaitUntil on Thread 40491850
debug: (server): Took 0ms to process request-90-textDocument/inlayHint on Thread 40491848
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40491848
debug: (server): Took 0ms to process request-95-textDocument/inlayHint on Thread 40491849
debug: (server): Took 0ms to process request-96-textDocument/inlayHint on Thread 40491850
debug: (server): Took 0ms to process request-93-textDocument/codeAction on Thread 40491849
debug: (server): Took 1ms to process request-94-textDocument/documentSymbol on Thread 40491848
debug: (server): Took 3ms to process request-89-textDocument/documentSymbol on Thread 40491850
debug: (server): Took 6ms to process request-92-textDocument/foldingRange on Thread 40491851
debug: (server): Took 0ms to process notification-textDocument/didSave on Thread 40491847
debug: (server): Took 0ms to process request-97-textDocument/codeAction on Thread 40491849
debug: (server): Took 25ms to process request-98-textDocument/semanticTokens/full on Thread 40491848
And here's the log with my patch applied, where the red squgly just snaps to the end once I stop typing:
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 283ms to process request-22-textDocument/documentSymbol on Thread 40493198
debug: (server): Took 376ms to process request-23-textDocument/completion on Thread 40493195
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-25-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-24-textDocument/documentSymbol on Thread 40493196
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=21
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-textDocument/willSave on Thread 40493195
debug: (server): Took 0ms to process request-28-textDocument/willSaveWaitUntil on Thread 40493197
debug: (server): Took 0ms to process request-27-textDocument/inlayHint on Thread 40493198
debug: (server): Took 1ms to process request-26-textDocument/documentSymbol on Thread 40493196
skipping, job-count=16
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493199
debug: (server): Took 420ms to process request-29-textDocument/documentSymbol on Thread 40493195
skipping, job-count=13
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 652ms to process request-31-textDocument/documentSymbol on Thread 40493195
debug: (server): Took 2286ms to process request-30-textDocument/semanticTokens/full on Thread 40493196
skipping, job-count=10
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=9
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-33-textDocument/inlayHint on Thread 40493195
debug: (server): Took 100ms to process request-32-textDocument/documentSymbol on Thread 40493199
skipping, job-count=6
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493196
debug: (server): Took 3ms to process request-34-textDocument/documentSymbol on Thread 40493195
skipping, job-count=3
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-36-textDocument/inlayHint on Thread 40493197
debug: (server): Took 2ms to process request-35-textDocument/documentSymbol on Thread 40493198
debug: (server): Took 0ms to process notification-textDocument/didSave on Thread 40493195
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=142
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 6ms to process request-37-textDocument/documentSymbol on Thread 40493199
debug: (server): Took 8ms to process request-38-textDocument/completion on Thread 40493195
skipping, job-count=139
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-39-textDocument/documentSymbol on Thread 40493198
skipping, job-count=137
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-41-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-40-textDocument/documentSymbol on Thread 40493197
skipping, job-count=134
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493196
debug: (server): Took 0ms to process request-43-textDocument/inlayHint on Thread 40493195
debug: (server): Took 4ms to process request-42-textDocument/documentSymbol on Thread 40493199
skipping, job-count=130
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=128
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-textDocument/willSave on Thread 40493198
debug: (server): Took 0ms to process request-46-textDocument/willSaveWaitUntil on Thread 40493195
debug: (server): Took 0ms to process request-45-textDocument/inlayHint on Thread 40493197
debug: (server): Took 6ms to process request-44-textDocument/documentSymbol on Thread 40493199
skipping, job-count=123
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=122
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 6ms to process request-47-textDocument/documentSymbol on Thread 40493195
skipping, job-count=120
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-48-textDocument/documentSymbol on Thread 40493195
skipping, job-count=118
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-49-textDocument/documentSymbol on Thread 40493195
skipping, job-count=116
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-50-textDocument/documentSymbol on Thread 40493195
skipping, job-count=114
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 5ms to process request-51-textDocument/documentSymbol on Thread 40493195
skipping, job-count=112
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-53-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-52-textDocument/documentSymbol on Thread 40493196
skipping, job-count=109
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=107
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=106
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-55-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-54-textDocument/documentSymbol on Thread 40493199
skipping, job-count=103
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-56-textDocument/documentSymbol on Thread 40493195
skipping, job-count=101
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=100
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 1ms to process request-58-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-57-textDocument/documentSymbol on Thread 40493198
skipping, job-count=97
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=95
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=94
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=93
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 5ms to process request-59-textDocument/documentSymbol on Thread 40493195
skipping, job-count=91
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 1ms to process request-60-textDocument/documentSymbol on Thread 40493195
skipping, job-count=89
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-61-textDocument/documentSymbol on Thread 40493195
skipping, job-count=87
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 5ms to process request-62-textDocument/documentSymbol on Thread 40493195
skipping, job-count=85
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
debug: (server): Took 1ms to process request-65-textDocument/inlayHint on Thread 40493195
debug: (server): Took 4ms to process request-64-textDocument/documentSymbol on Thread 40493197
debug: (server): Took 5ms to process request-63-textDocument/documentSymbol on Thread 40493199
skipping, job-count=80
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493198
debug: (server): Took 8ms to process request-66-textDocument/documentSymbol on Thread 40493195
skipping, job-count=77
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-67-textDocument/documentSymbol on Thread 40493195
skipping, job-count=75
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=74
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 3ms to process request-68-textDocument/documentSymbol on Thread 40493195
skipping, job-count=72
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 1ms to process request-69-textDocument/documentSymbol on Thread 40493195
skipping, job-count=70
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 1ms to process request-70-textDocument/documentSymbol on Thread 40493195
skipping, job-count=68
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 3ms to process request-71-textDocument/documentSymbol on Thread 40493195
skipping, job-count=66
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-73-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-72-textDocument/documentSymbol on Thread 40493199
skipping, job-count=63
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=61
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 4ms to process request-74-textDocument/documentSymbol on Thread 40493195
skipping, job-count=59
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-76-textDocument/inlayHint on Thread 40493195
debug: (server): Took 1ms to process request-75-textDocument/documentSymbol on Thread 40493198
skipping, job-count=56
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 2ms to process request-77-textDocument/documentSymbol on Thread 40493195
skipping, job-count=54
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=53
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-79-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-78-textDocument/documentSymbol on Thread 40493197
skipping, job-count=50
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493198
debug: (server): Took 2ms to process request-80-textDocument/documentSymbol on Thread 40493195
skipping, job-count=47
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-82-textDocument/inlayHint on Thread 40493195
debug: (server): Took 1ms to process request-81-textDocument/documentSymbol on Thread 40493197
skipping, job-count=44
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=42
debug: (server): Took 3ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 3ms to process request-83-textDocument/documentSymbol on Thread 40493195
skipping, job-count=40
debug: (server): Took 5ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 1ms to process request-85-textDocument/inlayHint on Thread 40493195
debug: (server): Took 3ms to process request-84-textDocument/documentSymbol on Thread 40493198
skipping, job-count=37
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=36
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-87-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-86-textDocument/documentSymbol on Thread 40493199
debug: (server): Took 0ms to process notification-textDocument/didSave on Thread 40493195
skipping, job-count=32
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493199
debug: (server): Took 0ms to process request-88-textDocument/inlayHint on Thread 40493198
debug: (server): Took 6ms to process request-89-textDocument/documentSymbol on Thread 40493195
skipping, job-count=28
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=26
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=25
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=24
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-91-textDocument/inlayHint on Thread 40493195
debug: (server): Took 1ms to process request-90-textDocument/documentSymbol on Thread 40493196
skipping, job-count=21
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 9ms to process request-92-textDocument/documentSymbol on Thread 40493195
skipping, job-count=19
debug: (server): Took 4ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-95-textDocument/willSaveWaitUntil on Thread 40493195
debug: (server): Took 0ms to process notification-textDocument/willSave on Thread 40493199
debug: (server): Took 0ms to process request-94-textDocument/inlayHint on Thread 40493195
debug: (server): Took 2ms to process request-93-textDocument/documentSymbol on Thread 40493198
skipping, job-count=14
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493195
skipping, job-count=12
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=11
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=10
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-96-textDocument/inlayHint on Thread 40493199
debug: (server): Took 3ms to process request-97-textDocument/documentSymbol on Thread 40493195
skipping, job-count=7
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
skipping, job-count=6
debug: (server): Took 2ms to process notification-textDocument/didChange on Thread 40493195
debug: (server): Took 0ms to process request-101-textDocument/codeAction on Thread 40493197
debug: (server): Took 0ms to process notification-$/cancelRequest on Thread 40493198
debug: (server): Took 0ms to process request-103-textDocument/codeAction on Thread 40493198
debug: (server): Took 0ms to process request-104-textDocument/inlayHint on Thread 40493197
debug: (server): Took 0ms to process request-99-textDocument/inlayHint on Thread 40493198
debug: (server): Took 62ms to process request-102-textDocument/documentSymbol on Thread 40493199
debug: (server): Took 63ms to process request-98-textDocument/documentSymbol on Thread 40493197
debug: (server): Took 65ms to process request-100-textDocument/foldingRange on Thread 40493196
debug: (server): Took 0ms to process notification-textDocument/didSave on Thread 40493195
debug: (server): Took 20ms to process request-105-textDocument/semanticTokens/full on Thread 40493198
debug: (server): Took 0ms to process request-106-textDocument/codeAction on Thread 40493199
debug: (server): Took 0ms to process request-107-textDocument/codeAction on Thread 40493198
To be honest, I am puzzled at this. Indeed, every individual things takes 0/2 ms, so it should be fast enough.
I wonder if the same issue might be on the editor side? 🤣 Basically, ZLS is sending a continuous stream of diagnostics, and VS Code doesn't coalesce redundant diagnostics and applies them one by one?
Also, I must say I am in general puzzled by the behavior I am observing. When I field this issue, this felt really bad. When I tested it today, while I still observe the "chasing" behavior, the chasing is actually much faster today. And I wasnt' able to reproduce this on my other machine all.
To be honest, I am puzzled at this. Indeed, every individual things takes 0/2 ms, so it should be fast enough.
The logs don't show the time it takes to generate diagnostics which could be the cause even though I am not sure why it would take too long. Adding a print for that or running tracy could help to verify this.
What also confuses me is why the printed job-count value is so high. Doesn't this count the number of messages that have been received but not yet processed? So how are there suddenly over 100 jobs in queue? I tried to run the same patch but even with a debug build it wasn't skipping jobs unless I started typing like a maniac until my fingers started to hurt.
I wonder if the same issue might be on the editor side? 🤣 Basically, ZLS is sending a continuous stream of diagnostics, and VS Code doesn't coalesce redundant diagnostics and applies them one by one?
ZLS is sending a single LSP message with diagnostics per text edit which doesn't seem like to much.