Log to stderr as well as the log file, on non-Darwin platforms

[Wilfred]

This is consistent with other LSP servers, and makes debugging sourcekit-lsp easier.

This was initially discussed in #2116. Let me know if you think we should log to stderr on macOS too.

[ahoppen]

We do log to stderr until we set up the global log file handlers using setUpGlobalLogFileHandler. We should also log to stderr from there. With the current implementation, we would log every message twice if setting up the global log file handlers failed (once from the log handler and then once again from your fputs call).

[Wilfred]

Gotcha, presumably something like this is better?

[bnbarham]

@swift-ci please test

[bnbarham]

@swift-ci please test

[bnbarham]

Let me know if you think we should log to stderr on macOS too.

I'm not sure this is actually possible with our current implementation. All the calls are direct to OSLog and NonDarwinLogger is just API compatible with it. We can't wrap it, as we'd then lose its performance optimizations and ability to set privacy levels.

That also makes me wonder if we want this in general, since it means we have very different output to LSP clients between the platforms.

EDIT: Ah, it seems like various editors also treat stderr output as actual errors (eg. neovim logs stderr output with the format "[ERROR][timestamp] ..."). So it may indeed be best to avoid doing this generally. I've opened #2161 which seems like a better direction to go here.

[ahoppen]

@swift-ci Please test macOS

[ahoppen]

@swift-ci Please test Windows

[ahoppen]

Sorry for missing this. I just found the PR again, looks good to me, I just fixed a trailing whitespace issue on your branch.

[ahoppen]

@swift-ci Please test

[ahoppen]

@swift-ci Please test Windows

[bnbarham]

Just to re-iterate the edit I made in the previous comment - I'm not sure this is a path we want to go down due to editors treating stderr output as errors. Neovim is one example here (it logs stderr output with the format "[ERROR][timestamp] ..."), but I imagine there's probably others.

I'd prefer something like #2161, but I'd also be open to adding this behind a flag to make things easier to debug in the meantime.

Based on @bnbarham’s comment, I agree that this isn’t the right direction to go.

[Wilfred]

@bnbarham I don't think that's correct. All the other LSP implementations I've looked at (e.g rust-analyzer, clangd) write logs to stderr without problems.

For example, if I create a hello.cpp file and start clangd, I get the following output to stderr:

I[13:16:15.748] clangd version 20.1.8
I[13:16:15.748] Features: linux
I[13:16:15.748] PID: 1574394
I[13:16:15.748] Working directory: /home/wilfred/tmp/cppdemo
I[13:16:15.748] argv[0]: /usr/bin/clangd
I[13:16:15.748] Starting LSP over stdin/stdout
I[13:16:15.753] <-- initialize(1)
I[13:16:15.762] --> reply:initialize(1) 8 ms
I[13:16:15.765] <-- initialized
I[13:16:15.812] <-- textDocument/didOpen
I[13:16:15.815] Failed to find compilation database for /home/wilfred/tmp/cppdemo/main.cpp
I[13:16:15.816] ASTWorker building file /home/wilfred/tmp/cppdemo/main.cpp version 0 with command clangd fallback
[/home/wilfred/tmp/cppdemo]
/usr/bin/clang -resource-dir=/usr/lib/clang/20 -- /home/wilfred/tmp/cppdemo/main.cpp
I[13:16:15.841] <-- workspace/didChangeConfiguration
I[13:16:15.852] <-- textDocument/inlayHint(2)
I[13:16:15.953] <-- textDocument/hover(3)
I[13:16:15.953] <-- textDocument/documentHighlight(4)
I[13:16:15.953] <-- textDocument/signatureHelp(5)
I[13:16:16.321] Built preamble of size 3942160 for file /home/wilfred/tmp/cppdemo/main.cpp version 0 in 0.50 seconds
I[13:16:16.322] Indexing c++17 standard library in the context of /home/wilfred/tmp/cppdemo/main.cpp
I[13:16:16.338] --> reply:textDocument/signatureHelp(5) 384 ms
I[13:16:16.359] --> textDocument/publishDiagnostics
I[13:16:16.360] --> reply:textDocument/inlayHint(2) 507 ms
I[13:16:16.360] --> reply:textDocument/hover(3) 407 ms
I[13:16:16.360] --> reply:textDocument/documentHighlight(4) 407 ms
I[13:16:20.186] Indexed c++17 standard library (incomplete due to errors): 14392 symbols, 11464 filtered
I[13:17:34.799] <-- textDocument/hover(6)
I[13:17:34.799] <-- textDocument/documentHighlight(7)
I[13:17:34.799] <-- textDocument/signatureHelp(8)
I[13:17:34.799] --> reply:textDocument/hover(6) 0 ms
I[13:17:34.799] --> reply:textDocument/documentHighlight(7) 0 ms
I[13:17:34.806] --> reply:textDocument/signatureHelp(8) 7 ms

I mostly use Emacs and VS Code for my LSP needs, but I don't think that any editor treats stderr output as error. Note that LSP doesn't say anything about stderr. You don't even need to use stdin/stdout -- the spec supports stdio, pipes, sockets and node-ipc.

If an LSP server wants to show an error to a user, there are window/showMessage and window/showMessageRequest LSP methods it can use. I don't know how to use neovim, but based on neovim/neovim#16807 I think it logs stderr to lsp.log rather than showing any pop-ups.

You can see in the linked thread that a clangd maintainer is asking for more options for stderr logging, but gets a ton of value from having these logs! I certainly find stderr logs super useful when investigating LSP issues, and stderr seems like a very common convention.

[bnbarham]

I don't know how to use neovim, but based on neovim/neovim#16807 I think it logs stderr to lsp.log rather than showing any pop-ups.

Yeah, it's not a pop-up, just:

it logs stderr output with the format "[ERROR][timestamp] ..."

Which seems like it could cause some confusion to someone looking at those logs.

Given we already log to a file, my preference would be to window/logMessage the location of the logs as in #2161, which could then be consistent across platforms. Still open to the stderr discussion if that doesn't seem like a reasonable solution to you though (assuming the de facto standard in other LSP servers is to log to stderr).