huahaofeng
/
aspnetcore
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Add some more logging (#1510)

This commit is contained in:
BrennanConroy 2018-02-28 14:11:59 -08:00 committed by GitHub
parent 9c74991ad6
commit 569c31bc62
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
14 changed files with 1093 additions and 859 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

295
src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.Log.cs Normal file
View File

@ -0,0 +1,295 @@
// 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
{
public partial class HubConnection
{
private static class Log
{
private static readonly Action<ILogger, string, int, Exception> _preparingNonBlockingInvocation =
LoggerMessage.Define<string, int>(LogLevel.Trace, new EventId(1, "PreparingNonBlockingInvocation"), "Preparing non-blocking invocation 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, new EventId(2, "PreparingBlockingInvocation"), "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, new EventId(3, "RegisterInvocation"), "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, new EventId(4, "IssueInvocation"), "Issuing Invocation '{invocationId}': {returnType} {methodName}({args}).");
private static readonly Action<ILogger, string, Exception> _sendInvocation =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(5, "SendInvocation"), "Sending Invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _sendInvocationCompleted =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(6, "SendInvocationCompleted"), "Sending Invocation '{invocationId}' completed.");
private static readonly Action<ILogger, string, Exception> _sendInvocationFailed =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(7, "SendInvocationFailed"), "Sending Invocation '{invocationId}' failed.");
private static readonly Action<ILogger, string, string, string, Exception> _receivedInvocation =
LoggerMessage.Define<string, string, string>(LogLevel.Trace, new EventId(8, "ReceivedInvocation"), "Received Invocation '{invocationId}': {methodName}({args}).");
private static readonly Action<ILogger, string, Exception> _dropCompletionMessage =
LoggerMessage.Define<string>(LogLevel.Warning, new EventId(9, "DropCompletionMessage"), "Dropped unsolicited Completion message for invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _dropStreamMessage =
LoggerMessage.Define<string>(LogLevel.Warning, new EventId(10, "DropStreamMessage"), "Dropped unsolicited StreamItem message for invocation '{invocationId}'.");
private static readonly Action<ILogger, Exception> _shutdownConnection =
LoggerMessage.Define(LogLevel.Trace, new EventId(11, "ShutdownConnection"), "Shutting down connection.");
private static readonly Action<ILogger, Exception> _shutdownWithError =
LoggerMessage.Define(LogLevel.Error, new EventId(12, "ShutdownWithError"), "Connection is shutting down due to an error.");
private static readonly Action<ILogger, string, Exception> _removeInvocation =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(13, "RemoveInvocation"), "Removing pending invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _missingHandler =
LoggerMessage.Define<string>(LogLevel.Warning, new EventId(14, "MissingHandler"), "Failed to find handler for '{target}' method.");
private static readonly Action<ILogger, string, Exception> _receivedStreamItem =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(15, "ReceivedStreamItem"), "Received StreamItem for Invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _cancelingStreamItem =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(16, "CancelingStreamItem"), "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, new EventId(17, "ReceivedStreamItemAfterClose"), "Invocation {invocationId} received stream item after channel was closed.");
private static readonly Action<ILogger, string, Exception> _receivedInvocationCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(18, "ReceivedInvocationCompletion"), "Received Completion for Invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _cancelingInvocationCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(19, "CancelingInvocationCompletion"), "Canceling dispatch of Completion message for Invocation {invocationId}. The invocation was canceled.");
private static readonly Action<ILogger, string, Exception> _cancelingCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(20, "CancelingCompletion"), "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, new EventId(21, "InvokeAfterTermination"), "Invoke for Invocation '{invocationId}' was called after the connection was terminated.");
private static readonly Action<ILogger, string, Exception> _invocationAlreadyInUse =
LoggerMessage.Define<string>(LogLevel.Critical, new EventId(22, "InvocationAlreadyInUse"), "Invocation ID '{invocationId}' is already in use.");
private static readonly Action<ILogger, string, Exception> _receivedUnexpectedResponse =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(23, "ReceivedUnexpectedResponse"), "Unsolicited response received for invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _hubProtocol =
LoggerMessage.Define<string>(LogLevel.Information, new EventId(24, "HubProtocol"), "Using HubProtocol '{protocol}'.");
private static readonly Action<ILogger, string, string, string, int, Exception> _preparingStreamingInvocation =
LoggerMessage.Define<string, string, string, int>(LogLevel.Trace, new EventId(25, "PreparingStreamingInvocation"), "Preparing streaming invocation '{invocationId}' of '{target}', with return type '{returnType}' and {argumentCount} argument(s).");
private static readonly Action<ILogger, Exception> _resettingKeepAliveTimer =
LoggerMessage.Define(LogLevel.Trace, new EventId(26, "ResettingKeepAliveTimer"), "Resetting keep-alive timer, received a message from the server.");
private static readonly Action<ILogger, Exception> _errorDuringClosedEvent =
LoggerMessage.Define(LogLevel.Error, new EventId(27, "ErrorDuringClosedEvent"), "An exception was thrown in the handler for the Closed event.");
private static readonly Action<ILogger, Exception> _sendingHubNegotiate =
LoggerMessage.Define(LogLevel.Debug, new EventId(28, "SendingHubNegotiate"), "Sending Hub Negotiation.");
private static readonly Action<ILogger, int, Exception> _parsingMessages =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(29, "ParsingMessages"), "Received {count} bytes. Parsing message(s).");
private static readonly Action<ILogger, int, Exception> _receivingMessages =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(30, "ReceivingMessages"), "Received {messageCount} message(s).");
private static readonly Action<ILogger, Exception> _receivedPing =
LoggerMessage.Define(LogLevel.Trace, new EventId(31, "ReceivedPing"), "Received a ping message.");
private static readonly Action<ILogger, int, Exception> _processedMessages =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(32, "ProcessedMessages"), "Finished processing {messageCount} message(s).");
private static readonly Action<ILogger, int, Exception> _failedParsing =
LoggerMessage.Define<int>(LogLevel.Warning, new EventId(33, "FailedParsing"), "No messages parsed from {count} byte(s).");
private static readonly Action<ILogger, string, Exception> _errorInvokingClientSideMethod =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(34, "ErrorInvokingClientSideMethod"), "Invoking client side method '{methodName}' failed.");
public static void PreparingNonBlockingInvocation(ILogger logger, string target, int count)
{
_preparingNonBlockingInvocation(logger, target, count, null);
}
public static void PreparingBlockingInvocation(ILogger logger, string invocationId, string target, string returnType, int count)
{
_preparingBlockingInvocation(logger, invocationId, target, returnType, count, null);
}
public static void PreparingStreamingInvocation(ILogger logger, string invocationId, string target, string returnType, int count)
{
_preparingStreamingInvocation(logger, invocationId, target, returnType, count, null);
}
public static void RegisterInvocation(ILogger logger, string invocationId)
{
_registerInvocation(logger, invocationId, null);
}
public static void IssueInvocation(ILogger logger, string invocationId, string returnType, string methodName, object[] args)
{
if (logger.IsEnabled(LogLevel.Trace))
{
var argsList = args == null ? string.Empty : string.Join(", ", args.Select(a => a?.GetType().FullName ?? "(null)"));
_issueInvocation(logger, invocationId, returnType, methodName, argsList, null);
}
}
public static void SendInvocation(ILogger logger, string invocationId)
{
_sendInvocation(logger, invocationId, null);
}
public static void SendInvocationCompleted(ILogger logger, string invocationId)
{
_sendInvocationCompleted(logger, invocationId, null);
}
public static void SendInvocationFailed(ILogger logger, string invocationId, Exception exception)
{
_sendInvocationFailed(logger, invocationId, exception);
}
public static void ReceivedInvocation(ILogger logger, string invocationId, string methodName, object[] args)
{
if (logger.IsEnabled(LogLevel.Trace))
{
var argsList = args == null ? string.Empty : string.Join(", ", args.Select(a => a?.GetType().FullName ?? "(null)"));
_receivedInvocation(logger, invocationId, methodName, argsList, null);
}
}
public static void DropCompletionMessage(ILogger logger, string invocationId)
{
_dropCompletionMessage(logger, invocationId, null);
}
public static void DropStreamMessage(ILogger logger, string invocationId)
{
_dropStreamMessage(logger, invocationId, null);
}
public static void ShutdownConnection(ILogger logger)
{
_shutdownConnection(logger, null);
}
public static void ShutdownWithError(ILogger logger, Exception exception)
{
_shutdownWithError(logger, exception);
}
public static void RemoveInvocation(ILogger logger, string invocationId)
{
_removeInvocation(logger, invocationId, null);
}
public static void MissingHandler(ILogger logger, string target)
{
_missingHandler(logger, target, null);
}
public static void ReceivedStreamItem(ILogger logger, string invocationId)
{
_receivedStreamItem(logger, invocationId, null);
}
public static void CancelingStreamItem(ILogger logger, string invocationId)
{
_cancelingStreamItem(logger, invocationId, null);
}
public static void ReceivedStreamItemAfterClose(ILogger logger, string invocationId)
{
_receivedStreamItemAfterClose(logger, invocationId, null);
}
public static void ReceivedInvocationCompletion(ILogger logger, string invocationId)
{
_receivedInvocationCompletion(logger, invocationId, null);
}
public static void CancelingInvocationCompletion(ILogger logger, string invocationId)
{
_cancelingInvocationCompletion(logger, invocationId, null);
}
public static void CancelingCompletion(ILogger logger, string invocationId)
{
_cancelingCompletion(logger, invocationId, null);
}
public static void InvokeAfterTermination(ILogger logger, string invocationId)
{
_invokeAfterTermination(logger, invocationId, null);
}
public static void InvocationAlreadyInUse(ILogger logger, string invocationId)
{
_invocationAlreadyInUse(logger, invocationId, null);
}
public static void ReceivedUnexpectedResponse(ILogger logger, string invocationId)
{
_receivedUnexpectedResponse(logger, invocationId, null);
}
public static void HubProtocol(ILogger logger, string hubProtocol)
{
_hubProtocol(logger, hubProtocol, null);
}
public static void ResettingKeepAliveTimer(ILogger logger)
{
_resettingKeepAliveTimer(logger, null);
}
public static void ErrorDuringClosedEvent(ILogger logger, Exception exception)
{
_errorDuringClosedEvent(logger, exception);
}
public static void SendingHubNegotiate(ILogger logger)
{
_sendingHubNegotiate(logger, null);
}
public static void ParsingMessages(ILogger logger, int byteCount)
{
_parsingMessages(logger, byteCount, null);
}
public static void ReceivingMessages(ILogger logger, int messageCount)
{
_receivingMessages(logger, messageCount, null);
}
public static void ReceivedPing(ILogger logger)
{
_receivedPing(logger, null);
}
public static void ProcessedMessages(ILogger logger, int messageCount)
{
_processedMessages(logger, messageCount, null);
}
public static void FailedParsing(ILogger logger, int byteCount)
{
_failedParsing(logger, byteCount, null);
}
public static void ErrorInvokingClientSideMethod(ILogger logger, string methodName, Exception exception)
{
_errorInvokingClientSideMethod(logger, methodName, exception);
}
}
}
}

78
src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs
View File

