Skip to content

Commit

Permalink
Merge pull request #63 from OmniSharp/fix/init
Browse files Browse the repository at this point in the history
fixed initialize not working correctly, added additional logging
  • Loading branch information
david-driscoll authored Jan 29, 2018
2 parents 0fef034 + 2d46bd8 commit bbbb6ec
Show file tree
Hide file tree
Showing 3 changed files with 179 additions and 65 deletions.
87 changes: 87 additions & 0 deletions src/Protocol/TimeLoggerExtensions.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,87 @@
using System;
using System.Diagnostics;
using System.Linq;
using Microsoft.Extensions.Logging;

// ReSharper disable once CheckNamespace
namespace Microsoft.Extensions.Logging
{
internal static class TimeLoggerExtensions
{
class Disposable : IDisposable
{
private readonly IDisposable _disposable;
private readonly Action<long> _action;
private readonly Stopwatch _sw;

public Disposable(IDisposable disposable, Action<long> action)
{
_disposable = disposable;
_action = action;
_sw = new Stopwatch();
_sw.Start();
}

public void Dispose()
{
_sw.Stop();
_action(_sw.ElapsedMilliseconds);
_disposable.Dispose();
}
}

/// <summary>
/// Times the trace.
/// </summary>
/// <param name="logger">The logger.</param>
/// <param name="message">The message.</param>
/// <param name="args">The arguments.</param>
/// <returns>IDisposable.</returns>
public static IDisposable TimeTrace(this ILogger logger, string message, params object[] args)
{
var scope = logger.BeginScope(new { });
logger.LogTrace($"Starting: {message}", args);
return new Disposable(scope, elapsed =>
{
var a = args.Concat(new object[] { elapsed }).ToArray();
logger.LogTrace($"Finished: {message} in {{ElapsedMilliseconds}}ms", a);
});
}

/// <summary>
/// Times the debug.
/// </summary>
/// <param name="logger">The logger.</param>
/// <param name="message">The message.</param>
/// <param name="args">The arguments.</param>
/// <returns>IDisposable.</returns>
public static IDisposable TimeDebug(this ILogger logger, string message, params object[] args)
{
var scope = logger.BeginScope(new { });
logger.LogDebug($"Starting: {message}", args);
return new Disposable(scope, elapsed =>
{
var a = args.Concat(new object[] { elapsed }).ToArray();
logger.LogDebug($"Finished: {message} in {{ElapsedMilliseconds}}ms", a);
});
}

/// <summary>
/// Times the information.
/// </summary>
/// <param name="logger">The logger.</param>
/// <param name="message">The message.</param>
/// <param name="args">The arguments.</param>
/// <returns>IDisposable.</returns>
public static IDisposable TimeInformation(this ILogger logger, string message, params object[] args)
{
var scope = logger.BeginScope(new { });
logger.LogInformation($"Starting: {message}", args);
return new Disposable(scope, elapsed =>
{
var a = args.Concat(new object[] { elapsed }).ToArray();
logger.LogInformation($"Finished: {message} in {{ElapsedMilliseconds}}ms", a);
});
}
}
}
154 changes: 90 additions & 64 deletions src/Server/LspRequestRouter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -74,82 +74,104 @@ private ILspHandlerDescriptor FindDescriptor(string method, JToken @params)
return _routeMatchers.SelectMany(strat => strat.FindHandler(paramsValue, lspHandlerDescriptors)).FirstOrDefault() ?? descriptor;
}

public async Task RouteNotification(IHandlerDescriptor handler, Notification notification)
public async Task RouteNotification(IHandlerDescriptor descriptor, Notification notification)
{
try
using (_logger.TimeDebug("Routing Notification {Method}", notification.Method))
{
Task result;
if (handler.Params is null)
using (_logger.BeginScope(new KeyValuePair<string, string>[] {
new KeyValuePair<string, string>( "Method", notification.Method),
new KeyValuePair<string, string>( "Params", notification.Params?.ToString())
}))
{
result = ReflectionRequestHandlers.HandleNotification(handler);
try
{
if (descriptor.Params is null)
{
await ReflectionRequestHandlers.HandleNotification(descriptor);
}
else
{
_logger.LogDebug("Converting params for Notification {Method} to {Type}", notification.Method, descriptor.Params.FullName);
var @params = notification.Params.ToObject(descriptor.Params, _serializer.JsonSerializer);
await ReflectionRequestHandlers.HandleNotification(descriptor, @params);
}
}
catch (Exception e)
{
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle request {Method}", notification.Method);
}
}
else
{
var @params = notification.Params.ToObject(handler.Params, _serializer.JsonSerializer);
result = ReflectionRequestHandlers.HandleNotification(handler, @params);
}

await result;
}
catch (Exception e)
{
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle request {Method}", notification.Method);
}
}

