Skip to content

Commit bbbb6ec

Browse files
david-driscolldavid-driscoll
authored
Merge pull request #63 from OmniSharp/fix/init
fixed initialize not working correctly, added additional logging
2 parents 0fef034 + 2d46bd8 commit bbbb6ec

File tree

3 files changed

+179
-65
lines changed

3 files changed

+179
-65
lines changed

‎src/Protocol/TimeLoggerExtensions.cs‎

Lines changed: 87 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,87 @@
1+
using System;
2+
using System.Diagnostics;
3+
using System.Linq;
4+
using Microsoft.Extensions.Logging;
5+
6+
// ReSharper disable once CheckNamespace
7+
namespace Microsoft.Extensions.Logging
8+
{
9+
internal static class TimeLoggerExtensions
10+
{
11+
class Disposable : IDisposable
12+
{
13+
private readonly IDisposable _disposable;
14+
private readonly Action<long> _action;
15+
private readonly Stopwatch _sw;
16+
17+
public Disposable(IDisposable disposable, Action<long> action)
18+
{
19+
_disposable = disposable;
20+
_action = action;
21+
_sw = new Stopwatch();
22+
_sw.Start();
23+
}
24+
25+
public void Dispose()
26+
{
27+
_sw.Stop();
28+
_action(_sw.ElapsedMilliseconds);
29+
_disposable.Dispose();
30+
}
31+
}
32+
33+
/// <summary>
34+
/// Times the trace.
35+
/// </summary>
36+
/// <param name="logger">The logger.</param>
37+
/// <param name="message">The message.</param>
38+
/// <param name="args">The arguments.</param>
39+
/// <returns>IDisposable.</returns>
40+
public static IDisposable TimeTrace(this ILogger logger, string message, params object[] args)
41+
{
42+
var scope = logger.BeginScope(new { });
43+
logger.LogTrace($"Starting: {message}", args);
44+
return new Disposable(scope, elapsed =>
45+
{
46+
var a = args.Concat(new object[] { elapsed }).ToArray();
47+
logger.LogTrace($"Finished: {message} in {{ElapsedMilliseconds}}ms", a);
48+
});
49+
}
50+
51+
/// <summary>
52+
/// Times the debug.
53+
/// </summary>
54+
/// <param name="logger">The logger.</param>
55+
/// <param name="message">The message.</param>
56+
/// <param name="args">The arguments.</param>
57+
/// <returns>IDisposable.</returns>
58+
public static IDisposable TimeDebug(this ILogger logger, string message, params object[] args)
59+
{
60+
var scope = logger.BeginScope(new { });
61+
logger.LogDebug($"Starting: {message}", args);
62+
return new Disposable(scope, elapsed =>
63+
{
64+
var a = args.Concat(new object[] { elapsed }).ToArray();
65+
logger.LogDebug($"Finished: {message} in {{ElapsedMilliseconds}}ms", a);
66+
});
67+
}
68+
69+
/// <summary>
70+
/// Times the information.
71+
/// </summary>
72+
/// <param name="logger">The logger.</param>
73+
/// <param name="message">The message.</param>
74+
/// <param name="args">The arguments.</param>
75+
/// <returns>IDisposable.</returns>
76+
public static IDisposable TimeInformation(this ILogger logger, string message, params object[] args)
77+
{
78+
var scope = logger.BeginScope(new { });
79+
logger.LogInformation($"Starting: {message}", args);
80+
return new Disposable(scope, elapsed =>
81+
{
82+
var a = args.Concat(new object[] { elapsed }).ToArray();
83+
logger.LogInformation($"Finished: {message} in {{ElapsedMilliseconds}}ms", a);
84+
});
85+
}
86+
}
87+
}

‎src/Server/LspRequestRouter.cs‎

Lines changed: 90 additions & 64 deletions
Original file line numberDiff line numberDiff line change
@@ -74,82 +74,104 @@ private ILspHandlerDescriptor FindDescriptor(string method, JToken @params)
7474
return _routeMatchers.SelectMany(strat => strat.FindHandler(paramsValue, lspHandlerDescriptors)).FirstOrDefault() ?? descriptor;
7575
}
7676