@ -9,7 +9,6 @@ using System.IO;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using System.Threading.Channels; using System.Threading.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;
@ -22,7 +21,7 @@ using Microsoft.Extensions.Logging.Abstractions;
namespace Microsoft.AspNetCore.SignalR.Client namespace Microsoft.AspNetCore.SignalR.Client
{ {
public class HubConnection public partial class HubConnection
{ {
public static readonly TimeSpan DefaultServerTimeout = TimeSpan.FromSeconds(30); // Server ping rate is 15 sec, this is 2 times that. public static readonly TimeSpan DefaultServerTimeout = TimeSpan.FromSeconds(30); // Server ping rate is 15 sec, this is 2 times that.
@ -96,7 +95,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
if (_needKeepAlive) if (_needKeepAlive)
{ {
_logger.ResettingKeepAliveTimer(); Log.ResettingKeepAliveTimer(_logger);
// If the connection is disposed while this callback is firing, or if the callback is fired after dispose // If the connection is disposed while this callback is firing, or if the callback is fired after dispose
// (which can happen because of some races), this will throw ObjectDisposedException. That's OK, because // (which can happen because of some races), this will throw ObjectDisposedException. That's OK, because
@ -134,11 +133,12 @@ namespace Microsoft.AspNetCore.SignalR.Client
_protocolReaderWriter = new HubProtocolReaderWriter(_protocol, GetDataEncoder(requestedTransferMode, actualTransferMode)); _protocolReaderWriter = new HubProtocolReaderWriter(_protocol, GetDataEncoder(requestedTransferMode, actualTransferMode));
_logger.HubProtocol(_protocol.Name); Log.HubProtocol(_logger, _protocol.Name);
_connectionActive = new CancellationTokenSource(); _connectionActive = new CancellationTokenSource();
using (var memoryStream = new MemoryStream()) using (var memoryStream = new MemoryStream())
{ {
Log.SendingHubNegotiate(_logger);
NegotiationProtocol.WriteMessage(new NegotiationMessage(_protocol.Name), memoryStream); NegotiationProtocol.WriteMessage(new NegotiationMessage(_protocol.Name), memoryStream);
await _connection.SendAsync(memoryStream.ToArray(), _connectionActive.Token); await _connection.SendAsync(memoryStream.ToArray(), _connectionActive.Token);
} }
@ -253,18 +253,18 @@ namespace Microsoft.AspNetCore.SignalR.Client
private Task InvokeCore(string methodName, InvocationRequest irq, object[] args) private Task InvokeCore(string methodName, InvocationRequest irq, object[] args)
{ {
ThrowIfConnectionTerminated(irq.InvocationId); ThrowIfConnectionTerminated(irq.InvocationId);
_logger.PreparingBlockingInvocation(irq.InvocationId, methodName, irq.ResultType.FullName, args.Length); Log.PreparingBlockingInvocation(_logger, irq.InvocationId, methodName, irq.ResultType.FullName, args.Length);
// Client invocations are always blocking // Client invocations are always blocking
var invocationMessage = new InvocationMessage(irq.InvocationId, target: methodName, var invocationMessage = new InvocationMessage(irq.InvocationId, target: methodName,
argumentBindingException: null, arguments: args); argumentBindingException: null, arguments: args);
_logger.RegisterInvocation(invocationMessage.InvocationId); Log.RegisterInvocation(_logger, invocationMessage.InvocationId);
AddInvocation(irq); AddInvocation(irq);
// Trace the full invocation // Trace the full invocation
_logger.IssueInvocation(invocationMessage.InvocationId, irq.ResultType.FullName, methodName, args); Log.IssueInvocation(_logger, invocationMessage.InvocationId, irq.ResultType.FullName, methodName, args);
// 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 SendHubMessage(invocationMessage, irq); return SendHubMessage(invocationMessage, irq);
@ -274,18 +274,18 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
ThrowIfConnectionTerminated(irq.InvocationId); ThrowIfConnectionTerminated(irq.InvocationId);
_logger.PreparingStreamingInvocation(irq.InvocationId, methodName, irq.ResultType.FullName, args.Length); Log.PreparingStreamingInvocation(_logger, irq.InvocationId, methodName, irq.ResultType.FullName, args.Length);
var invocationMessage = new StreamInvocationMessage(irq.InvocationId, methodName, var invocationMessage = new StreamInvocationMessage(irq.InvocationId, methodName,
argumentBindingException: null, arguments: args); argumentBindingException: null, arguments: args);
// 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.RegisterInvocation(invocationMessage.InvocationId); Log.RegisterInvocation(_logger, invocationMessage.InvocationId);
AddInvocation(irq); AddInvocation(irq);
// Trace the full invocation // Trace the full invocation
_logger.IssueInvocation(invocationMessage.InvocationId, irq.ResultType.FullName, methodName, args); Log.IssueInvocation(_logger, invocationMessage.InvocationId, irq.ResultType.FullName, methodName, args);
// 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 SendHubMessage(invocationMessage, irq); return SendHubMessage(invocationMessage, irq);
@ -296,14 +296,14 @@ namespace Microsoft.AspNetCore.SignalR.Client
try try
{ {
var payload = _protocolReaderWriter.WriteMessage(hubMessage); var payload = _protocolReaderWriter.WriteMessage(hubMessage);
_logger.SendInvocation(hubMessage.InvocationId); Log.SendInvocation(_logger, hubMessage.InvocationId);
await _connection.SendAsync(payload, irq.CancellationToken); await _connection.SendAsync(payload, irq.CancellationToken);
_logger.SendInvocationCompleted(hubMessage.InvocationId); Log.SendInvocationCompleted(_logger, hubMessage.InvocationId);
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.SendInvocationFailed(hubMessage.InvocationId, ex); Log.SendInvocationFailed(_logger, hubMessage.InvocationId, ex);
irq.Fail(ex); irq.Fail(ex);
TryRemoveInvocation(hubMessage.InvocationId, out _); TryRemoveInvocation(hubMessage.InvocationId, out _);
} }
@ -326,17 +326,17 @@ namespace Microsoft.AspNetCore.SignalR.Client
try try
{ {
_logger.PreparingNonBlockingInvocation(methodName, args.Length); Log.PreparingNonBlockingInvocation(_logger, methodName, args.Length);
var payload = _protocolReaderWriter.WriteMessage(invocationMessage); var payload = _protocolReaderWriter.WriteMessage(invocationMessage);
_logger.SendInvocation(invocationMessage.InvocationId); Log.SendInvocation(_logger, invocationMessage.InvocationId);
await _connection.SendAsync(payload, cancellationToken); await _connection.SendAsync(payload, cancellationToken);
_logger.SendInvocationCompleted(invocationMessage.InvocationId); Log.SendInvocationCompleted(_logger, invocationMessage.InvocationId);
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.SendInvocationFailed(invocationMessage.InvocationId, ex); Log.SendInvocationFailed(_logger, invocationMessage.InvocationId, ex);
throw; throw;
} }
} }
@ -344,22 +344,24 @@ namespace Microsoft.AspNetCore.SignalR.Client
private async Task OnDataReceivedAsync(byte[] data) private async Task OnDataReceivedAsync(byte[] data)
{ {
ResetTimeoutTimer(); ResetTimeoutTimer();
Log.ParsingMessages(_logger, data.Length);
if (_protocolReaderWriter.ReadMessages(data, _binder, out var messages)) if (_protocolReaderWriter.ReadMessages(data, _binder, out var messages))
{ {
Log.ReceivingMessages(_logger, messages.Count);
foreach (var message in messages) foreach (var message in messages)
{ {
InvocationRequest irq; InvocationRequest irq;
switch (message) switch (message)
{ {
case InvocationMessage invocation: case InvocationMessage invocation:
_logger.ReceivedInvocation(invocation.InvocationId, invocation.Target, Log.ReceivedInvocation(_logger, invocation.InvocationId, invocation.Target,
invocation.ArgumentBindingException != null ? null : invocation.Arguments); invocation.ArgumentBindingException != null ? null : invocation.Arguments);
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.DropCompletionMessage(completion.InvocationId); Log.DropCompletionMessage(_logger, completion.InvocationId);
return; return;
} }
DispatchInvocationCompletion(completion, irq); DispatchInvocationCompletion(completion, irq);
@ -369,27 +371,33 @@ 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.DropStreamMessage(streamItem.InvocationId); Log.DropStreamMessage(_logger, streamItem.InvocationId);
return; return;
} }
DispatchInvocationStreamItemAsync(streamItem, irq); DispatchInvocationStreamItemAsync(streamItem, irq);
break; break;
case PingMessage _: case PingMessage _:
Log.ReceivedPing(_logger);
// Nothing to do on receipt of a ping. // Nothing to do on receipt of a ping.
break; break;
default: default:
throw new InvalidOperationException($"Unexpected message type: {message.GetType().FullName}"); throw new InvalidOperationException($"Unexpected message type: {message.GetType().FullName}");
} }
} }
Log.ProcessedMessages(_logger, messages.Count);
}
else
{
Log.FailedParsing(_logger, data.Length);
} }
} }
private void Shutdown(Exception exception = null) private void Shutdown(Exception exception = null)
{ {
_logger.ShutdownConnection(); Log.ShutdownConnection(_logger);
if (exception != null) if (exception != null)
{ {
_logger.ShutdownWithError(exception); Log.ShutdownWithError(_logger, exception);
} }
lock (_pendingCallsLock) lock (_pendingCallsLock)
@ -401,7 +409,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
foreach (var outstandingCall in _pendingCalls.Values) foreach (var outstandingCall in _pendingCalls.Values)
{ {
_logger.RemoveInvocation(outstandingCall.InvocationId); Log.RemoveInvocation(_logger, outstandingCall.InvocationId);
if (exception != null) if (exception != null)
{ {
outstandingCall.Fail(exception); outstandingCall.Fail(exception);
@ -417,7 +425,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.ErrorDuringClosedEvent(ex); Log.ErrorDuringClosedEvent(_logger, ex);
} }
} }
@ -426,7 +434,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
// Find the handler // Find the handler
if (!_handlers.TryGetValue(invocation.Target, out var handlers)) if (!_handlers.TryGetValue(invocation.Target, out var handlers))
{ {
_logger.MissingHandler(invocation.Target); Log.MissingHandler(_logger, invocation.Target);
return; return;
} }
@ -447,7 +455,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.ErrorInvokingClientSideMethod(invocation.Target, ex); Log.ErrorInvokingClientSideMethod(_logger, invocation.Target, ex);
} }
} }
} }
@ -456,25 +464,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.ReceivedStreamItem(streamItem.InvocationId); Log.ReceivedStreamItem(_logger, streamItem.InvocationId);
if (irq.CancellationToken.IsCancellationRequested) if (irq.CancellationToken.IsCancellationRequested)
{ {
_logger.CancelingStreamItem(irq.InvocationId); Log.CancelingStreamItem(_logger, irq.InvocationId);
} }
else if (!await irq.StreamItem(streamItem.Item)) else if (!await irq.StreamItem(streamItem.Item))
{ {
_logger.ReceivedStreamItemAfterClose(irq.InvocationId); Log.ReceivedStreamItemAfterClose(_logger, irq.InvocationId);
} }
} }
private void DispatchInvocationCompletion(CompletionMessage completion, InvocationRequest irq) private void DispatchInvocationCompletion(CompletionMessage completion, InvocationRequest irq)
{ {
_logger.ReceivedInvocationCompletion(completion.InvocationId); Log.ReceivedInvocationCompletion(_logger, completion.InvocationId);
if (irq.CancellationToken.IsCancellationRequested) if (irq.CancellationToken.IsCancellationRequested)
{ {
_logger.CancelingInvocationCompletion(irq.InvocationId); Log.CancelingInvocationCompletion(_logger, irq.InvocationId);
} }
else else
{ {
@ -486,7 +494,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
if (_connectionActive.Token.IsCancellationRequested) if (_connectionActive.Token.IsCancellationRequested)
{ {
_logger.InvokeAfterTermination(invocationId); Log.InvokeAfterTermination(_logger, invocationId);
throw new InvalidOperationException("Connection has been terminated."); throw new InvalidOperationException("Connection has been terminated.");
} }
} }
@ -500,7 +508,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
ThrowIfConnectionTerminated(irq.InvocationId); ThrowIfConnectionTerminated(irq.InvocationId);
if (_pendingCalls.ContainsKey(irq.InvocationId)) if (_pendingCalls.ContainsKey(irq.InvocationId))
{ {
_logger.InvocationAlreadyInUse(irq.InvocationId); Log.InvocationAlreadyInUse(_logger, 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
@ -569,7 +577,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
if (!_connection._pendingCalls.TryGetValue(invocationId, out var irq)) if (!_connection._pendingCalls.TryGetValue(invocationId, out var irq))
{ {
_connection._logger.ReceivedUnexpectedResponse(invocationId); Log.ReceivedUnexpectedResponse(_connection._logger, invocationId);
return null; return null;
} }
return irq.ResultType; return irq.ResultType;
@ -579,7 +587,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
{ {
if (!_connection._handlers.TryGetValue(methodName, out var handlers)) if (!_connection._handlers.TryGetValue(methodName, out var handlers))
{ {
_connection._logger.MissingHandler(methodName); Log.MissingHandler(_connection._logger, methodName);
return Type.EmptyTypes; return Type.EmptyTypes;
} }

304
src/Microsoft.AspNetCore.SignalR.Client.Core/Internal/SignalRClientLoggerExtensions.cs
View File

@ -1,304 +0,0 @@
// 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, int, Exception> _preparingNonBlockingInvocation =
LoggerMessage.Define<string, int>(LogLevel.Trace, new EventId(1, nameof(PreparingNonBlockingInvocation)), "Preparing non-blocking invocation 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, new EventId(2, nameof(PreparingBlockingInvocation)), "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, new EventId(3, nameof(RegisterInvocation)), "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, new EventId(4, nameof(IssueInvocation)), "Issuing Invocation '{invocationId}': {returnType} {methodName}({args}).");
private static readonly Action<ILogger, string, Exception> _sendInvocation =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(5, nameof(SendInvocation)), "Sending Invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _sendInvocationCompleted =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(6, nameof(SendInvocationCompleted)), "Sending Invocation '{invocationId}' completed.");
private static readonly Action<ILogger, string, Exception> _sendInvocationFailed =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(7, nameof(SendInvocationFailed)), "Sending Invocation '{invocationId}' failed.");
private static readonly Action<ILogger, string, string, string, Exception> _receivedInvocation =
LoggerMessage.Define<string, string, string>(LogLevel.Trace, new EventId(8, nameof(ReceivedInvocation)), "Received Invocation '{invocationId}': {methodName}({args}).");
private static readonly Action<ILogger, string, Exception> _dropCompletionMessage =
LoggerMessage.Define<string>(LogLevel.Warning, new EventId(9, nameof(DropCompletionMessage)), "Dropped unsolicited Completion message for invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _dropStreamMessage =
LoggerMessage.Define<string>(LogLevel.Warning, new EventId(10, nameof(DropStreamMessage)), "Dropped unsolicited StreamItem message for invocation '{invocationId}'.");
private static readonly Action<ILogger, Exception> _shutdownConnection =
LoggerMessage.Define(LogLevel.Trace, new EventId(11, nameof(ShutdownConnection)), "Shutting down connection.");
private static readonly Action<ILogger, Exception> _shutdownWithError =
LoggerMessage.Define(LogLevel.Error, new EventId(12, nameof(ShutdownWithError)), "Connection is shutting down due to an error.");
private static readonly Action<ILogger, string, Exception> _removeInvocation =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(13, nameof(RemoveInvocation)), "Removing pending invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _missingHandler =
LoggerMessage.Define<string>(LogLevel.Warning, new EventId(14, nameof(MissingHandler)), "Failed to find handler for '{target}' method.");
private static readonly Action<ILogger, string, Exception> _receivedStreamItem =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(15, nameof(ReceivedStreamItem)), "Received StreamItem for Invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _cancelingStreamItem =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(16, nameof(CancelingStreamItem)), "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, new EventId(17, nameof(ReceivedStreamItemAfterClose)), "Invocation {invocationId} received stream item after channel was closed.");
private static readonly Action<ILogger, string, Exception> _receivedInvocationCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(18, nameof(ReceivedInvocationCompletion)), "Received Completion for Invocation {invocationId}.");
private static readonly Action<ILogger, string, Exception> _cancelingInvocationCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(19, nameof(CancelingInvocationCompletion)), "Canceling dispatch of Completion message for Invocation {invocationId}. The invocation was canceled.");
private static readonly Action<ILogger, string, Exception> _cancelingCompletion =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(20, nameof(CancelingCompletion)), "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, new EventId(21, nameof(InvokeAfterTermination)), "Invoke for Invocation '{invocationId}' was called after the connection was terminated.");
private static readonly Action<ILogger, string, Exception> _invocationAlreadyInUse =
LoggerMessage.Define<string>(LogLevel.Critical, new EventId(22, nameof(InvocationAlreadyInUse)), "Invocation ID '{invocationId}' is already in use.");
private static readonly Action<ILogger, string, Exception> _receivedUnexpectedResponse =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(23, nameof(ReceivedUnexpectedResponse)), "Unsolicited response received for invocation '{invocationId}'.");
private static readonly Action<ILogger, string, Exception> _hubProtocol =
LoggerMessage.Define<string>(LogLevel.Information, new EventId(24, nameof(HubProtocol)), "Using HubProtocol '{protocol}'.");
private static readonly Action<ILogger, string, string, string, int, Exception> _preparingStreamingInvocation =
LoggerMessage.Define<string, string, string, int>(LogLevel.Trace, new EventId(25, nameof(PreparingStreamingInvocation)), "Preparing streaming invocation '{invocationId}' of '{target}', with return type '{returnType}' and {argumentCount} argument(s).");
private static readonly Action<ILogger, Exception> _resettingKeepAliveTimer =
LoggerMessage.Define(LogLevel.Trace, new EventId(26, nameof(ResettingKeepAliveTimer)), "Resetting keep-alive timer, received a message from the server.");
private static readonly Action<ILogger, Exception> _errorDuringClosedEvent =
LoggerMessage.Define(LogLevel.Error, new EventId(27, nameof(ErrorDuringClosedEvent)), "An exception was thrown in the handler for the Closed event.");
// Category: Streaming and NonStreaming
private static readonly Action<ILogger, string, Exception> _invocationCreated =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(1, nameof(InvocationCreated)), "Invocation {invocationId} created.");
private static readonly Action<ILogger, string, Exception> _invocationDisposed =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(2, nameof(InvocationDisposed)), "Invocation {invocationId} disposed.");
private static readonly Action<ILogger, string, Exception> _invocationCompleted =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(3, nameof(InvocationCompleted)), "Invocation {invocationId} marked as completed.");
private static readonly Action<ILogger, string, Exception> _invocationFailed =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(4, nameof(InvocationFailed)), "Invocation {invocationId} marked as failed.");
// Category: Streaming
private static readonly Action<ILogger, string, Exception> _errorWritingStreamItem =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(5, nameof(ErrorWritingStreamItem)), "Invocation {invocationId} caused an error trying to write a stream item.");
private static readonly Action<ILogger, string, Exception> _receivedUnexpectedComplete =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(6, nameof(ReceivedUnexpectedComplete)), "Invocation {invocationId} received a completion result, but was invoked as a streaming invocation.");
// Category: NonStreaming
private static readonly Action<ILogger, string, Exception> _streamItemOnNonStreamInvocation =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(5, nameof(StreamItemOnNonStreamInvocation)), "Invocation {invocationId} received stream item but was invoked as a non-streamed invocation.");
private static readonly Action<ILogger, string, Exception> _errorInvokingClientSideMethod =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(6, nameof(ErrorInvokingClientSideMethod)), "Invoking client side method '{methodName}' failed.");
public static void PreparingNonBlockingInvocation(this ILogger logger, string target, int count)
{
_preparingNonBlockingInvocation(logger, 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 PreparingStreamingInvocation(this ILogger logger, string invocationId, string target, string returnType, int count)
{
_preparingStreamingInvocation(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 = args == null ? string.Empty : string.Join(", ", args.Select(a => a?.GetType().FullName ?? "(null)"));
_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 = args == null ? string.Empty : string.Join(", ", args.Select(a => a?.GetType().FullName ?? "(null)"));
_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 CancelingInvocationCompletion(this ILogger logger, string invocationId)
{
_cancelingInvocationCompletion(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 HubProtocol(this ILogger logger, string hubProtocol)
{
_hubProtocol(logger, hubProtocol, 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 ErrorWritingStreamItem(this ILogger logger, string invocationId, Exception exception)
{
_errorWritingStreamItem(logger, invocationId, exception);
}
public static void ReceivedUnexpectedComplete(this ILogger logger, string invocationId)
{
_receivedUnexpectedComplete(logger, invocationId, null);
}
public static void StreamItemOnNonStreamInvocation(this ILogger logger, string invocationId)
{
_streamItemOnNonStreamInvocation(logger, invocationId, null);
}
public static void ErrorInvokingClientSideMethod(this ILogger logger, string methodName, Exception exception)
{
_errorInvokingClientSideMethod(logger, methodName, exception);
}
public static void ResettingKeepAliveTimer(this ILogger logger)
{
_resettingKeepAliveTimer(logger, null);
}
public static void ErrorDuringClosedEvent(this ILogger logger, Exception exception)
{
_errorDuringClosedEvent(logger, exception);
}
}
}

83
src/Microsoft.AspNetCore.SignalR.Client.Core/InvocationRequest.cs
View File

@ -3,9 +3,8 @@
using System; using System;
using System.Threading; using System.Threading;
using System.Threading.Tasks;
using System.Threading.Channels; using System.Threading.Channels;
using Microsoft.AspNetCore.SignalR.Client.Internal; using System.Threading.Tasks;
using Microsoft.AspNetCore.SignalR.Internal.Protocol; using Microsoft.AspNetCore.SignalR.Internal.Protocol;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
@ -32,7 +31,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
Logger = logger; Logger = logger;
HubConnection = hubConnection; HubConnection = hubConnection;
Logger.InvocationCreated(InvocationId); Log.InvocationCreated(Logger, InvocationId);
} }
public static InvocationRequest Invoke(CancellationToken cancellationToken, Type resultType, string invocationId, ILoggerFactory loggerFactory, HubConnection hubConnection, out Task<object> result) public static InvocationRequest Invoke(CancellationToken cancellationToken, Type resultType, string invocationId, ILoggerFactory loggerFactory, HubConnection hubConnection, out Task<object> result)
@ -58,7 +57,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
public virtual void Dispose() public virtual void Dispose()
{ {
Logger.InvocationDisposed(InvocationId); Log.InvocationDisposed(Logger, InvocationId);
// Just in case it hasn't already been completed // Just in case it hasn't already been completed
Cancel(); Cancel();
@ -79,10 +78,10 @@ namespace Microsoft.AspNetCore.SignalR.Client
public override void Complete(CompletionMessage completionMessage) public override void Complete(CompletionMessage completionMessage)
{ {
Logger.InvocationCompleted(InvocationId); Log.InvocationCompleted(Logger, InvocationId);
if (completionMessage.Result != null) if (completionMessage.Result != null)
{ {
Logger.ReceivedUnexpectedComplete(InvocationId); Log.ReceivedUnexpectedComplete(Logger, InvocationId);
_channel.Writer.TryComplete(new InvalidOperationException("Server provided a result in a completion response to a streamed invocation.")); _channel.Writer.TryComplete(new InvalidOperationException("Server provided a result in a completion response to a streamed invocation."));
} }
@ -97,7 +96,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
public override void Fail(Exception exception) public override void Fail(Exception exception)
{ {
Logger.InvocationFailed(InvocationId); Log.InvocationFailed(Logger, InvocationId);
_channel.Writer.TryComplete(exception); _channel.Writer.TryComplete(exception);
} }
@ -115,7 +114,7 @@ namespace Microsoft.AspNetCore.SignalR.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
Logger.ErrorWritingStreamItem(InvocationId, ex); Log.ErrorWritingStreamItem(Logger, InvocationId, ex);
} }
return true; return true;
} }
@ -145,19 +144,19 @@ namespace Microsoft.AspNetCore.SignalR.Client
return; return;
} }
Logger.InvocationCompleted(InvocationId); Log.InvocationCompleted(Logger, InvocationId);
_completionSource.TrySetResult(completionMessage.Result); _completionSource.TrySetResult(completionMessage.Result);
} }
public override void Fail(Exception exception) public override void Fail(Exception exception)
{ {
Logger.InvocationFailed(InvocationId); Log.InvocationFailed(Logger, InvocationId);
_completionSource.TrySetException(exception); _completionSource.TrySetException(exception);
} }
public override ValueTask<bool> StreamItem(object item) public override ValueTask<bool> StreamItem(object item)
{ {
Logger.StreamItemOnNonStreamInvocation(InvocationId); Log.StreamItemOnNonStreamInvocation(Logger, InvocationId);
_completionSource.TrySetException(new InvalidOperationException($"Streaming hub methods must be invoked with the '{nameof(HubConnection)}.{nameof(HubConnection.StreamAsync)}' method.")); _completionSource.TrySetException(new InvalidOperationException($"Streaming hub methods must be invoked with the '{nameof(HubConnection)}.{nameof(HubConnection.StreamAsync)}' method."));
// We "delivered" the stream item successfully as far as the caller cares // We "delivered" the stream item successfully as far as the caller cares
@ -169,5 +168,67 @@ namespace Microsoft.AspNetCore.SignalR.Client
_completionSource.TrySetCanceled(); _completionSource.TrySetCanceled();
} }
} }
private static class Log
{
// Category: Streaming and NonStreaming
private static readonly Action<ILogger, string, Exception> _invocationCreated =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(1, "InvocationCreated"), "Invocation {invocationId} created.");
private static readonly Action<ILogger, string, Exception> _invocationDisposed =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(2, "InvocationDisposed"), "Invocation {invocationId} disposed.");
private static readonly Action<ILogger, string, Exception> _invocationCompleted =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(3, "InvocationCompleted"), "Invocation {invocationId} marked as completed.");
private static readonly Action<ILogger, string, Exception> _invocationFailed =
LoggerMessage.Define<string>(LogLevel.Trace, new EventId(4, "InvocationFailed"), "Invocation {invocationId} marked as failed.");
// Category: Streaming
private static readonly Action<ILogger, string, Exception> _errorWritingStreamItem =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(5, "ErrorWritingStreamItem"), "Invocation {invocationId} caused an error trying to write a stream item.");
private static readonly Action<ILogger, string, Exception> _receivedUnexpectedComplete =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(6, "ReceivedUnexpectedComplete"), "Invocation {invocationId} received a completion result, but was invoked as a streaming invocation.");
// Category: NonStreaming
private static readonly Action<ILogger, string, Exception> _streamItemOnNonStreamInvocation =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(5, "StreamItemOnNonStreamInvocation"), "Invocation {invocationId} received stream item but was invoked as a non-streamed invocation.");
public static void InvocationCreated(ILogger logger, string invocationId)
{
_invocationCreated(logger, invocationId, null);
}
public static void InvocationDisposed(ILogger logger, string invocationId)
{
_invocationDisposed(logger, invocationId, null);
}
public static void InvocationCompleted(ILogger logger, string invocationId)
{
_invocationCompleted(logger, invocationId, null);
}
public static void InvocationFailed(ILogger logger, string invocationId)
{
_invocationFailed(logger, invocationId, null);
}
public static void ErrorWritingStreamItem(ILogger logger, string invocationId, Exception exception)
{
_errorWritingStreamItem(logger, invocationId, exception);
}
public static void ReceivedUnexpectedComplete(ILogger logger, string invocationId)
{
_receivedUnexpectedComplete(logger, invocationId, null);
}
public static void StreamItemOnNonStreamInvocation(ILogger logger, string invocationId)
{
_streamItemOnNonStreamInvocation(logger, invocationId, null);
}
}
} }
} }