public async Task<ErrorResponse> RouteRequest(IHandlerDescriptor descriptor, Request request)
{
var id = GetId(request.Id);
var cts = new CancellationTokenSource();
_requests.TryAdd(id, cts);

// TODO: Try / catch for Internal Error
try
using (_logger.TimeDebug("Routing Request ({Id}) {Method}", request.Id, request.Method))
{
if (descriptor is null)
{
return new MethodNotFound(request.Id, request.Method);
}

object @params;
try
{
@params = request.Params?.ToObject(descriptor.Params, _serializer.JsonSerializer);
}
catch (Exception cannotDeserializeRequestParams)
{
_logger.LogError(new EventId(-32602), cannotDeserializeRequestParams, "Failed to deserialise request parameters.");

return new InvalidParams(request.Id);
}

var result = ReflectionRequestHandlers.HandleRequest(descriptor, @params, cts.Token).ConfigureAwait(false);
await result;

object responseValue = null;
if (result.GetType().GetTypeInfo().IsGenericType)
using (_logger.BeginScope(new KeyValuePair<string, string>[] {
new KeyValuePair<string, string>( "Id", request.Id?.ToString()),
new KeyValuePair<string, string>( "Method", request.Method),
new KeyValuePair<string, string>( "Params", request.Params?.ToString())
}))
{
var property = typeof(Task<>)
.MakeGenericType(result.GetType().GetTypeInfo().GetGenericArguments()[0]).GetTypeInfo()
.GetProperty(nameof(Task<object>.Result), BindingFlags.Public | BindingFlags.Instance);

responseValue = property.GetValue(result);
var id = GetId(request.Id);
var cts = new CancellationTokenSource();
_requests.TryAdd(id, cts);

// TODO: Try / catch for Internal Error
try
{
if (descriptor is null)
{
_logger.LogDebug("descriptor not found for Request ({Id}) {Method}", request.Id, request.Method);
return new MethodNotFound(request.Id, request.Method);
}

object @params;
try
{
_logger.LogDebug("Converting params for Request ({Id}) {Method} to {Type}", request.Id, request.Method, descriptor.Params.FullName);
@params = request.Params?.ToObject(descriptor.Params, _serializer.JsonSerializer);
}
catch (Exception cannotDeserializeRequestParams)
{
_logger.LogError(new EventId(-32602), cannotDeserializeRequestParams, "Failed to deserialise request parameters.");
return new InvalidParams(request.Id);
}

var result = ReflectionRequestHandlers.HandleRequest(descriptor, @params, cts.Token);
await result;

_logger.LogDebug("Result was {Type}", result.GetType().FullName);

object responseValue = null;
if (result.GetType().GetTypeInfo().IsGenericType)
{
var property = typeof(Task<>)
.MakeGenericType(result.GetType().GetTypeInfo().GetGenericArguments()[0]).GetTypeInfo()
.GetProperty(nameof(Task<object>.Result), BindingFlags.Public | BindingFlags.Instance);

responseValue = property.GetValue(result);
_logger.LogDebug("Response value was {Type}", responseValue?.GetType().FullName);
}

return new JsonRpc.Client.Response(request.Id, responseValue);
}
catch (TaskCanceledException e)
{
_logger.LogDebug("Request {Id} was cancelled", id);
return new RequestCancelled();
}
catch (Exception e)
{
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle notification {Method}", request.Method);
return new InternalError(id);
}
finally
{
_requests.TryRemove(id, out var _);
}
}

return new JsonRpc.Client.Response(request.Id, responseValue);
}
catch (TaskCanceledException)
{
return new RequestCancelled();
}
catch (Exception e)
{
_logger.LogCritical(Events.UnhandledRequest, e, "Failed to handle notification {Method}", request.Method);
return new InternalError(id);
}
finally
{
_requests.TryRemove(id, out var _);
}
}

Expand All @@ -159,6 +181,10 @@ public void CancelRequest(object id)
{
cts.Cancel();
}
else
{
_logger.LogDebug("Request {Id} was not found to cancel", id);
}
}

public IHandlerDescriptor GetDescriptor(Notification notification)
Expand Down
3 changes: 2 additions & 1 deletion vscode-testextension/src/extension.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,8 @@ import { Trace } from 'vscode-jsonrpc';
export function activate(context: ExtensionContext) {

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

0 comments on commit bbbb6ec

Please sign in to comment.