[info request] traceparent and general logging question

[ToddGrun]

I've got a question about logging in O#. For context, I work on the Visual Studio web tooling team, and we are using O# for html and css language server support in VS. We run the language server in it's own process as opposed to running inside the VS process. Everything works pretty dandy so far. Kudos to the work you’ve done!

To clarify what I'm trying to do, I've called ConfigureLogging and added my ILoggerProvider to the builder.Services instead of using AddLanguageProtocolLogging. My ILoggerProvider doesn't send out a window/logMessage notification, but rather writes out to a .svclog file (via LogHub) that will be able to be collected by VS and opened with other log files from the VS process which can link the activity IDs.

The difficulty I’m experiencing is trying to get logging inside this process to understand the "traceparent" activity id that VS sends over in the json payload. In VS, setting TraceSource.ActivityID is handled by this code in StreamJsonRpc, which makes it so we can associate activity ids from the two processes. However, it appears O# has it’s own RPC infrastructure, and doesn’t handle this on our behalf. I then tried looking into whether there were any hooks that I could use to inspect the JToken during the routing and gather this information before it’s converted into the appropriate args, but I haven’t been able to find any.

I’m hoping I’m misunderstanding logging inside O# and there is a way to have it understand the trace parent activity id from the client process. Any suggestions would be greatly appreciated!

[NTaylorMullen]

@david-driscoll this would definitely be nice! Of course if we could utilize StreamJsonRpc in O# that would also suffice. That being said I don't know the initial motivators you had when writing the original O# infrastructure. I guess the answer was probably it seemed too "VS like" lol, aka the name of the repo containing "vs" https://github.com/microsoft/vs-streamjsonrpc.

@AArnott out of sheer curiosity is StreamJsonRpc really VS intrinsic?

[TanayParikh]

Thanks Todd for providing those details. The Razor Language Server in VS has a similar architecture and would greatly benefit from being able to access the activity ID. Here is how we currently do it with StreamJsonRpc. Any suggestions would be appreciated! 😄

[AArnott]

StreamJsonRpc is decidedly not VS-specific. It's used in many dozens of apps that I've heard of, and probably many more that I haven't. We test it on Mac and Linux as well as Windows, and on .NET Core, .NET Framework and mono too. Use within O# should certainly work. If it doesn't, I'd entertain bug reports.

[david-driscoll]

Moving to StreamJsonRpc would be a breaking change. I'm not specifically against it, I just haven't prototyped what it would take to migrate over to it.

However I think activity support can be added fairly easily, I'll have to take a look at what's required.

[david-driscoll]

@NTaylorMullen honestly when I originally started the library years ago I couldn't find any other jsonrpc libraries that would do what I needed. It was built sheerly out of necessity at the time.

[david-driscoll]

Alright this is my first stab at getting it setup, shameless stealing (but referencing!) the work of vs-streamjsonrpc for the initial bit. I need to add unit tests and configuration code.
#553

[david-driscoll]

@AArnott Question, would supporting ContentModified work with vs-streamjsonrpc? That's the only thing I can see (on the surface anyway) that might cause me a headache to move over.

[AArnott]

@david-driscoll I'm not sure I understand the question. By ContentModified are you referring to the HTTP header? What would it do in the context of JSON-RPC? Is there a spec for it somewhere?

That's the only thing I can see (on the surface anyway) that might cause me a headache to move over.

Does this mean you're considering switching to StreamJsonRpc?

[david-driscoll]

@AArnott Yes, if it means less work for me :)

So basically the LSP spec defines an extension to the spec.

if a server detects an internal state change (for example a project context changed) that invalidates the result of a request in execution the server can error these requests with ContentModified. If clients receive a ContentModified error, it generally should not show it in the UI for the end-user. Clients can resend the request if they know how to do so. It should be noted that for all position based requests it might be especially hard for clients to re-craft a request.

In our case we use so that when we receive a text change, we can cancel any pending requests (like completion, code lens, etc). This allows us to get around to serving the subsequent requests from the client faster.

Things that I've implemented that technically outside the spec or ambiguous in the spec are...

• Content Modified support -- Requests get cancelled transparently
• Request Timeout -- In the event user code doesn't handle requests properly we will automatically cancel the request to the caller.
• Request Priority and parallelization -- Based on content modified we have two kinds of requests. "Serial" requests that must be handled in serial, and "Parallel" requests that can be handled in parallel.
  • If Content Modified support is enabled, when a serial request comes through, any outstanding parallel requests will be cancelled with the error code -32801.
  • Serial request will wait for the last serial request to complete in order received.
  • Parallel requests will fan out on the thread pool however we support setting a concurrency limit, so that if a developer wants to limit the outstanding parallel requests they can easily configure this. This allows someone make everything serial if they want (eg. concurrency: 1) or to some arbitrary number (eg. concurrency: 20).

[AArnott]

• Content Modified: It looks like ContentModified is just an integer constant that LSP uses as an error code. Nothing divergent from the JSON-RPC spec about that. You could do that with StreamJsonRpc by throwing LocalRpcException from your RPC server method, which gives you control over the error code sent back to the RPC client.
• Request timeout: In StreamJsonRpc we do this with a CancellationToken that has a timer behind it. But I wonder who is setting the timeout? In LSP as I understand it, the client may cancel a request. StreamJsonRpc supports the LSP spec on cancellation in terms of CancellationToken. So everything should work here unless you have an idea that the server is choosing to timeout and cancel instead of letting the client decide that.
• Request Priority and parallelization: StreamJsonRpc guarantees every incoming request (which is fundamentally ordered of course at an RPC protocol level) is dispatched in the same order it came in. We dispatch incoming requests by calling SynchronizationContext.Post, which then owns responsibility to execute in parallel, in sequence, or whatever policy makes sense. While I don't think we expose it in our public API today, StreamJsonRpc can have a unique SynchronizationContext object per registered RPC server method, so you could build it such that you have certain methods that run in parallel and others that run in sequence by assigning different SynchronizationContext objects to different subsets of methods.
  But a perhaps simpler way to do it, and how everyone does it today, is they use the default SynchronizationContext that we provide which guarantees the server method is invoked in the same order as the request was received. If the server method returns Task or ValueTask (or their generic variants), yielding from that server method allows the next request to be dispatched (per the policy of our default SynchronizationContext). So folks can implement their server to allow concurrency simply with await Task.Yield(); at the top of some methods. After their first yield, they just run on the threadpool and may run concurrently with other requests.
  In your case, two SynchronizationContext objects sound perfect.

Your server would presumably need to record some state so that when a sequential request comes in that modifies content, any parallel request can notice that and throw your ContentModified error, but that shouldn't be too hard I think.

[ToddGrun]

Any update on whether consuming StreamJsonRpc is a possibility moving forward?