223
src/Microsoft.AspNetCore.Sockets.Client.Http/HttpConnection.Log.cs Normal file
View File

@ -0,0 +1,223 @@
// 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 Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Client
{
public partial class HttpConnection
{
private static class Log
{
private static readonly Action<ILogger, Exception> _httpConnectionStarting =
LoggerMessage.Define(LogLevel.Debug, new EventId(1, "HttpConnectionStarting"), "Starting connection.");
private static readonly Action<ILogger, Exception> _httpConnectionClosed =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, "HttpConnectionClosed"), "Connection was closed from a different thread.");
private static readonly Action<ILogger, string, Uri, Exception> _startingTransport =
LoggerMessage.Define<string, Uri>(LogLevel.Debug, new EventId(3, "StartingTransport"), "Starting transport '{transport}' with Url: {url}.");
private static readonly Action<ILogger, Exception> _processRemainingMessages =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "ProcessRemainingMessages"), "Ensuring all outstanding messages are processed.");
private static readonly Action<ILogger, Exception> _drainEvents =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, "DrainEvents"), "Draining event queue.");
private static readonly Action<ILogger, Exception> _completeClosed =
LoggerMessage.Define(LogLevel.Debug, new EventId(6, "CompleteClosed"), "Completing Closed task.");
private static readonly Action<ILogger, Uri, Exception> _establishingConnection =
LoggerMessage.Define<Uri>(LogLevel.Debug, new EventId(7, "EstablishingConnection"), "Establishing Connection at: {url}.");
private static readonly Action<ILogger, Uri, Exception> _errorWithNegotiation =
LoggerMessage.Define<Uri>(LogLevel.Error, new EventId(8, "ErrorWithNegotiation"), "Failed to start connection. Error getting negotiation response from '{url}'.");
private static readonly Action<ILogger, string, Exception> _errorStartingTransport =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(9, "ErrorStartingTransport"), "Failed to start connection. Error starting transport '{transport}'.");
private static readonly Action<ILogger, Exception> _httpReceiveStarted =
LoggerMessage.Define(LogLevel.Trace, new EventId(10, "HttpReceiveStarted"), "Beginning receive loop.");
private static readonly Action<ILogger, Exception> _skipRaisingReceiveEvent =
LoggerMessage.Define(LogLevel.Debug, new EventId(11, "SkipRaisingReceiveEvent"), "Message received but connection is not connected. Skipping raising Received event.");
private static readonly Action<ILogger, Exception> _scheduleReceiveEvent =
LoggerMessage.Define(LogLevel.Debug, new EventId(12, "ScheduleReceiveEvent"), "Scheduling raising Received event.");
private static readonly Action<ILogger, Exception> _raiseReceiveEvent =
LoggerMessage.Define(LogLevel.Debug, new EventId(13, "RaiseReceiveEvent"), "Raising Received event.");
private static readonly Action<ILogger, Exception> _failedReadingMessage =
LoggerMessage.Define(LogLevel.Debug, new EventId(14, "FailedReadingMessage"), "Could not read message.");
private static readonly Action<ILogger, Exception> _errorReceiving =
LoggerMessage.Define(LogLevel.Error, new EventId(15, "ErrorReceiving"), "Error receiving message.");
private static readonly Action<ILogger, Exception> _endReceive =
LoggerMessage.Define(LogLevel.Trace, new EventId(16, "EndReceive"), "Ending receive loop.");
private static readonly Action<ILogger, Exception> _sendingMessage =
LoggerMessage.Define(LogLevel.Debug, new EventId(17, "SendingMessage"), "Sending message.");
private static readonly Action<ILogger, Exception> _stoppingClient =
LoggerMessage.Define(LogLevel.Information, new EventId(18, "StoppingClient"), "Stopping client.");
private static readonly Action<ILogger, string, Exception> _exceptionThrownFromCallback =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(19, "ExceptionThrownFromCallback"), "An exception was thrown from the '{callback}' callback.");
private static readonly Action<ILogger, Exception> _disposingClient =
LoggerMessage.Define(LogLevel.Information, new EventId(20, "DisposingClient"), "Disposing client.");
private static readonly Action<ILogger, Exception> _abortingClient =
LoggerMessage.Define(LogLevel.Error, new EventId(21, "AbortingClient"), "Aborting client.");
private static readonly Action<ILogger, Exception> _errorDuringClosedEvent =
LoggerMessage.Define(LogLevel.Error, new EventId(22, "ErrorDuringClosedEvent"), "An exception was thrown in the handler for the Closed event.");
private static readonly Action<ILogger, Exception> _skippingStop =
LoggerMessage.Define(LogLevel.Debug, new EventId(23, "SkippingStop"), "Skipping stop, connection is already stopped.");
private static readonly Action<ILogger, Exception> _skippingDispose =
LoggerMessage.Define(LogLevel.Debug, new EventId(24, "SkippingDispose"), "Skipping dispose, connection is already disposed.");
private static readonly Action<ILogger, string, string, Exception> _connectionStateChanged =
LoggerMessage.Define<string, string>(LogLevel.Debug, new EventId(25, "ConnectionStateChanged"), "Connection state changed from {previousState} to {newState}.");
public static void HttpConnectionStarting(ILogger logger)
{
_httpConnectionStarting(logger, null);
}
public static void HttpConnectionClosed(ILogger logger)
{
_httpConnectionClosed(logger, null);
}
public static void StartingTransport(ILogger logger, ITransport transport, Uri url)
{
if (logger.IsEnabled(LogLevel.Debug))
{
_startingTransport(logger, transport.GetType().Name, url, null);
}
}
public static void ProcessRemainingMessages(ILogger logger)
{
_processRemainingMessages(logger, null);
}
public static void DrainEvents(ILogger logger)
{
_drainEvents(logger, null);
}
public static void CompleteClosed(ILogger logger)
{
_completeClosed(logger, null);
}
public static void EstablishingConnection(ILogger logger, Uri url)
{
_establishingConnection(logger, url, null);
}
public static void ErrorWithNegotiation(ILogger logger, Uri url, Exception exception)
{
_errorWithNegotiation(logger, url, exception);
}
public static void ErrorStartingTransport(ILogger logger, ITransport transport, Exception exception)
{
if (logger.IsEnabled(LogLevel.Error))
{
_errorStartingTransport(logger, transport.GetType().Name, exception);
}
}
public static void HttpReceiveStarted(ILogger logger)
{
_httpReceiveStarted(logger, null);
}
public static void SkipRaisingReceiveEvent(ILogger logger)
{
_skipRaisingReceiveEvent(logger, null);
}
public static void ScheduleReceiveEvent(ILogger logger)
{
_scheduleReceiveEvent(logger, null);
}
public static void RaiseReceiveEvent(ILogger logger)
{
_raiseReceiveEvent(logger, null);
}
public static void FailedReadingMessage(ILogger logger)
{
_failedReadingMessage(logger, null);
}
public static void ErrorReceiving(ILogger logger, Exception exception)
{
_errorReceiving(logger, exception);
}
public static void EndReceive(ILogger logger)
{
_endReceive(logger, null);
}
public static void SendingMessage(ILogger logger)
{
_sendingMessage(logger, null);
}
public static void AbortingClient(ILogger logger, Exception ex)
{
_abortingClient(logger, ex);
}
public static void StoppingClient(ILogger logger)
{
_stoppingClient(logger, null);
}
public static void DisposingClient(ILogger logger)
{
_disposingClient(logger, null);
}
public static void SkippingDispose(ILogger logger)
{
_skippingDispose(logger, null);
}
public static void ConnectionStateChanged(ILogger logger, HttpConnection.ConnectionState previousState, HttpConnection.ConnectionState newState)
{
if (logger.IsEnabled(LogLevel.Debug))
{
_connectionStateChanged(logger, previousState.ToString(), newState.ToString(), null);
}
}
public static void SkippingStop(ILogger logger)
{
_skippingStop(logger, null);
}
public static void ExceptionThrownFromCallback(ILogger logger, string callbackName, Exception exception)
{
_exceptionThrownFromCallback(logger, callbackName, exception);
}
public static void ErrorDuringClosedEvent(ILogger logger, Exception exception)
{
_errorDuringClosedEvent(logger, exception);
}
}
}
}