77-
public async Task RouteNotification(IHandlerDescriptor handler, Notification notification)
77+
public async Task RouteNotification(IHandlerDescriptor descriptor, Notification notification)
7878
{
79-
try
79+
using (_logger.TimeDebug("Routing Notification {Method}", notification.Method))
8080
{
81-
Task result;
82-
if (handler.Params is null)
81+
using (_logger.BeginScope(new KeyValuePair<string, string>[] {
82+
new KeyValuePair<string, string>( "Method", notification.Method),
83+
new KeyValuePair<string, string>( "Params", notification.Params?.ToString())
84+
}))
8385
{
84-
result = ReflectionRequestHandlers.HandleNotification(handler);
86+
try
87+
{
88+
if (descriptor.Params is null)
89+
{
90+
await ReflectionRequestHandlers.HandleNotification(descriptor);
91+
}
92+
else
93+
{
94+
_logger.LogDebug("Converting params for Notification {Method} to {Type}", notification.Method, descriptor.Params.FullName);
95+
var @params = notification.Params.ToObject(descriptor.Params, _serializer.JsonSerializer);
96+
await ReflectionRequestHandlers.HandleNotification(descriptor, @params);
97+
}
98+
}
99+
catch (Exception e)
100+
{
101+
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle request {Method}", notification.Method);
102+
}
85103
}
86-
else
87-
{
88-
var @params = notification.Params.ToObject(handler.Params, _serializer.JsonSerializer);
89-
result = ReflectionRequestHandlers.HandleNotification(handler, @params);
90-
}
91-
92-
await result;
93-
}
94-
catch (Exception e)
95-
{
96-
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle request {Method}", notification.Method);
97104
}
98105
}
99106

