Exit a language server if it sends a message with invalid json

[bendennis]

I've been struggling to get c# + omnisharp working reliably with helix. Omnisharp occasionally sends messages with malformed json, which causes the helix LSP event listener thread to die. After this happens, the LSP functionality within helix no longer works, even though omnisharp is still up and running. If I try to close helix at this point, it hangs for a bit and writes an lsp shutdown timeout log. If I run :lsp-restart, a second instance of omnisharp is started, leaving the first one running in the background.

This PR updates the recv function in helix-lsp::transport to request that an LSP is exited after it sends a message that cannot be parsed. This causes the Language server exited message to be displayed in the status bar within the editor. Surprisingly, the omnisharp process is still running at this point. Despite that, exiting helix is quick and running :lsp-restart restarts the process as expected.

Additionally, I updated some logging that caused confusion as I was troubleshooting.

[pascalkuthe]

This is definitely a bug in the language server it should never be sending invalid json. I think this could be an ok change to be a bit more robust but I would add somekind of counter to abort after a give counter of invalid messages received (without any valid messages) to avoid keeping an obviously crashing/crashed/missebhaving program alive forever. What do you think @the-mikedavis

[the-mikedavis]

I expected to see something in the JSONRPC spec about closing connections that send invalid JSON but it looks like we're only obligated to send an error response back when we receive a request with invalid JSON: https://www.jsonrpc.org/specification#error_object. (The message in the post is a notification though, so no response is necessary.) And the LSP spec doesn't say anything about invalid JSON. I think that closing the connection when we get non-JSON is reasonable though because JSONRPC says that we need to respond to all requests and if we can't parse a request enough to know that it's a request then we can't know that we have to respond to it.

Pragmatically I think it would be ok to make this change but it invites some extra complexity as @pascalkuthe says: we want servers that are obviously malfunctioning to exit rather than hang around forever. So I think this should really be fixed in omnisharp rather than any changes in Helix. I would prefer that we fail fast in Helix rather than trying to accomodate broken language servers.

[bendennis]

I agree that it would be ideal to fix the root cause in omnisharp. I actually created an issue over there initially. We'll see what comes of that. I might take a stab at debugging from that side if I have time.

There are some confusing aspects of the current helix behavior that made it harder to determine exactly what was going on. When the issue occurs, the LSP functionality just stops working from user's perspective. There's an error log for the json parse failure, but there are also a bunch of unrelated malformed notification from Language Server logs that don't seem to cause any issues. I thought it was confusing that some "malformed" messages cause issues while others don't. Maybe malformed should be changed to "undefined" or "unexpected" if those are actually valid messages that just don't follow the spec?

... a lot more malformed notification logs
2024-01-14T10:58:07.227 helix_term::application [ERROR] received malformed notification from Language Server: Unhandled
2024-01-14T10:58:07.929 helix_term::application [ERROR] received malformed notification from Language Server: Unhandled
2024-01-14T10:58:07.929 helix_term::application [ERROR] received malformed notification from Language Server: Unhandled
2024-01-14T10:58:08.702 helix_term::application [ERROR] received malformed notification from Language Server: Unhandled
2024-01-14T10:58:08.702 helix_term::application [ERROR] received malformed notification from Language Server: Unhandled
2024-01-14T10:58:08.976 helix_lsp::transport [ERROR] omnisharp err: <- Parse(Error("control character (\\u0000-\\u001F) found while parsing a string", line: 2, column: 0))

At this point, omnisharp is still running. If I try to close helix, it hangs for a bit and writes an lsp shutdown timeout log like the one below. If I run :lsp-restart, a second instance of omnisharp is started, leaving the first one running in the background.

2024-01-14T10:59:14.313 helix_term::application [ERROR] Timed out waiting for language servers to shutdown

If helix is going to bail on an lsp server that it thinks is unhealthy, I think it should do so completely and let the lsp server close before spinning up the new one. At that point, running :lsp-restart could be used to re-launch the lsp if desired. As long as the error logs make it clear what's going on, I think that'd be preferable to what happens today.

For now I think it probably makes sense to hold off on adding any additional complexity to account for straight up broken json coming from the lsp server.

If you think all that seems reasonable, I can take a swing at making the change to how the error is handled and logged.

[the-mikedavis]

Ah I see, in this case the client doesn't properly exit. Yeah let's properly shutdown the client in the Err case in recv doing all the cleanup we do for the StreamClosed error:

helix/helix-lsp/src/transport.rs

Lines 274 to 302 in eca3ccf

	// Close any outstanding requests.
	for (id, tx) in transport.pending_requests.lock().await.drain() {
	match tx.send(Err(Error::StreamClosed)).await {
	Ok(_) => (),
	Err(_) => {
	error!("Could not close request on a closed channel (id={:?})", id)
	}
	}
	}
	// Hack: inject a terminated notification so we trigger code that needs to happen after exit
	use lsp_types::notification::Notification as _;
	let notification =
	ServerMessage::Call(jsonrpc::Call::Notification(jsonrpc::Notification {
	jsonrpc: None,
	method: lsp_types::notification::Exit::METHOD.to_string(),
	params: jsonrpc::Params::None,
	}));
	match transport
	.process_server_message(&client_tx, notification, &transport.name)
	.await
	{
	Ok(_) => {}
	Err(err) => {
	error!("err: <- {:?}", err);
	}
	}
	break;
	}

Improving the logging sounds good too: we can probably log that line at info and have a more descriptive message so debugging wonky language servers is easier. The Unhandled error is benign - we just discard those messages - so there's no reason for it be logged at error level now.

[the-mikedavis]

Thanks!