50
src/Microsoft.AspNetCore.Sockets.Client.Http/HttpConnection.cs
View File

@ -21,7 +21,7 @@ using Newtonsoft.Json;
namespace Microsoft.AspNetCore.Sockets.Client namespace Microsoft.AspNetCore.Sockets.Client
{ {
public class HttpConnection : IConnection public partial class HttpConnection : IConnection
{ {
private static readonly TimeSpan HttpClientTimeout = TimeSpan.FromSeconds(120); private static readonly TimeSpan HttpClientTimeout = TimeSpan.FromSeconds(120);
@ -144,7 +144,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
private async Task StartAsyncInternal() private async Task StartAsyncInternal()
{ {
_logger.HttpConnectionStarting(); Log.HttpConnectionStarting(_logger);
try try
{ {
@ -162,7 +162,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
// Connection is being disposed while start was in progress // Connection is being disposed while start was in progress
if (_connectionState == ConnectionState.Disposed) if (_connectionState == ConnectionState.Disposed)
{ {
_logger.HttpConnectionClosed(); Log.HttpConnectionClosed(_logger);
return; return;
} }
@ -170,7 +170,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
connectUrl = CreateConnectUrl(Url, negotiationResponse); connectUrl = CreateConnectUrl(Url, negotiationResponse);
} }
_logger.StartingTransport(_transport, connectUrl); Log.StartingTransport(_logger, _transport, connectUrl);
await StartTransport(connectUrl); await StartTransport(connectUrl);
} }
catch catch
@ -200,16 +200,16 @@ namespace Microsoft.AspNetCore.Sockets.Client
// to make sure that the message removed from the channel is processed before we drain the queue. // to make sure that the message removed from the channel is processed before we drain the queue.
// There is a short window between we start the channel and assign the _receiveLoopTask a value. // There is a short window between we start the channel and assign the _receiveLoopTask a value.
// To make sure that _receiveLoopTask can be awaited (i.e. is not null) we need to await _startTask. // To make sure that _receiveLoopTask can be awaited (i.e. is not null) we need to await _startTask.
_logger.ProcessRemainingMessages(); Log.ProcessRemainingMessages(_logger);
await _startTcs.Task; await _startTcs.Task;
await _receiveLoopTask; await _receiveLoopTask;
_logger.DrainEvents(); Log.DrainEvents(_logger);
await Task.WhenAny(_eventQueue.Drain().NoThrow(), Task.Delay(_eventQueueDrainTimeout)); await Task.WhenAny(_eventQueue.Drain().NoThrow(), Task.Delay(_eventQueueDrainTimeout));
_logger.CompleteClosed(); Log.CompleteClosed(_logger);
_logScope.ConnectionId = null; _logScope.ConnectionId = null;
// At this point the connection can be either in the Connected or Disposed state. The state should be changed // At this point the connection can be either in the Connected or Disposed state. The state should be changed
@ -235,7 +235,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
catch (Exception ex) catch (Exception ex)
{ {
// Suppress (but log) the exception, this is user code // Suppress (but log) the exception, this is user code
_logger.ErrorDuringClosedEvent(ex); Log.ErrorDuringClosedEvent(_logger, ex);
} }
}, null); }, null);
@ -249,7 +249,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
try try
{ {
// Get a connection ID from the server // Get a connection ID from the server
logger.EstablishingConnection(url); Log.EstablishingConnection(logger, url);
var urlBuilder = new UriBuilder(url); var urlBuilder = new UriBuilder(url);
if (!urlBuilder.Path.EndsWith("/")) if (!urlBuilder.Path.EndsWith("/"))
{ {
@ -270,7 +270,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
logger.ErrorWithNegotiation(url, ex); Log.ErrorWithNegotiation(logger, url, ex);
throw; throw;
} }
} }
@ -345,7 +345,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.ErrorStartingTransport(_transport, ex); Log.ErrorStartingTransport(_logger, _transport, ex);
throw; throw;
} }
} }
@ -377,13 +377,13 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
try try
{ {
_logger.HttpReceiveStarted(); Log.HttpReceiveStarted(_logger);
while (true) while (true)
{ {
if (_connectionState != ConnectionState.Connected) if (_connectionState != ConnectionState.Connected)
{ {
_logger.SkipRaisingReceiveEvent(); Log.SkipRaisingReceiveEvent(_logger);
break; break;
} }
@ -395,12 +395,12 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
if (!buffer.IsEmpty) if (!buffer.IsEmpty)
{ {
_logger.ScheduleReceiveEvent(); Log.ScheduleReceiveEvent(_logger);
var data = buffer.ToArray(); var data = buffer.ToArray();
_ = _eventQueue.Enqueue(async () => _ = _eventQueue.Enqueue(async () =>
{ {
_logger.RaiseReceiveEvent(); Log.RaiseReceiveEvent(_logger);
// Copying the callbacks to avoid concurrency issues // Copying the callbacks to avoid concurrency issues
ReceiveCallback[] callbackCopies; ReceiveCallback[] callbackCopies;
@ -418,7 +418,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.ExceptionThrownFromCallback(nameof(OnReceived), ex); Log.ExceptionThrownFromCallback(_logger, nameof(OnReceived), ex);
} }
} }
}); });
@ -439,14 +439,14 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
Input.Complete(ex); Input.Complete(ex);
_logger.ErrorReceiving(ex); Log.ErrorReceiving(_logger, ex);
} }
finally finally
{ {
Input.Complete(); Input.Complete();
} }
_logger.EndReceive(); Log.EndReceive(_logger);
} }
public async Task SendAsync(byte[] data, CancellationToken cancellationToken = default) => public async Task SendAsync(byte[] data, CancellationToken cancellationToken = default) =>
@ -465,7 +465,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
"Cannot send messages when the connection is not in the Connected state."); "Cannot send messages when the connection is not in the Connected state.");
} }
_logger.SendingMessage(); Log.SendingMessage(_logger);
cancellationToken.ThrowIfCancellationRequested(); cancellationToken.ThrowIfCancellationRequested();
@ -494,7 +494,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
if (!(_connectionState == ConnectionState.Connecting || _connectionState == ConnectionState.Connected)) if (!(_connectionState == ConnectionState.Connecting || _connectionState == ConnectionState.Connected))
{ {
_logger.SkippingStop(); Log.SkippingStop(_logger);
return; return;
} }
} }
@ -507,7 +507,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
// See comment at AbortAsync for more discussion on the thread-safety of this. // See comment at AbortAsync for more discussion on the thread-safety of this.
_abortException = exception; _abortException = exception;
_logger.StoppingClient(); Log.StoppingClient(_logger);
try try
{ {
@ -570,13 +570,13 @@ namespace Microsoft.AspNetCore.Sockets.Client
if (ChangeState(to: ConnectionState.Disposed) == ConnectionState.Disposed) if (ChangeState(to: ConnectionState.Disposed) == ConnectionState.Disposed)
{ {
_logger.SkippingDispose(); Log.SkippingDispose(_logger);
// the connection was already disposed // the connection was already disposed
return; return;
} }
_logger.DisposingClient(); Log.DisposingClient(_logger);
_httpClient?.Dispose(); _httpClient?.Dispose();
_scopeDisposable.Dispose(); _scopeDisposable.Dispose();
@ -638,7 +638,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
_connectionState = to; _connectionState = to;
} }
_logger.ConnectionStateChanged(state, to); Log.ConnectionStateChanged(_logger, state, to);
return state; return state;
} }
} }
@ -649,7 +649,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
var state = _connectionState; var state = _connectionState;
_connectionState = to; _connectionState = to;
_logger.ConnectionStateChanged(state, to); Log.ConnectionStateChanged(_logger, state, to);
return state; return state;
} }
} }