100107
public async Task<ErrorResponse> RouteRequest(IHandlerDescriptor descriptor, Request request)
101108
{
102-
var id = GetId(request.Id);
103-
var cts = new CancellationTokenSource();
104-
_requests.TryAdd(id, cts);
105-
106-
// TODO: Try / catch for Internal Error
107-
try
109+
using (_logger.TimeDebug("Routing Request ({Id}) {Method}", request.Id, request.Method))
108110
{
109-
if (descriptor is null)
110-
{
111-
return new MethodNotFound(request.Id, request.Method);
112-
}
113-
114-
object @params;
115-
try
116-
{
117-
@params = request.Params?.ToObject(descriptor.Params, _serializer.JsonSerializer);
118-
}
119-
catch (Exception cannotDeserializeRequestParams)
120-
{
121-
_logger.LogError(new EventId(-32602), cannotDeserializeRequestParams, "Failed to deserialise request parameters.");
122-
123-
return new InvalidParams(request.Id);
124-
}
125-
126-
var result = ReflectionRequestHandlers.HandleRequest(descriptor, @params, cts.Token).ConfigureAwait(false);
127-
await result;
128-
129-
object responseValue = null;
130-
if (result.GetType().GetTypeInfo().IsGenericType)
111+
using (_logger.BeginScope(new KeyValuePair<string, string>[] {
112+
new KeyValuePair<string, string>( "Id", request.Id?.ToString()),
113+
new KeyValuePair<string, string>( "Method", request.Method),
114+
new KeyValuePair<string, string>( "Params", request.Params?.ToString())
115+
}))
131116
{
132-
var property = typeof(Task<>)
133-
.MakeGenericType(result.GetType().GetTypeInfo().GetGenericArguments()[0]).GetTypeInfo()
134-
.GetProperty(nameof(Task<object>.Result), BindingFlags.Public | BindingFlags.Instance);
135-
136-
responseValue = property.GetValue(result);
117+
var id = GetId(request.Id);
118+
var cts = new CancellationTokenSource();
119+
_requests.TryAdd(id, cts);
120+
121+
// TODO: Try / catch for Internal Error
122+
try
123+
{
124+
if (descriptor is null)
125+
{
126+
_logger.LogDebug("descriptor not found for Request ({Id}) {Method}", request.Id, request.Method);
127+
return new MethodNotFound(request.Id, request.Method);
128+
}
129+
130+
object @params;
131+
try
132+
{
133+
_logger.LogDebug("Converting params for Request ({Id}) {Method} to {Type}", request.Id, request.Method, descriptor.Params.FullName);
134+
@params = request.Params?.ToObject(descriptor.Params, _serializer.JsonSerializer);
135+
}
136+
catch (Exception cannotDeserializeRequestParams)
137+
{
138+
_logger.LogError(new EventId(-32602), cannotDeserializeRequestParams, "Failed to deserialise request parameters.");
139+
return new InvalidParams(request.Id);
140+
}
141+
142+
var result = ReflectionRequestHandlers.HandleRequest(descriptor, @params, cts.Token);
143+
await result;
144+
145+
_logger.LogDebug("Result was {Type}", result.GetType().FullName);
146+
147+
object responseValue = null;
148+
if (result.GetType().GetTypeInfo().IsGenericType)
149+
{
150+
var property = typeof(Task<>)
151+
.MakeGenericType(result.GetType().GetTypeInfo().GetGenericArguments()[0]).GetTypeInfo()
152+
.GetProperty(nameof(Task<object>.Result), BindingFlags.Public | BindingFlags.Instance);
153+
154+
responseValue = property.GetValue(result);
155+
_logger.LogDebug("Response value was {Type}", responseValue?.GetType().FullName);
156+
}
157+
158+
return new JsonRpc.Client.Response(request.Id, responseValue);
159+
}
160+
catch (TaskCanceledException e)
161+
{
162+
_logger.LogDebug("Request {Id} was cancelled", id);
163+
return new RequestCancelled();
164+
}
165+
catch (Exception e)
166+
{
167+
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle notification {Method}", request.Method);
168+
return new InternalError(id);
169+
}
170+
finally
171+
{
172+
_requests.TryRemove(id, out var _);
173+
}
137174
}
138-
139-
return new JsonRpc.Client.Response(request.Id, responseValue);
140-
}
141-
catch (TaskCanceledException)
142-
{
143-
return new RequestCancelled();
144-
}
145-
catch (Exception e)
146-
{
147-
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle notification {Method}", request.Method);
148-
return new InternalError(id);
149-
}
150-
finally
151-
{
152-
_requests.TryRemove(id, out var _);
153175
}
154176
}
155177

@@ -159,6 +181,10 @@ public void CancelRequest(object id)
159181
{
160182
cts.Cancel();
161183
}
184+
else
185+
{
186+
_logger.LogDebug("Request {Id} was not found to cancel", id);
187+
}
162188
}
163189

164190
public IHandlerDescriptor GetDescriptor(Notification notification)

‎vscode-testextension/src/extension.ts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -13,7 +13,8 @@ import { Trace } from 'vscode-jsonrpc';
1313
export function activate(context: ExtensionContext) {
1414

1515
// The server is implemented in node
16-
let serverExe = 'C:/Other/omnisharp-roslyn/bin/Debug/OmniSharp.Stdio/net46/OmniSharp.exe';
16+
let serverExe = 'C:\\Other\\csharp-language-server-protocol\\sample\\SampleServer\\bin\\Debug\\netcoreapp2.0\\win7-x64\\SampleServer.exe';
17+
// // let serverExe = 'C:/Other/omnisharp-roslyn/bin/Debug/OmniSharp.Stdio/net46/OmniSharp.exe';
1718
// let serverExe = 'D:/Development/Omnisharp/omnisharp-roslyn/artifacts/publish/OmniSharp.Stdio/win7-x64/OmniSharp.exe';
1819
// let serverExe = context.asAbsolutePath('D:/Development/Omnisharp/omnisharp-roslyn/artifacts/publish/OmniSharp.Stdio/win7-x64/OmniSharp.exe');
1920
// The debug options for the server

0 commit comments

Comments
 (0)