SignalR C# Client logging (#752)

This commit is contained in:
BrennanConroy 2017-08-24 08:37:05 -07:00 committed by GitHub
parent b8a936f2c1
commit a702713cd4
4 changed files with 298 additions and 48 deletions

View File

@ -1,6 +1,6 @@
Microsoft Visual Studio Solution File, Format Version 12.00 Microsoft Visual Studio Solution File, Format Version 12.00
# Visual Studio 15 # Visual Studio 15
VisualStudioVersion = 15.0.26706.0 VisualStudioVersion = 15.0.26730.0
MinimumVisualStudioVersion = 10.0.40219.1 MinimumVisualStudioVersion = 10.0.40219.1
Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "src", "src", "{DA69F624-5398-4884-87E4-B816698CDE65}" Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "src", "src", "{DA69F624-5398-4884-87E4-B816698CDE65}"
EndProject EndProject
@ -55,6 +55,7 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Common", "Common", "{6CEC3D
test\Common\ChannelExtensions.cs = test\Common\ChannelExtensions.cs test\Common\ChannelExtensions.cs = test\Common\ChannelExtensions.cs
test\Common\ServerFixture.cs = test\Common\ServerFixture.cs test\Common\ServerFixture.cs = test\Common\ServerFixture.cs
test\Common\TaskExtensions.cs = test\Common\TaskExtensions.cs test\Common\TaskExtensions.cs = test\Common\TaskExtensions.cs
test\Common\TestHelpers.cs = test\Common\TestHelpers.cs
EndProjectSection EndProjectSection
EndProject EndProject
Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "client-ts", "client-ts", "{3A76C5A2-79ED-49BC-8BDC-6A3A766FFA1B}" Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "client-ts", "client-ts", "{3A76C5A2-79ED-49BC-8BDC-6A3A766FFA1B}"

View File

@ -10,6 +10,7 @@ using System.Linq;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using System.Threading.Tasks.Channels; using System.Threading.Tasks.Channels;
using Microsoft.AspNetCore.SignalR.Client.Internal;
using Microsoft.AspNetCore.SignalR.Internal; using Microsoft.AspNetCore.SignalR.Internal;
using Microsoft.AspNetCore.SignalR.Internal.Encoders; using Microsoft.AspNetCore.SignalR.Internal.Encoders;
using Microsoft.AspNetCore.SignalR.Internal.Protocol; using Microsoft.AspNetCore.SignalR.Internal.Protocol;
@ -155,14 +156,14 @@ namespace Microsoft.AspNetCore.SignalR.Client
private Task InvokeCore(string methodName, InvocationRequest irq, object[] args, bool nonBlocking) private Task InvokeCore(string methodName, InvocationRequest irq, object[] args, bool nonBlocking)
{ {
ThrowIfConnectionTerminated(); ThrowIfConnectionTerminated(irq.InvocationId);
if (nonBlocking) if (nonBlocking)
{ {
_logger.LogTrace("Preparing invocation of '{target}' and {argumentCount} args", methodName, irq.ResultType.AssemblyQualifiedName, args.Length); _logger.PreparingNonBlockingInvocation(irq.InvocationId, methodName, args.Length);
} }
else else
{ {
_logger.LogTrace("Preparing invocation of '{target}', with return type '{returnType}' and {argumentCount} args", methodName, irq.ResultType.AssemblyQualifiedName, args.Length); _logger.PreparingBlockingInvocation(irq.InvocationId, methodName, irq.ResultType.FullName, args.Length);
} }
// Create an invocation descriptor. Client invocations are always blocking // Create an invocation descriptor. Client invocations are always blocking
@ -172,17 +173,13 @@ namespace Microsoft.AspNetCore.SignalR.Client
if (!nonBlocking) if (!nonBlocking)
{ {
// I just want an excuse to use 'irq' as a variable name... // I just want an excuse to use 'irq' as a variable name...
_logger.LogDebug("Registering Invocation ID '{invocationId}' for tracking", invocationMessage.InvocationId); _logger.RegisterInvocation(invocationMessage.InvocationId);
AddInvocation(irq); AddInvocation(irq);
} }
// Trace the full invocation, but only if that logging level is enabled (because building the args list is a bit slow) // Trace the full invocation
if (_logger.IsEnabled(LogLevel.Trace)) _logger.IssueInvocation(invocationMessage.InvocationId, irq.ResultType.FullName, methodName, args);
{
var argsList = string.Join(", ", args.Select(a => a.GetType().FullName));
_logger.LogTrace("Issuing Invocation '{invocationId}': {returnType} {methodName}({args})", invocationMessage.InvocationId, irq.ResultType.FullName, methodName, argsList);
}
// We don't need to wait for this to complete. It will signal back to the invocation request. // We don't need to wait for this to complete. It will signal back to the invocation request.
return SendInvocation(invocationMessage, irq); return SendInvocation(invocationMessage, irq);
@ -193,14 +190,14 @@ namespace Microsoft.AspNetCore.SignalR.Client
try try
{ {
var payload = _protocolReaderWriter.WriteMessage(invocationMessage); var payload = _protocolReaderWriter.WriteMessage(invocationMessage);
_logger.LogInformation("Sending Invocation '{invocationId}'", invocationMessage.InvocationId); _logger.SendInvocation(invocationMessage.InvocationId);
await _connection.SendAsync(payload, irq.CancellationToken); await _connection.SendAsync(payload, irq.CancellationToken);
_logger.LogInformation("Sending Invocation '{invocationId}' complete", invocationMessage.InvocationId); _logger.SendInvocationCompleted(invocationMessage.InvocationId);
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.LogError(0, ex, "Sending Invocation '{invocationId}' failed", invocationMessage.InvocationId); _logger.SendInvocationFailed(invocationMessage.InvocationId, ex);
irq.Fail(ex); irq.Fail(ex);
TryRemoveInvocation(invocationMessage.InvocationId, out _); TryRemoveInvocation(invocationMessage.InvocationId, out _);
} }
@ -216,17 +213,13 @@ namespace Microsoft.AspNetCore.SignalR.Client
switch (message) switch (message)
{ {
case InvocationMessage invocation: case InvocationMessage invocation:
if (_logger.IsEnabled(LogLevel.Trace)) _logger.ReceivedInvocation(invocation.InvocationId, invocation.Target, invocation.Arguments);
{
var argsList = string.Join(", ", invocation.Arguments.Select(a => a.GetType().FullName));
_logger.LogTrace("Received Invocation '{invocationId}': {methodName}({args})", invocation.InvocationId, invocation.Target, argsList);
}
await DispatchInvocationAsync(invocation, _connectionActive.Token); await DispatchInvocationAsync(invocation, _connectionActive.Token);
break; break;
case CompletionMessage completion: case CompletionMessage completion:
if (!TryRemoveInvocation(completion.InvocationId, out irq)) if (!TryRemoveInvocation(completion.InvocationId, out irq))
{ {
_logger.LogWarning("Dropped unsolicited Completion message for invocation '{invocationId}'", completion.InvocationId); _logger.DropCompletionMessage(completion.InvocationId);
return; return;
} }
DispatchInvocationCompletion(completion, irq); DispatchInvocationCompletion(completion, irq);
@ -236,7 +229,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
// Complete the invocation with an error, we don't support streaming (yet) // Complete the invocation with an error, we don't support streaming (yet)
if (!TryGetInvocation(streamItem.InvocationId, out irq)) if (!TryGetInvocation(streamItem.InvocationId, out irq))
{ {
_logger.LogWarning("Dropped unsolicited Stream Item message for invocation '{invocationId}'", streamItem.InvocationId); _logger.DropStreamMessage(streamItem.InvocationId);
return; return;
} }
DispatchInvocationStreamItemAsync(streamItem, irq); DispatchInvocationStreamItemAsync(streamItem, irq);
@ -250,10 +243,10 @@ namespace Microsoft.AspNetCore.SignalR.Client
private Task Shutdown(Exception ex = null) private Task Shutdown(Exception ex = null)
{ {
_logger.LogTrace("Shutting down connection"); _logger.ShutdownConnection();
if (ex != null) if (ex != null)
{ {
_logger.LogError(ex, "Connection is shutting down due to an error"); _logger.ShutdownWithError(ex);
} }
lock (_pendingCallsLock) lock (_pendingCallsLock)
@ -265,7 +258,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
foreach (var outstandingCall in _pendingCalls.Values) foreach (var outstandingCall in _pendingCalls.Values)
{ {
_logger.LogTrace("Removing pending call {invocationId}", outstandingCall.InvocationId); _logger.RemoveInvocation(outstandingCall.InvocationId);
if (ex != null) if (ex != null)
{ {
outstandingCall.Fail(ex); outstandingCall.Fail(ex);
@ -282,7 +275,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
// Find the handler // Find the handler
if (!_handlers.TryGetValue(invocation.Target, out InvocationHandler handler)) if (!_handlers.TryGetValue(invocation.Target, out InvocationHandler handler))
{ {
_logger.LogWarning("Failed to find handler for '{target}' method", invocation.Target); _logger.MissingHandler(invocation.Target);
return Task.CompletedTask; return Task.CompletedTask;
} }
@ -295,25 +288,25 @@ namespace Microsoft.AspNetCore.SignalR.Client
// and there's nobody to actually wait for us to finish. // and there's nobody to actually wait for us to finish.
private async void DispatchInvocationStreamItemAsync(StreamItemMessage streamItem, InvocationRequest irq) private async void DispatchInvocationStreamItemAsync(StreamItemMessage streamItem, InvocationRequest irq)
{ {
_logger.LogTrace("Received StreamItem for Invocation #{invocationId}", streamItem.InvocationId); _logger.ReceivedStreamItem(streamItem.InvocationId);
if (irq.CancellationToken.IsCancellationRequested) if (irq.CancellationToken.IsCancellationRequested)
{ {
_logger.LogTrace("Canceling dispatch of StreamItem message for Invocation {invocationId}. The invocation was cancelled.", irq.InvocationId); _logger.CancelingStreamItem(irq.InvocationId);
} }
else if (!await irq.StreamItem(streamItem.Item)) else if (!await irq.StreamItem(streamItem.Item))
{ {
_logger.LogWarning("Invocation {invocationId} received stream item after channel was closed.", irq.InvocationId); _logger.ReceivedStreamItemAfterClose(irq.InvocationId);
} }
} }
private void DispatchInvocationCompletion(CompletionMessage completion, InvocationRequest irq) private void DispatchInvocationCompletion(CompletionMessage completion, InvocationRequest irq)
{ {
_logger.LogTrace("Received Completion for Invocation #{invocationId}", completion.InvocationId); _logger.ReceivedInvocationCompletion(completion.InvocationId);
if (irq.CancellationToken.IsCancellationRequested) if (irq.CancellationToken.IsCancellationRequested)
{ {
_logger.LogTrace("Cancelling dispatch of Completion message for Invocation {invocationId}. The invocation was cancelled.", irq.InvocationId); _logger.CancelingCompletion(irq.InvocationId);
} }
else else
{ {
@ -328,11 +321,11 @@ namespace Microsoft.AspNetCore.SignalR.Client
} }
} }
private void ThrowIfConnectionTerminated() private void ThrowIfConnectionTerminated(string invocationId)
{ {
if (_connectionActive.Token.IsCancellationRequested) if (_connectionActive.Token.IsCancellationRequested)
{ {
_logger.LogError("Invoke was called after the connection was terminated"); _logger.InvokeAfterTermination(invocationId);
throw new InvalidOperationException("Connection has been terminated."); throw new InvalidOperationException("Connection has been terminated.");
} }
} }
@ -343,10 +336,10 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
lock (_pendingCallsLock) lock (_pendingCallsLock)
{ {
ThrowIfConnectionTerminated(); ThrowIfConnectionTerminated(irq.InvocationId);
if (_pendingCalls.ContainsKey(irq.InvocationId)) if (_pendingCalls.ContainsKey(irq.InvocationId))
{ {
_logger.LogCritical("Invocation ID '{invocationId}' is already in use.", irq.InvocationId); _logger.InvocationAlreadyInUse(irq.InvocationId);
throw new InvalidOperationException($"Invocation ID '{irq.InvocationId}' is already in use."); throw new InvalidOperationException($"Invocation ID '{irq.InvocationId}' is already in use.");
} }
else else
@ -360,7 +353,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
lock (_pendingCallsLock) lock (_pendingCallsLock)
{ {
ThrowIfConnectionTerminated(); ThrowIfConnectionTerminated(invocationId);
return _pendingCalls.TryGetValue(invocationId, out irq); return _pendingCalls.TryGetValue(invocationId, out irq);
} }
} }
@ -369,7 +362,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
lock (_pendingCallsLock) lock (_pendingCallsLock)
{ {
ThrowIfConnectionTerminated(); ThrowIfConnectionTerminated(invocationId);
if (_pendingCalls.TryGetValue(invocationId, out irq)) if (_pendingCalls.TryGetValue(invocationId, out irq))
{ {
_pendingCalls.Remove(invocationId); _pendingCalls.Remove(invocationId);
@ -395,7 +388,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
if (!_connection._pendingCalls.TryGetValue(invocationId, out InvocationRequest irq)) if (!_connection._pendingCalls.TryGetValue(invocationId, out InvocationRequest irq))
{ {
_connection._logger.LogError("Unsolicited response received for invocation '{invocationId}'", invocationId); _connection._logger.ReceivedUnexpectedResponse(invocationId);
return null; return null;
} }
return irq.ResultType; return irq.ResultType;
@ -405,7 +398,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
if (!_connection._handlers.TryGetValue(methodName, out InvocationHandler handler)) if (!_connection._handlers.TryGetValue(methodName, out InvocationHandler handler))
{ {
_connection._logger.LogWarning("Failed to find handler for '{target}' method", methodName); _connection._logger.MissingHandler(methodName);
return Type.EmptyTypes; return Type.EmptyTypes;
} }
return handler.ParameterTypes; return handler.ParameterTypes;

View File

@ -0,0 +1,256 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System;
using System.Linq;
using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.SignalR.Client.Internal
{
internal static class SignalRClientLoggerExtensions
{
// Category: HubConnection
private static readonly Action<ILogger, string, string, int, Exception> _preparingNonBlockingInvocation =
LoggerMessage.Define<string, string, int>(LogLevel.Trace, 0, "Preparing non-blocking invocation '{invocationId}' of '{target}', with {argumentCount} argument(s).");
private static readonly Action<ILogger, string, string, string, int, Exception> _preparingBlockingInvocation =
LoggerMessage.Define<string, string, string, int>(LogLevel.Trace, 1, "Preparing blocking invocation '{invocationId}' of '{target}', with return type '{returnType}' and {argumentCount} argument(s).");
private static readonly Action<ILogger, string, Exception> _registerInvocation =
LoggerMessage.Define<string>(LogLevel.Debug, 2, "Registering Invocation ID '{invocationId}' for tracking.");
private static readonly Action<ILogger, string, string, string, string, Exception> _issueInvocation =
LoggerMessage.Define<string, string, string, string>(LogLevel.Trace, 3, "Issuing Invocation '{invocationId}': {returnType} {methodName}({args}).");
private static readonly Action<ILogger, string, Exception> _sendInvocation =
LoggerMessage.Define<string>(LogLevel.Information, 4, "Sending Invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _sendInvocationCompleted =
LoggerMessage.Define<string>(LogLevel.Information, 5, "Sending Invocation '{invocationId}' completed.");
private static readonly Action<ILogger, string, Exception> _sendInvocationFailed =
LoggerMessage.Define<string>(LogLevel.Error, 6, "Sending Invocation '{invocationId}' failed.");
private static readonly Action<ILogger, string, string, string, Exception> _receivedInvocation =
LoggerMessage.Define<string, string, string>(LogLevel.Trace, 7, "Received Invocation '{invocationId}': {methodName}({args}).");
private static readonly Action<ILogger, string, Exception> _dropCompletionMessage =
LoggerMessage.Define<string>(LogLevel.Warning, 8, "Dropped unsolicited Completion message for invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _dropStreamMessage =
LoggerMessage.Define<string>(LogLevel.Warning, 9, "Dropped unsolicited StreamItem message for invocation '{invocationId}'.");
private static readonly Action<ILogger, Exception> _shutdownConnection =
LoggerMessage.Define(LogLevel.Trace, 10, "Shutting down connection.");
private static readonly Action<ILogger, Exception> _shutdownWithError =
LoggerMessage.Define(LogLevel.Error, 11, "Connection is shutting down due to an error.");
private static readonly Action<ILogger, string, Exception> _removeInvocation =
LoggerMessage.Define<string>(LogLevel.Trace, 12, "Removing pending invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _missingHandler =
LoggerMessage.Define<string>(LogLevel.Warning, 13, "Failed to find handler for '{target}' method.");
private static readonly Action<ILogger, string, Exception> _receivedStreamItem =
LoggerMessage.Define<string>(LogLevel.Trace, 14, "Received StreamItem for Invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _cancelingStreamItem =
LoggerMessage.Define<string>(LogLevel.Trace, 15, "Canceling dispatch of StreamItem message for Invocation {invocationId}. The invocation was canceled.");
private static readonly Action<ILogger, string, Exception> _receivedStreamItemAfterClose =
LoggerMessage.Define<string>(LogLevel.Warning, 16, "Invocation {invocationId} received stream item after channel was closed.");
private static readonly Action<ILogger, string, Exception> _receivedInvocationCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, 17, "Received Completion for Invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _cancelingCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, 18, "Canceling dispatch of Completion message for Invocation {invocationId}. The invocation was canceled.");
private static readonly Action<ILogger, string, Exception> _invokeAfterTermination =
LoggerMessage.Define<string>(LogLevel.Error, 19, "Invoke for Invocation '{invocationId}' was called after the connection was terminated.");
private static readonly Action<ILogger, string, Exception> _invocationAlreadyInUse =
LoggerMessage.Define<string>(LogLevel.Critical, 20, "Invocation ID '{invocationId}' is already in use.");
private static readonly Action<ILogger, string, Exception> _receivedUnexpectedResponse =
LoggerMessage.Define<string>(LogLevel.Error, 21, "Unsolicited response received for invocation '{invocationId}'.");
// Category: Streaming and NonStreaming
private static readonly Action<ILogger, string, Exception> _invocationCreated =
LoggerMessage.Define<string>(LogLevel.Trace, 0, "Invocation {invocationId} created.");
private static readonly Action<ILogger, string, Exception> _invocationDisposed =
LoggerMessage.Define<string>(LogLevel.Trace, 1, "Invocation {invocationId} disposed.");
private static readonly Action<ILogger, string, Exception> _invocationCompleted =
LoggerMessage.Define<string>(LogLevel.Trace, 2, "Invocation {invocationId} marked as completed.");
private static readonly Action<ILogger, string, Exception> _invocationFailed =
LoggerMessage.Define<string>(LogLevel.Trace, 3, "Invocation {invocationId} marked as failed.");
// Category: Streaming
private static readonly Action<ILogger, string, Exception> _receivedUnexpectedComplete =
LoggerMessage.Define<string>(LogLevel.Error, 4, "Invocation {invocationId} received a completion result, but was invoked as a streaming invocation.");
private static readonly Action<ILogger, string, Exception> _errorWritingStreamItem =
LoggerMessage.Define<string>(LogLevel.Error, 5, "Invocation {invocationId} caused an error trying to write a stream item.");
// Category: NonStreaming
private static readonly Action<ILogger, string, Exception> _streamItemOnNonStreamInvocation =
LoggerMessage.Define<string>(LogLevel.Error, 4, "Invocation {invocationId} received stream item but was invoked as a non-streamed invocation.");
public static void PreparingNonBlockingInvocation(this ILogger logger, string invocationId, string target, int count)
{
_preparingNonBlockingInvocation(logger, invocationId, target, count, null);
}
public static void PreparingBlockingInvocation(this ILogger logger, string invocationId, string target, string returnType, int count)
{
_preparingBlockingInvocation(logger, invocationId, target, returnType, count, null);
}
public static void RegisterInvocation(this ILogger logger, string invocationId)
{
_registerInvocation(logger, invocationId, null);
}
public static void IssueInvocation(this ILogger logger, string invocationId, string returnType, string methodName, object[] args)
{
if (logger.IsEnabled(LogLevel.Trace))
{
var argsList = string.Join(", ", args.Select(a => a.GetType().FullName));
_issueInvocation(logger, invocationId, returnType, methodName, argsList, null);
}
}
public static void SendInvocation(this ILogger logger, string invocationId)
{
_sendInvocation(logger, invocationId, null);
}
public static void SendInvocationCompleted(this ILogger logger, string invocationId)
{
_sendInvocationCompleted(logger, invocationId, null);
}
public static void SendInvocationFailed(this ILogger logger, string invocationId, Exception exception)
{
_sendInvocationFailed(logger, invocationId, exception);
}
public static void ReceivedInvocation(this ILogger logger, string invocationId, string methodName, object[] args)
{
if (logger.IsEnabled(LogLevel.Trace))
{
var argsList = string.Join(", ", args.Select(a => a.GetType().FullName));
_receivedInvocation(logger, invocationId, methodName, argsList, null);
}
}
public static void DropCompletionMessage(this ILogger logger, string invocationId)
{
_dropCompletionMessage(logger, invocationId, null);
}
public static void DropStreamMessage(this ILogger logger, string invocationId)
{
_dropStreamMessage(logger, invocationId, null);
}
public static void ShutdownConnection(this ILogger logger)
{
_shutdownConnection(logger, null);
}
public static void ShutdownWithError(this ILogger logger, Exception exception)
{
_shutdownWithError(logger, exception);
}
public static void RemoveInvocation(this ILogger logger, string invocationId)
{
_removeInvocation(logger, invocationId, null);
}
public static void MissingHandler(this ILogger logger, string target)
{
_missingHandler(logger, target, null);
}
public static void ReceivedStreamItem(this ILogger logger, string invocationId)
{
_receivedStreamItem(logger, invocationId, null);
}
public static void CancelingStreamItem(this ILogger logger, string invocationId)
{
_cancelingStreamItem(logger, invocationId, null);
}
public static void ReceivedStreamItemAfterClose(this ILogger logger, string invocationId)
{
_receivedStreamItemAfterClose(logger, invocationId, null);
}
public static void ReceivedInvocationCompletion(this ILogger logger, string invocationId)
{
_receivedInvocationCompletion(logger, invocationId, null);
}
public static void CancelingCompletion(this ILogger logger, string invocationId)
{
_cancelingCompletion(logger, invocationId, null);
}
public static void InvokeAfterTermination(this ILogger logger, string invocationId)
{
_invokeAfterTermination(logger, invocationId, null);
}
public static void InvocationAlreadyInUse(this ILogger logger, string invocationId)
{
_invocationAlreadyInUse(logger, invocationId, null);
}
public static void ReceivedUnexpectedResponse(this ILogger logger, string invocationId)
{
_receivedUnexpectedResponse(logger, invocationId, null);
}
public static void InvocationCreated(this ILogger logger, string invocationId)
{
_invocationCreated(logger, invocationId, null);
}
public static void InvocationDisposed(this ILogger logger, string invocationId)
{
_invocationDisposed(logger, invocationId, null);
}
public static void InvocationCompleted(this ILogger logger, string invocationId)
{
_invocationCompleted(logger, invocationId, null);
}
public static void InvocationFailed(this ILogger logger, string invocationId)
{
_invocationFailed(logger, invocationId, null);
}
public static void ReceivedUnexpectedComplete(this ILogger logger, string invocationId)
{
_receivedUnexpectedComplete(logger, invocationId, null);
}
public static void ErrorWritingStreamItem(this ILogger logger, string invocationId, Exception exception)
{
_errorWritingStreamItem(logger, invocationId, exception);
}
public static void StreamItemOnNonStreamInvocation(this ILogger logger, string invocationId)
{
_streamItemOnNonStreamInvocation(logger, invocationId, null);
}
}
}

View File

@ -5,6 +5,7 @@ using System;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using System.Threading.Tasks.Channels; using System.Threading.Tasks.Channels;
using Microsoft.AspNetCore.SignalR.Client.Internal;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.SignalR.Client namespace Microsoft.AspNetCore.SignalR.Client
@ -28,7 +29,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
ResultType = resultType; ResultType = resultType;
Logger = logger; Logger = logger;
Logger.LogTrace("Invocation {invocationId} created", InvocationId); Logger.InvocationCreated(InvocationId);
} }
public static InvocationRequest Invoke(CancellationToken cancellationToken, Type resultType, string invocationId, ILoggerFactory loggerFactory, out Task<object> result) public static InvocationRequest Invoke(CancellationToken cancellationToken, Type resultType, string invocationId, ILoggerFactory loggerFactory, out Task<object> result)
@ -54,7 +55,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
public virtual void Dispose() public virtual void Dispose()
{ {
Logger.LogTrace("Invocation {invocationId} disposed", InvocationId); Logger.InvocationDisposed(InvocationId);
// Just in case it hasn't already been completed // Just in case it hasn't already been completed
Cancel(); Cancel();
@ -75,10 +76,10 @@ namespace Microsoft.AspNetCore.SignalR.Client
public override void Complete(object result) public override void Complete(object result)
{ {
Logger.LogTrace("Invocation {invocationId} marked as completed.", InvocationId); Logger.InvocationCompleted(InvocationId);
if (result != null) if (result != null)
{ {
Logger.LogError("Invocation {invocationId} received a completion result, but was invoked as a streaming invocation.", InvocationId); Logger.ReceivedUnexpectedComplete(InvocationId);
_channel.Out.TryComplete(new InvalidOperationException("Server provided a result in a completion response to a streamed invocation.")); _channel.Out.TryComplete(new InvalidOperationException("Server provided a result in a completion response to a streamed invocation."));
} }
else else
@ -89,7 +90,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
public override void Fail(Exception exception) public override void Fail(Exception exception)
{ {
Logger.LogTrace("Invocation {invocationId} marked as failed.", InvocationId); Logger.InvocationFailed(InvocationId);
_channel.Out.TryComplete(exception); _channel.Out.TryComplete(exception);
} }
@ -97,7 +98,6 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
try try
{ {
Logger.LogTrace("Invocation {invocationId} received stream item.", InvocationId);
while (!_channel.Out.TryWrite(item)) while (!_channel.Out.TryWrite(item))
{ {
if (!await _channel.Out.WaitToWriteAsync()) if (!await _channel.Out.WaitToWriteAsync())
@ -108,7 +108,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
Logger.LogError(ex, "Invocation {invocationId} caused an error trying to write a stream item.", InvocationId); Logger.ErrorWritingStreamItem(InvocationId, ex);
} }
return true; return true;
} }
@ -132,19 +132,19 @@ namespace Microsoft.AspNetCore.SignalR.Client
public override void Complete(object result) public override void Complete(object result)
{ {
Logger.LogTrace("Invocation {invocationId} marked as completed.", InvocationId); Logger.InvocationCompleted(InvocationId);
_completionSource.TrySetResult(result); _completionSource.TrySetResult(result);
} }
public override void Fail(Exception exception) public override void Fail(Exception exception)
{ {
Logger.LogTrace("Invocation {invocationId} marked as failed.", InvocationId); Logger.InvocationFailed(InvocationId);
_completionSource.TrySetException(exception); _completionSource.TrySetException(exception);
} }
public override ValueTask<bool> StreamItem(object item) public override ValueTask<bool> StreamItem(object item)
{ {
Logger.LogError("Invocation {invocationId} received stream item but was invoked as a non-streamed invocation.", InvocationId); Logger.StreamItemOnNonStreamInvocation(InvocationId);
_completionSource.TrySetException(new InvalidOperationException("Streaming methods must be invoked using HubConnection.Stream")); _completionSource.TrySetException(new InvalidOperationException("Streaming methods must be invoked using HubConnection.Stream"));
// We "delivered" the stream item successfully as far as the caller cares // We "delivered" the stream item successfully as far as the caller cares