443
src/Microsoft.AspNetCore.Sockets.Client.Http/Internal/SocketClientLoggerExtensions.cs
View File

@ -1,443 +0,0 @@
// 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.Net.WebSockets;
using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Client.Internal
{
internal static class SocketClientLoggerExtensions
{
// Category: Shared with LongPollingTransport, WebSocketsTransport and ServerSentEventsTransport
private static readonly Action<ILogger, TransferMode, Exception> _startTransport =
LoggerMessage.Define<TransferMode>(LogLevel.Information, new EventId(1, nameof(StartTransport)), "Starting transport. Transfer mode: {transferMode}.");
private static readonly Action<ILogger, Exception> _transportStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, nameof(TransportStopped)), "Transport stopped.");
private static readonly Action<ILogger, Exception> _startReceive =
LoggerMessage.Define(LogLevel.Debug, new EventId(3, nameof(StartReceive)), "Starting receive loop.");
private static readonly Action<ILogger, Exception> _receiveStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, nameof(ReceiveStopped)), "Receive loop stopped.");
private static readonly Action<ILogger, Exception> _receiveCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, nameof(ReceiveCanceled)), "Receive loop canceled.");
private static readonly Action<ILogger, Exception> _transportStopping =
LoggerMessage.Define(LogLevel.Information, new EventId(6, nameof(TransportStopping)), "Transport is stopping.");
private static readonly Action<ILogger, Exception> _sendStarted =
LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(SendStarted)), "Starting the send loop.");
private static readonly Action<ILogger, Exception> _sendStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(8, nameof(SendStopped)), "Send loop stopped.");
private static readonly Action<ILogger, Exception> _sendCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(9, nameof(SendCanceled)), "Send loop canceled.");
// Category: WebSocketsTransport
private static readonly Action<ILogger, WebSocketCloseStatus?, Exception> _webSocketClosed =
LoggerMessage.Define<WebSocketCloseStatus?>(LogLevel.Information, new EventId(10, nameof(WebSocketClosed)), "Websocket closed by the server. Close status {closeStatus}.");
private static readonly Action<ILogger, WebSocketMessageType, int, bool, Exception> _messageReceived =
LoggerMessage.Define<WebSocketMessageType, int, bool>(LogLevel.Debug, new EventId(11, nameof(MessageReceived)), "Message received. Type: {messageType}, size: {count}, EndOfMessage: {endOfMessage}.");
private static readonly Action<ILogger, int, Exception> _messageToApp =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(12, nameof(MessageToApp)), "Passing message to application. Payload size: {count}.");
private static readonly Action<ILogger, long, Exception> _receivedFromApp =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(13, nameof(ReceivedFromApp)), "Received message from application. Payload size: {count}.");
private static readonly Action<ILogger, Exception> _sendMessageCanceled =
LoggerMessage.Define(LogLevel.Information, new EventId(14, nameof(SendMessageCanceled)), "Sending a message canceled.");
private static readonly Action<ILogger, Exception> _errorSendingMessage =
LoggerMessage.Define(LogLevel.Error, new EventId(15, nameof(ErrorSendingMessage)), "Error while sending a message.");
private static readonly Action<ILogger, Exception> _closingWebSocket =
LoggerMessage.Define(LogLevel.Information, new EventId(16, nameof(ClosingWebSocket)), "Closing WebSocket.");
private static readonly Action<ILogger, Exception> _closingWebSocketFailed =
LoggerMessage.Define(LogLevel.Information, new EventId(17, nameof(ClosingWebSocketFailed)), "Closing webSocket failed.");
private static readonly Action<ILogger, Exception> _cancelMessage =
LoggerMessage.Define(LogLevel.Debug, new EventId(18, nameof(CancelMessage)), "Canceled passing message to application.");
// Category: ServerSentEventsTransport and LongPollingTransport
private static readonly Action<ILogger, long, Uri, Exception> _sendingMessages =
LoggerMessage.Define<long, Uri>(LogLevel.Debug, new EventId(10, nameof(SendingMessages)), "Sending {count} bytes to the server using url: {url}.");
private static readonly Action<ILogger, Exception> _sentSuccessfully =
LoggerMessage.Define(LogLevel.Debug, new EventId(11, nameof(SentSuccessfully)), "Message(s) sent successfully.");
private static readonly Action<ILogger, Exception> _noMessages =
LoggerMessage.Define(LogLevel.Debug, new EventId(12, nameof(NoMessages)), "No messages in batch to send.");
private static readonly Action<ILogger, Uri, Exception> _errorSending =
LoggerMessage.Define<Uri>(LogLevel.Error, new EventId(13, nameof(ErrorSending)), "Error while sending to '{url}'.");
// Category: ServerSentEventsTransport
private static readonly Action<ILogger, Exception> _eventStreamEnded =
LoggerMessage.Define(LogLevel.Debug, new EventId(14, nameof(EventStreamEnded)), "Server-Sent Event Stream ended.");
// Category: LongPollingTransport
private static readonly Action<ILogger, Exception> _closingConnection =
LoggerMessage.Define(LogLevel.Debug, new EventId(14, nameof(ClosingConnection)), "The server is closing the connection.");
private static readonly Action<ILogger, Exception> _receivedMessages =
LoggerMessage.Define(LogLevel.Debug, new EventId(15, nameof(ReceivedMessages)), "Received messages from the server.");
private static readonly Action<ILogger, Uri, Exception> _errorPolling =
LoggerMessage.Define<Uri>(LogLevel.Error, new EventId(16, nameof(ErrorPolling)), "Error while polling '{pollUrl}'.");
// Category: HttpConnection
private static readonly Action<ILogger, Exception> _httpConnectionStarting =
LoggerMessage.Define(LogLevel.Debug, new EventId(1, nameof(HttpConnectionStarting)), "Starting connection.");
private static readonly Action<ILogger, Exception> _httpConnectionClosed =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, nameof(HttpConnectionClosed)), "Connection was closed from a different thread.");
private static readonly Action<ILogger, string, Uri, Exception> _startingTransport =
LoggerMessage.Define<string, Uri>(LogLevel.Debug, new EventId(3, nameof(StartingTransport)), "Starting transport '{transport}' with Url: {url}.");
private static readonly Action<ILogger, Exception> _raiseConnected =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, nameof(RaiseConnected)), "Raising Connected event.");
private static readonly Action<ILogger, Exception> _processRemainingMessages =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, nameof(ProcessRemainingMessages)), "Ensuring all outstanding messages are processed.");
private static readonly Action<ILogger, Exception> _drainEvents =
LoggerMessage.Define(LogLevel.Debug, new EventId(6, nameof(DrainEvents)), "Draining event queue.");
private static readonly Action<ILogger, Exception> _completeClosed =
LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(CompleteClosed)), "Completing Closed task.");
private static readonly Action<ILogger, Uri, Exception> _establishingConnection =
LoggerMessage.Define<Uri>(LogLevel.Debug, new EventId(8, nameof(EstablishingConnection)), "Establishing Connection at: {url}.");
private static readonly Action<ILogger, Uri, Exception> _errorWithNegotiation =
LoggerMessage.Define<Uri>(LogLevel.Error, new EventId(9, nameof(ErrorWithNegotiation)), "Failed to start connection. Error getting negotiation response from '{url}'.");
private static readonly Action<ILogger, string, Exception> _errorStartingTransport =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(10, nameof(ErrorStartingTransport)), "Failed to start connection. Error starting transport '{transport}'.");
private static readonly Action<ILogger, Exception> _httpReceiveStarted =
LoggerMessage.Define(LogLevel.Trace, new EventId(11, nameof(HttpReceiveStarted)), "Beginning receive loop.");
private static readonly Action<ILogger, Exception> _skipRaisingReceiveEvent =
LoggerMessage.Define(LogLevel.Debug, new EventId(12, nameof(SkipRaisingReceiveEvent)), "Message received but connection is not connected. Skipping raising Received event.");
private static readonly Action<ILogger, Exception> _scheduleReceiveEvent =
LoggerMessage.Define(LogLevel.Debug, new EventId(13, nameof(ScheduleReceiveEvent)), "Scheduling raising Received event.");
private static readonly Action<ILogger, Exception> _raiseReceiveEvent =
LoggerMessage.Define(LogLevel.Debug, new EventId(14, nameof(RaiseReceiveEvent)), "Raising Received event.");
private static readonly Action<ILogger, Exception> _failedReadingMessage =
LoggerMessage.Define(LogLevel.Debug, new EventId(15, nameof(FailedReadingMessage)), "Could not read message.");
private static readonly Action<ILogger, Exception> _errorReceiving =
LoggerMessage.Define(LogLevel.Error, new EventId(16, nameof(ErrorReceiving)), "Error receiving message.");
private static readonly Action<ILogger, Exception> _endReceive =
LoggerMessage.Define(LogLevel.Trace, new EventId(17, nameof(EndReceive)), "Ending receive loop.");
private static readonly Action<ILogger, Exception> _sendingMessage =
LoggerMessage.Define(LogLevel.Debug, new EventId(18, nameof(SendingMessage)), "Sending message.");
private static readonly Action<ILogger, Exception> _stoppingClient =
LoggerMessage.Define(LogLevel.Information, new EventId(19, nameof(StoppingClient)), "Stopping client.");
private static readonly Action<ILogger, string, Exception> _exceptionThrownFromCallback =
LoggerMessage.Define<string>(LogLevel.Error, new EventId(20, nameof(ExceptionThrownFromCallback)), "An exception was thrown from the '{callback}' callback.");
private static readonly Action<ILogger, Exception> _disposingClient =
LoggerMessage.Define(LogLevel.Information, new EventId(21, nameof(DisposingClient)), "Disposing client.");
private static readonly Action<ILogger, Exception> _abortingClient =
LoggerMessage.Define(LogLevel.Error, new EventId(22, nameof(AbortingClient)), "Aborting client.");
private static readonly Action<ILogger, Exception> _errorDuringClosedEvent =
LoggerMessage.Define(LogLevel.Error, new EventId(23, nameof(ErrorDuringClosedEvent)), "An exception was thrown in the handler for the Closed event.");
private static readonly Action<ILogger, Exception> _skippingStop =
LoggerMessage.Define(LogLevel.Debug, new EventId(24, nameof(SkippingStop)), "Skipping stop, connection is already stopped.");
private static readonly Action<ILogger, Exception> _skippingDispose =
LoggerMessage.Define(LogLevel.Debug, new EventId(25, nameof(SkippingDispose)), "Skipping dispose, connection is already disposed.");
private static readonly Action<ILogger, string, string, Exception> _connectionStateChanged =
LoggerMessage.Define<string, string>(LogLevel.Debug, new EventId(26, nameof(ConnectionStateChanged)), "Connection state changed from {previousState} to {newState}.");
public static void StartTransport(this ILogger logger, TransferMode transferMode)
{
_startTransport(logger, transferMode, null);
}
public static void TransportStopped(this ILogger logger, Exception exception)
{
_transportStopped(logger, exception);
}
public static void StartReceive(this ILogger logger)
{
_startReceive(logger, null);
}
public static void TransportStopping(this ILogger logger)
{
_transportStopping(logger, null);
}
public static void WebSocketClosed(this ILogger logger, WebSocketCloseStatus? closeStatus)
{
_webSocketClosed(logger, closeStatus, null);
}
public static void MessageReceived(this ILogger logger, WebSocketMessageType messageType, int count, bool endOfMessage)
{
_messageReceived(logger, messageType, count, endOfMessage, null);
}
public static void MessageToApp(this ILogger logger, int count)
{
_messageToApp(logger, count, null);
}
public static void ReceiveCanceled(this ILogger logger)
{
_receiveCanceled(logger, null);
}
public static void ReceiveStopped(this ILogger logger)
{
_receiveStopped(logger, null);
}
public static void SendStarted(this ILogger logger)
{
_sendStarted(logger, null);
}
public static void ReceivedFromApp(this ILogger logger, long count)
{
_receivedFromApp(logger, count, null);
}
public static void SendMessageCanceled(this ILogger logger)
{
_sendMessageCanceled(logger, null);
}
public static void ErrorSendingMessage(this ILogger logger, Exception exception)
{
_errorSendingMessage(logger, exception);
}
public static void SendCanceled(this ILogger logger)
{
_sendCanceled(logger, null);
}
public static void SendStopped(this ILogger logger)
{
_sendStopped(logger, null);
}
public static void ClosingWebSocket(this ILogger logger)
{
_closingWebSocket(logger, null);
}
public static void ClosingWebSocketFailed(this ILogger logger, Exception exception)
{
_closingWebSocketFailed(logger, exception);
}
public static void CancelMessage(this ILogger logger)
{
_cancelMessage(logger, null);
}
public static void SendingMessages(this ILogger logger, long count, Uri url)
{
_sendingMessages(logger, count, url, null);
}
public static void SentSuccessfully(this ILogger logger)
{
_sentSuccessfully(logger, null);
}
public static void NoMessages(this ILogger logger)
{
_noMessages(logger, null);
}
public static void ErrorSending(this ILogger logger, Uri url, Exception exception)
{
_errorSending(logger, url, exception);
}
public static void EventStreamEnded(this ILogger logger)
{
_eventStreamEnded(logger, null);
}
public static void ClosingConnection(this ILogger logger)
{
_closingConnection(logger, null);
}
public static void ReceivedMessages(this ILogger logger)
{
_receivedMessages(logger, null);
}
public static void ErrorPolling(this ILogger logger, Uri pollUrl, Exception exception)
{
_errorPolling(logger, pollUrl, exception);
}
public static void HttpConnectionStarting(this ILogger logger)
{
_httpConnectionStarting(logger, null);
}
public static void HttpConnectionClosed(this ILogger logger)
{
_httpConnectionClosed(logger, null);
}
public static void StartingTransport(this ILogger logger, ITransport transport, Uri url)
{
if (logger.IsEnabled(LogLevel.Debug))
{
_startingTransport(logger, transport.GetType().Name, url, null);
}
}
public static void RaiseConnected(this ILogger logger)
{
_raiseConnected(logger, null);
}
public static void ProcessRemainingMessages(this ILogger logger)
{
_processRemainingMessages(logger, null);
}
public static void DrainEvents(this ILogger logger)
{
_drainEvents(logger, null);
}
public static void CompleteClosed(this ILogger logger)
{
_completeClosed(logger, null);
}
public static void EstablishingConnection(this ILogger logger, Uri url)
{
_establishingConnection(logger, url, null);
}
public static void ErrorWithNegotiation(this ILogger logger, Uri url, Exception exception)
{
_errorWithNegotiation(logger, url, exception);
}
public static void ErrorStartingTransport(this ILogger logger, ITransport transport, Exception exception)
{
if (logger.IsEnabled(LogLevel.Error))
{
_errorStartingTransport(logger, transport.GetType().Name, exception);
}
}
public static void HttpReceiveStarted(this ILogger logger)
{
_httpReceiveStarted(logger, null);
}
public static void SkipRaisingReceiveEvent(this ILogger logger)
{
_skipRaisingReceiveEvent(logger, null);
}
public static void ScheduleReceiveEvent(this ILogger logger)
{
_scheduleReceiveEvent(logger, null);
}
public static void RaiseReceiveEvent(this ILogger logger)
{
_raiseReceiveEvent(logger, null);
}
public static void FailedReadingMessage(this ILogger logger)
{
_failedReadingMessage(logger, null);
}
public static void ErrorReceiving(this ILogger logger, Exception exception)
{
_errorReceiving(logger, exception);
}
public static void EndReceive(this ILogger logger)
{
_endReceive(logger, null);
}
public static void SendingMessage(this ILogger logger)
{
_sendingMessage(logger, null);
}
public static void AbortingClient(this ILogger logger, Exception ex)
{
_abortingClient(logger, ex);
}
public static void StoppingClient(this ILogger logger)
{
_stoppingClient(logger, null);
}
public static void DisposingClient(this ILogger logger)
{
_disposingClient(logger, null);
}
public static void SkippingDispose(this ILogger logger)
{
_skippingDispose(logger, null);
}
public static void ConnectionStateChanged(this ILogger logger, HttpConnection.ConnectionState previousState, HttpConnection.ConnectionState newState)
{
if (logger.IsEnabled(LogLevel.Debug))
{
_connectionStateChanged(logger, previousState.ToString(), newState.ToString(), null);
}
}
public static void SkippingStop(this ILogger logger)
{
_skippingStop(logger, null);
}
public static void ExceptionThrownFromCallback(this ILogger logger, string callbackName, Exception exception)
{
_exceptionThrownFromCallback(logger, callbackName, exception);
}
public static void ErrorDuringClosedEvent(this ILogger logger, Exception exception)
{
_errorDuringClosedEvent(logger, exception);
}
}
}

88
src/Microsoft.AspNetCore.Sockets.Client.Http/LongPollingTransport.Log.cs Normal file
View File

@ -0,0 +1,88 @@
// 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 Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Client
{
public partial class LongPollingTransport
{
private static class Log
{
private static readonly Action<ILogger, TransferMode, Exception> _startTransport =
LoggerMessage.Define<TransferMode>(LogLevel.Information, new EventId(1, "StartTransport"), "Starting transport. Transfer mode: {transferMode}.");
private static readonly Action<ILogger, Exception> _transportStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, "TransportStopped"), "Transport stopped.");
private static readonly Action<ILogger, Exception> _startReceive =
LoggerMessage.Define(LogLevel.Debug, new EventId(3, "StartReceive"), "Starting receive loop.");
private static readonly Action<ILogger, Exception> _receiveStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "ReceiveStopped"), "Receive loop stopped.");
private static readonly Action<ILogger, Exception> _receiveCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, "ReceiveCanceled"), "Receive loop canceled.");
private static readonly Action<ILogger, Exception> _transportStopping =
LoggerMessage.Define(LogLevel.Information, new EventId(6, "TransportStopping"), "Transport is stopping.");
private static readonly Action<ILogger, Exception> _closingConnection =
LoggerMessage.Define(LogLevel.Debug, new EventId(7, "ClosingConnection"), "The server is closing the connection.");
private static readonly Action<ILogger, Exception> _receivedMessages =
LoggerMessage.Define(LogLevel.Debug, new EventId(8, "ReceivedMessages"), "Received messages from the server.");
private static readonly Action<ILogger, Uri, Exception> _errorPolling =
LoggerMessage.Define<Uri>(LogLevel.Error, new EventId(9, "ErrorPolling"), "Error while polling '{pollUrl}'.");
// EventIds 100 - 106 used in SendUtils
public static void StartTransport(ILogger logger, TransferMode transferMode)
{
_startTransport(logger, transferMode, null);
}
public static void TransportStopped(ILogger logger, Exception exception)
{
_transportStopped(logger, exception);
}
public static void StartReceive(ILogger logger)
{
_startReceive(logger, null);
}
public static void TransportStopping(ILogger logger)
{
_transportStopping(logger, null);
}
public static void ReceiveCanceled(ILogger logger)
{
_receiveCanceled(logger, null);
}
public static void ReceiveStopped(ILogger logger)
{
_receiveStopped(logger, null);
}
public static void ClosingConnection(ILogger logger)
{
_closingConnection(logger, null);
}
public static void ReceivedMessages(ILogger logger)
{
_receivedMessages(logger, null);
}
public static void ErrorPolling(ILogger logger, Uri pollUrl, Exception exception)
{
_errorPolling(logger, pollUrl, exception);
}
}
}
}

21
src/Microsoft.AspNetCore.Sockets.Client.Http/LongPollingTransport.cs
View File

@ -8,14 +8,13 @@ using System.Net.Http;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Sockets.Client.Http; using Microsoft.AspNetCore.Sockets.Client.Http;
using Microsoft.AspNetCore.Sockets.Client.Internal;
using Microsoft.AspNetCore.Sockets.Features; using Microsoft.AspNetCore.Sockets.Features;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Logging.Abstractions;
namespace Microsoft.AspNetCore.Sockets.Client namespace Microsoft.AspNetCore.Sockets.Client
{ {
public class LongPollingTransport : ITransport public partial class LongPollingTransport : ITransport
{ {
private readonly HttpClient _httpClient; private readonly HttpClient _httpClient;
private readonly HttpOptions _httpOptions; private readonly HttpOptions _httpOptions;
@ -53,7 +52,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
_application = application; _application = application;
Mode = requestedTransferMode; Mode = requestedTransferMode;
_logger.StartTransport(Mode.Value); Log.StartTransport(_logger, Mode.Value);
// Start sending and polling (ask for binary if the server supports it) // Start sending and polling (ask for binary if the server supports it)
_poller = Poll(url, _transportCts.Token); _poller = Poll(url, _transportCts.Token);
@ -61,7 +60,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
Running = Task.WhenAll(_sender, _poller).ContinueWith(t => Running = Task.WhenAll(_sender, _poller).ContinueWith(t =>
{ {
_logger.TransportStopped(t.Exception?.InnerException); Log.TransportStopped(_logger, t.Exception?.InnerException);
_application.Output.Complete(t.Exception?.InnerException); _application.Output.Complete(t.Exception?.InnerException);
_application.Input.Complete(); _application.Input.Complete();
return t; return t;
@ -72,7 +71,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
public async Task StopAsync() public async Task StopAsync()
{ {
_logger.TransportStopping(); Log.TransportStopping(_logger);
_transportCts.Cancel(); _transportCts.Cancel();
@ -88,7 +87,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
private async Task Poll(Uri pollUrl, CancellationToken cancellationToken) private async Task Poll(Uri pollUrl, CancellationToken cancellationToken)
{ {
_logger.StartReceive(); Log.StartReceive(_logger);
try try
{ {
while (!cancellationToken.IsCancellationRequested) while (!cancellationToken.IsCancellationRequested)
@ -114,14 +113,14 @@ namespace Microsoft.AspNetCore.Sockets.Client
if (response.StatusCode == HttpStatusCode.NoContent || cancellationToken.IsCancellationRequested) if (response.StatusCode == HttpStatusCode.NoContent || cancellationToken.IsCancellationRequested)
{ {
_logger.ClosingConnection(); Log.ClosingConnection(_logger);
// Transport closed or polling stopped, we're done // Transport closed or polling stopped, we're done
break; break;
} }
else else
{ {
_logger.ReceivedMessages(); Log.ReceivedMessages(_logger);
var stream = new PipeWriterStream(_application.Output); var stream = new PipeWriterStream(_application.Output);
await response.Content.CopyToAsync(stream); await response.Content.CopyToAsync(stream);
@ -132,18 +131,18 @@ namespace Microsoft.AspNetCore.Sockets.Client
catch (OperationCanceledException) catch (OperationCanceledException)
{ {
// transport is being closed // transport is being closed
_logger.ReceiveCanceled(); Log.ReceiveCanceled(_logger);
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.ErrorPolling(pollUrl, ex); Log.ErrorPolling(_logger, pollUrl, ex);
throw; throw;
} }
finally finally
{ {
// Make sure the send loop is terminated // Make sure the send loop is terminated
_transportCts.Cancel(); _transportCts.Cancel();
_logger.ReceiveStopped(); Log.ReceiveStopped(_logger);
} }
} }
} }

79
src/Microsoft.AspNetCore.Sockets.Client.Http/SendUtils.cs
View File

@ -10,7 +10,6 @@ using System.Net.Http;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Sockets.Client.Http; using Microsoft.AspNetCore.Sockets.Client.Http;
using Microsoft.AspNetCore.Sockets.Client.Internal;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Client namespace Microsoft.AspNetCore.Sockets.Client
@ -20,7 +19,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
public static async Task SendMessages(Uri sendUrl, IDuplexPipe application, HttpClient httpClient, public static async Task SendMessages(Uri sendUrl, IDuplexPipe application, HttpClient httpClient,
HttpOptions httpOptions, CancellationTokenSource transportCts, ILogger logger) HttpOptions httpOptions, CancellationTokenSource transportCts, ILogger logger)
{ {
logger.SendStarted(); Log.SendStarted(logger);
try try
{ {
@ -31,12 +30,12 @@ namespace Microsoft.AspNetCore.Sockets.Client
try try
{ {
// Grab as many messages as we can from the channel // Grab as many messages as we can from the pipe
transportCts.Token.ThrowIfCancellationRequested(); transportCts.Token.ThrowIfCancellationRequested();
if (!buffer.IsEmpty) if (!buffer.IsEmpty)
{ {
logger.SendingMessages(buffer.Length, sendUrl); Log.SendingMessages(logger, buffer.Length, sendUrl);
// Send them in a single post // Send them in a single post
var request = new HttpRequestMessage(HttpMethod.Post, sendUrl); var request = new HttpRequestMessage(HttpMethod.Post, sendUrl);
@ -47,7 +46,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
var response = await httpClient.SendAsync(request, transportCts.Token); var response = await httpClient.SendAsync(request, transportCts.Token);
response.EnsureSuccessStatusCode(); response.EnsureSuccessStatusCode();
logger.SentSuccessfully(); Log.SentSuccessfully(logger);
} }
else if (result.IsCompleted) else if (result.IsCompleted)
{ {
@ -55,7 +54,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
else else
{ {
logger.NoMessages(); Log.NoMessages(logger);
} }
} }
finally finally
@ -66,11 +65,11 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
catch (OperationCanceledException) catch (OperationCanceledException)
{ {
logger.SendCanceled(); Log.SendCanceled(logger);
} }
catch (Exception ex) catch (Exception ex)
{ {
logger.ErrorSending(sendUrl, ex); Log.ErrorSending(logger, sendUrl, ex);
throw; throw;
} }
finally finally
@ -79,7 +78,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
transportCts.Cancel(); transportCts.Cancel();
} }
logger.SendStopped(); Log.SendStopped(logger);
} }
public static void PrepareHttpRequest(HttpRequestMessage request, HttpOptions httpOptions) public static void PrepareHttpRequest(HttpRequestMessage request, HttpOptions httpOptions)
@ -119,5 +118,67 @@ namespace Microsoft.AspNetCore.Sockets.Client
return true; return true;
} }
} }
private static class Log
{
private static readonly Action<ILogger, Exception> _sendStarted =
LoggerMessage.Define(LogLevel.Debug, new EventId(100, "SendStarted"), "Starting the send loop.");
private static readonly Action<ILogger, Exception> _sendStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(101, "SendStopped"), "Send loop stopped.");
private static readonly Action<ILogger, Exception> _sendCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(102, "SendCanceled"), "Send loop canceled.");
private static readonly Action<ILogger, long, Uri, Exception> _sendingMessages =
LoggerMessage.Define<long, Uri>(LogLevel.Debug, new EventId(103, "SendingMessages"), "Sending {count} bytes to the server using url: {url}.");
private static readonly Action<ILogger, Exception> _sentSuccessfully =
LoggerMessage.Define(LogLevel.Debug, new EventId(104, "SentSuccessfully"), "Message(s) sent successfully.");
private static readonly Action<ILogger, Exception> _noMessages =
LoggerMessage.Define(LogLevel.Debug, new EventId(105, "NoMessages"), "No messages in batch to send.");
private static readonly Action<ILogger, Uri, Exception> _errorSending =
LoggerMessage.Define<Uri>(LogLevel.Error, new EventId(106, "ErrorSending"), "Error while sending to '{url}'.");
// When adding a new log message make sure to check with LongPollingTransport and ServerSentEventsTransport that share these logs to not have conflicting EventIds
// We start the IDs at 100 to make it easy to avoid conflicting IDs
public static void SendStarted(ILogger logger)
{
_sendStarted(logger, null);
}
public static void SendCanceled(ILogger logger)
{
_sendCanceled(logger, null);
}
public static void SendStopped(ILogger logger)
{
_sendStopped(logger, null);
}
public static void SendingMessages(ILogger logger, long count, Uri url)
{
_sendingMessages(logger, count, url, null);
}
public static void SentSuccessfully(ILogger logger)
{
_sentSuccessfully(logger, null);
}
public static void NoMessages(ILogger logger)
{
_noMessages(logger, null);
}
public static void ErrorSending(ILogger logger, Uri url, Exception exception)
{
_errorSending(logger, url, exception);
}
}
} }
} }

88
src/Microsoft.AspNetCore.Sockets.Client.Http/ServerSentEventsTransport.Log.cs Normal file
View File

@ -0,0 +1,88 @@
// 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 Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Client
{
public partial class ServerSentEventsTransport
{
private static class Log
{
private static readonly Action<ILogger, TransferMode, Exception> _startTransport =
LoggerMessage.Define<TransferMode>(LogLevel.Information, new EventId(1, "StartTransport"), "Starting transport. Transfer mode: {transferMode}.");
private static readonly Action<ILogger, Exception> _transportStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, "TransportStopped"), "Transport stopped.");
private static readonly Action<ILogger, Exception> _startReceive =
LoggerMessage.Define(LogLevel.Debug, new EventId(3, "StartReceive"), "Starting receive loop.");
private static readonly Action<ILogger, Exception> _receiveStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "ReceiveStopped"), "Receive loop stopped.");
private static readonly Action<ILogger, Exception> _receiveCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, "ReceiveCanceled"), "Receive loop canceled.");
private static readonly Action<ILogger, Exception> _transportStopping =
LoggerMessage.Define(LogLevel.Information, new EventId(6, "TransportStopping"), "Transport is stopping.");
private static readonly Action<ILogger, int, Exception> _messageToApp =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(7, "MessageToApp"), "Passing message to application. Payload size: {count}.");
private static readonly Action<ILogger, Exception> _eventStreamEnded =
LoggerMessage.Define(LogLevel.Debug, new EventId(8, "EventStreamEnded"), "Server-Sent Event Stream ended.");
private static readonly Action<ILogger, long, Exception> _parsingSSE =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(9, "ParsingSSE"), "Received {count} bytes. Parsing SSE frame.");
// EventIds 100 - 106 used in SendUtils
public static void StartTransport(ILogger logger, TransferMode transferMode)
{
_startTransport(logger, transferMode, null);
}
public static void TransportStopped(ILogger logger, Exception exception)
{
_transportStopped(logger, exception);
}
public static void StartReceive(ILogger logger)
{
_startReceive(logger, null);
}
public static void TransportStopping(ILogger logger)
{
_transportStopping(logger, null);
}
public static void MessageToApp(ILogger logger, int count)
{
_messageToApp(logger, count, null);
}
public static void ReceiveCanceled(ILogger logger)
{
_receiveCanceled(logger, null);
}
public static void ReceiveStopped(ILogger logger)
{
_receiveStopped(logger, null);
}
public static void EventStreamEnded(ILogger logger)
{
_eventStreamEnded(logger, null);
}
public static void ParsingSSE(ILogger logger, long bytes)
{
_parsingSSE(logger, bytes, null);
}
}
}
}

20
src/Microsoft.AspNetCore.Sockets.Client.Http/ServerSentEventsTransport.cs
View File

@ -5,18 +5,16 @@ using System;
using System.IO.Pipelines; using System.IO.Pipelines;
using System.Net.Http; using System.Net.Http;
using System.Net.Http.Headers; using System.Net.Http.Headers;
using System.Text;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Sockets.Client.Http; using Microsoft.AspNetCore.Sockets.Client.Http;
using Microsoft.AspNetCore.Sockets.Client.Internal;
using Microsoft.AspNetCore.Sockets.Internal.Formatters; using Microsoft.AspNetCore.Sockets.Internal.Formatters;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Logging.Abstractions;
namespace Microsoft.AspNetCore.Sockets.Client namespace Microsoft.AspNetCore.Sockets.Client
{ {
public class ServerSentEventsTransport : ITransport public partial class ServerSentEventsTransport : ITransport
{ {
private readonly HttpClient _httpClient; private readonly HttpClient _httpClient;
private readonly HttpOptions _httpOptions; private readonly HttpOptions _httpOptions;
@ -56,14 +54,14 @@ namespace Microsoft.AspNetCore.Sockets.Client
_application = application; _application = application;
Mode = TransferMode.Text; // Server Sent Events is a text only transport Mode = TransferMode.Text; // Server Sent Events is a text only transport
_logger.StartTransport(Mode.Value); Log.StartTransport(_logger, Mode.Value);
var sendTask = SendUtils.SendMessages(url, _application, _httpClient, _httpOptions, _transportCts, _logger); var sendTask = SendUtils.SendMessages(url, _application, _httpClient, _httpOptions, _transportCts, _logger);
var receiveTask = OpenConnection(_application, url, _transportCts.Token); var receiveTask = OpenConnection(_application, url, _transportCts.Token);
Running = Task.WhenAll(sendTask, receiveTask).ContinueWith(t => Running = Task.WhenAll(sendTask, receiveTask).ContinueWith(t =>
{ {
_logger.TransportStopped(t.Exception?.InnerException); Log.TransportStopped(_logger, t.Exception?.InnerException);
_application.Output.Complete(t.Exception?.InnerException); _application.Output.Complete(t.Exception?.InnerException);
_application.Input.Complete(); _application.Input.Complete();
@ -75,7 +73,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
private async Task OpenConnection(IDuplexPipe application, Uri url, CancellationToken cancellationToken) private async Task OpenConnection(IDuplexPipe application, Uri url, CancellationToken cancellationToken)
{ {
_logger.StartReceive(); Log.StartReceive(_logger);
var request = new HttpRequestMessage(HttpMethod.Get, url); var request = new HttpRequestMessage(HttpMethod.Get, url);
SendUtils.PrepareHttpRequest(request, _httpOptions); SendUtils.PrepareHttpRequest(request, _httpOptions);
@ -95,7 +93,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
var input = result.Buffer; var input = result.Buffer;
if (result.IsCanceled || (input.IsEmpty && result.IsCompleted)) if (result.IsCanceled || (input.IsEmpty && result.IsCompleted))
{ {
_logger.EventStreamEnded(); Log.EventStreamEnded(_logger);
break; break;
} }
@ -104,11 +102,13 @@ namespace Microsoft.AspNetCore.Sockets.Client
try try
{ {
Log.ParsingSSE(_logger, input.Length);
var parseResult = _parser.ParseMessage(input, out consumed, out examined, out var buffer); var parseResult = _parser.ParseMessage(input, out consumed, out examined, out var buffer);
switch (parseResult) switch (parseResult)
{ {
case ServerSentEventsMessageParser.ParseResult.Completed: case ServerSentEventsMessageParser.ParseResult.Completed:
Log.MessageToApp(_logger, buffer.Length);
await _application.Output.WriteAsync(buffer); await _application.Output.WriteAsync(buffer);
_parser.Reset(); _parser.Reset();
break; break;
@ -128,20 +128,20 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
catch (OperationCanceledException) catch (OperationCanceledException)
{ {
_logger.ReceiveCanceled(); Log.ReceiveCanceled(_logger);
} }
finally finally
{ {
readCancellationRegistration.Dispose(); readCancellationRegistration.Dispose();
_transportCts.Cancel(); _transportCts.Cancel();
_logger.ReceiveStopped(); Log.ReceiveStopped(_logger);
} }
} }
} }
public async Task StopAsync() public async Task StopAsync()
{ {
_logger.TransportStopping(); Log.TransportStopping(_logger);
_transportCts.Cancel(); _transportCts.Cancel();
try try

159
src/Microsoft.AspNetCore.Sockets.Client.Http/WebSocketsTransport.Log.cs Normal file
View File

@ -0,0 +1,159 @@
// 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.Net.WebSockets;
using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Client
{
public partial class WebSocketsTransport
{
private static class Log
{
private static readonly Action<ILogger, TransferMode, Exception> _startTransport =
LoggerMessage.Define<TransferMode>(LogLevel.Information, new EventId(1, "StartTransport"), "Starting transport. Transfer mode: {transferMode}.");
private static readonly Action<ILogger, Exception> _transportStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, "TransportStopped"), "Transport stopped.");
private static readonly Action<ILogger, Exception> _startReceive =
LoggerMessage.Define(LogLevel.Debug, new EventId(3, "StartReceive"), "Starting receive loop.");
private static readonly Action<ILogger, Exception> _receiveStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "ReceiveStopped"), "Receive loop stopped.");
private static readonly Action<ILogger, Exception> _receiveCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, "ReceiveCanceled"), "Receive loop canceled.");
private static readonly Action<ILogger, Exception> _transportStopping =
LoggerMessage.Define(LogLevel.Information, new EventId(6, "TransportStopping"), "Transport is stopping.");
private static readonly Action<ILogger, Exception> _sendStarted =
LoggerMessage.Define(LogLevel.Debug, new EventId(7, "SendStarted"), "Starting the send loop.");
private static readonly Action<ILogger, Exception> _sendStopped =
LoggerMessage.Define(LogLevel.Debug, new EventId(8, "SendStopped"), "Send loop stopped.");
private static readonly Action<ILogger, Exception> _sendCanceled =
LoggerMessage.Define(LogLevel.Debug, new EventId(9, "SendCanceled"), "Send loop canceled.");
private static readonly Action<ILogger, int, Exception> _messageToApp =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(10, "MessageToApp"), "Passing message to application. Payload size: {count}.");
private static readonly Action<ILogger, WebSocketCloseStatus?, Exception> _webSocketClosed =
LoggerMessage.Define<WebSocketCloseStatus?>(LogLevel.Information, new EventId(11, "WebSocketClosed"), "Websocket closed by the server. Close status {closeStatus}.");
private static readonly Action<ILogger, WebSocketMessageType, int, bool, Exception> _messageReceived =
LoggerMessage.Define<WebSocketMessageType, int, bool>(LogLevel.Debug, new EventId(12, "MessageReceived"), "Message received. Type: {messageType}, size: {count}, EndOfMessage: {endOfMessage}.");
private static readonly Action<ILogger, long, Exception> _receivedFromApp =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(13, "ReceivedFromApp"), "Received message from application. Payload size: {count}.");
private static readonly Action<ILogger, Exception> _sendMessageCanceled =
LoggerMessage.Define(LogLevel.Information, new EventId(14, "SendMessageCanceled"), "Sending a message canceled.");
private static readonly Action<ILogger, Exception> _errorSendingMessage =
LoggerMessage.Define(LogLevel.Error, new EventId(15, "ErrorSendingMessage"), "Error while sending a message.");
private static readonly Action<ILogger, Exception> _closingWebSocket =
LoggerMessage.Define(LogLevel.Information, new EventId(16, "ClosingWebSocket"), "Closing WebSocket.");
private static readonly Action<ILogger, Exception> _closingWebSocketFailed =
LoggerMessage.Define(LogLevel.Information, new EventId(17, "ClosingWebSocketFailed"), "Closing webSocket failed.");
private static readonly Action<ILogger, Exception> _cancelMessage =
LoggerMessage.Define(LogLevel.Debug, new EventId(18, "CancelMessage"), "Canceled passing message to application.");
public static void StartTransport(ILogger logger, TransferMode transferMode)
{
_startTransport(logger, transferMode, null);
}
public static void TransportStopped(ILogger logger, Exception exception)
{
_transportStopped(logger, exception);
}
public static void StartReceive(ILogger logger)
{
_startReceive(logger, null);
}
public static void TransportStopping(ILogger logger)
{
_transportStopping(logger, null);
}
public static void MessageToApp(ILogger logger, int count)
{
_messageToApp(logger, count, null);
}
public static void ReceiveCanceled(ILogger logger)
{
_receiveCanceled(logger, null);
}
public static void ReceiveStopped(ILogger logger)
{
_receiveStopped(logger, null);
}
public static void SendStarted(ILogger logger)
{
_sendStarted(logger, null);
}
public static void SendCanceled(ILogger logger)
{
_sendCanceled(logger, null);
}
public static void SendStopped(ILogger logger)
{
_sendStopped(logger, null);
}
public static void WebSocketClosed(ILogger logger, WebSocketCloseStatus? closeStatus)
{
_webSocketClosed(logger, closeStatus, null);
}
public static void MessageReceived(ILogger logger, WebSocketMessageType messageType, int count, bool endOfMessage)
{
_messageReceived(logger, messageType, count, endOfMessage, null);
}
public static void ReceivedFromApp(ILogger logger, long count)
{
_receivedFromApp(logger, count, null);
}
public static void SendMessageCanceled(ILogger logger)
{
_sendMessageCanceled(logger, null);
}
public static void ErrorSendingMessage(ILogger logger, Exception exception)
{
_errorSendingMessage(logger, exception);
}
public static void ClosingWebSocket(ILogger logger)
{
_closingWebSocket(logger, null);
}
public static void ClosingWebSocketFailed(ILogger logger, Exception exception)
{
_closingWebSocketFailed(logger, exception);
}
public static void CancelMessage(ILogger logger)
{
_cancelMessage(logger, null);
}
}
}
}

21
src/Microsoft.AspNetCore.Sockets.Client.Http/WebSocketsTransport.cs
View File

@ -8,13 +8,12 @@ using System.Net.WebSockets;
using System.Threading; using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Sockets.Client.Http; using Microsoft.AspNetCore.Sockets.Client.Http;
using Microsoft.AspNetCore.Sockets.Client.Internal;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Logging.Abstractions;
namespace Microsoft.AspNetCore.Sockets.Client namespace Microsoft.AspNetCore.Sockets.Client
{ {
public class WebSocketsTransport : ITransport public partial class WebSocketsTransport : ITransport
{ {
private readonly ClientWebSocket _webSocket; private readonly ClientWebSocket _webSocket;
private IDuplexPipe _application; private IDuplexPipe _application;
@ -74,7 +73,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
_application = application; _application = application;
Mode = requestedTransferMode; Mode = requestedTransferMode;
_logger.StartTransport(Mode.Value); Log.StartTransport(_logger, Mode.Value);
await Connect(url); await Connect(url);
@ -157,7 +156,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
#endif #endif
if (receiveResult.MessageType == WebSocketMessageType.Close) if (receiveResult.MessageType == WebSocketMessageType.Close)
{ {
_logger.WebSocketClosed(_webSocket.CloseStatus); Log.WebSocketClosed(_logger, _webSocket.CloseStatus);
if (_webSocket.CloseStatus != WebSocketCloseStatus.NormalClosure) if (_webSocket.CloseStatus != WebSocketCloseStatus.NormalClosure)
{ {
@ -167,7 +166,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
return; return;
} }
_logger.MessageReceived(receiveResult.MessageType, receiveResult.Count, receiveResult.EndOfMessage); Log.MessageReceived(_logger, receiveResult.MessageType, receiveResult.Count, receiveResult.EndOfMessage);
_application.Output.Advance(receiveResult.Count); _application.Output.Advance(receiveResult.Count);
@ -186,7 +185,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
} }
catch (OperationCanceledException) catch (OperationCanceledException)
{ {
_logger.ReceiveCanceled(); Log.ReceiveCanceled(_logger);
} }
catch (Exception ex) catch (Exception ex)
{ {
@ -204,7 +203,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
// We're done writing // We're done writing
_application.Output.Complete(); _application.Output.Complete();
_logger.ReceiveStopped(); Log.ReceiveStopped(_logger);
} }
} }
@ -237,7 +236,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
try try
{ {
_logger.ReceivedFromApp(buffer.Length); Log.ReceivedFromApp(_logger, buffer.Length);
if (WebSocketCanSend(socket)) if (WebSocketCanSend(socket))
{ {
@ -252,7 +251,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
{ {
if (!_aborted) if (!_aborted)
{ {
_logger.ErrorSendingMessage(ex); Log.ErrorSendingMessage(_logger, ex);
} }
break; break;
} }
@ -282,7 +281,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
_application.Input.Complete(); _application.Input.Complete();
_logger.SendStopped(); Log.SendStopped(_logger);
} }
} }
@ -310,7 +309,7 @@ namespace Microsoft.AspNetCore.Sockets.Client
public async Task StopAsync() public async Task StopAsync()
{ {
_logger.TransportStopping(); Log.TransportStopping(_logger);
// Cancel any pending reads from the application, this should start the entire shutdown process // Cancel any pending reads from the application, this should start the entire shutdown process
_application.Input.CancelPendingRead(); _application.Input.CancelPendingRead();