Reduce detailed payload logs to trace (#1515)

This commit is contained in:
Andrew Stanton-Nurse 2018-02-28 10:46:44 -08:00 committed by GitHub
parent c4eb501343
commit 13b25ec518
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 305 additions and 288 deletions

View File

@ -1251,12 +1251,6 @@
"tweetnacl": "0.14.5"
}
},
"string_decoder": {
"version": "0.10.31",
"resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-0.10.31.tgz",
"integrity": "sha1-YuIDvEF2bGwoyfyEMB2rHFMQ+pQ=",
"dev": true
},
"string-width": {
"version": "2.1.1",
"resolved": "https://registry.npmjs.org/string-width/-/string-width-2.1.1.tgz",
@ -1267,6 +1261,12 @@
"strip-ansi": "4.0.0"
}
},
"string_decoder": {
"version": "0.10.31",
"resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-0.10.31.tgz",
"integrity": "sha1-YuIDvEF2bGwoyfyEMB2rHFMQ+pQ=",
"dev": true
},
"stringstream": {
"version": "0.0.5",
"resolved": "https://registry.npmjs.org/stringstream/-/stringstream-0.0.5.tgz",

View File

@ -0,0 +1,94 @@
// 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
{
public partial class HttpConnectionDispatcher
{
private static class Log
{
private static readonly Action<ILogger, string, Exception> _connectionDisposed =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(1, "ConnectionDisposed"), "Connection Id {connectionId} was disposed.");
private static readonly Action<ILogger, string, string, Exception> _connectionAlreadyActive =
LoggerMessage.Define<string, string>(LogLevel.Debug, new EventId(2, "ConnectionAlreadyActive"), "Connection Id {connectionId} is already active via {requestId}.");
private static readonly Action<ILogger, string, string, Exception> _pollCanceled =
LoggerMessage.Define<string, string>(LogLevel.Trace, new EventId(3, "PollCanceled"), "Previous poll canceled for {connectionId} on {requestId}.");
private static readonly Action<ILogger, Exception> _establishedConnection =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "EstablishedConnection"), "Establishing new connection.");
private static readonly Action<ILogger, Exception> _resumingConnection =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, "ResumingConnection"), "Resuming existing connection.");
private static readonly Action<ILogger, long, Exception> _receivedBytes =
LoggerMessage.Define<long>(LogLevel.Trace, new EventId(6, "ReceivedBytes"), "Received {count} bytes.");
private static readonly Action<ILogger, TransportType, Exception> _transportNotSupported =
LoggerMessage.Define<TransportType>(LogLevel.Debug, new EventId(7, "TransportNotSupported"), "{transportType} transport not supported by this endpoint type.");
private static readonly Action<ILogger, TransportType, TransportType, Exception> _cannotChangeTransport =
LoggerMessage.Define<TransportType, TransportType>(LogLevel.Error, new EventId(8, "CannotChangeTransport"), "Cannot change transports mid-connection; currently using {transportType}, requesting {requestedTransport}.");
private static readonly Action<ILogger, Exception> _postNotallowedForWebsockets =
LoggerMessage.Define(LogLevel.Debug, new EventId(9, "PostNotAllowedForWebSockets"), "POST requests are not allowed for websocket connections.");
private static readonly Action<ILogger, Exception> _negotiationRequest =
LoggerMessage.Define(LogLevel.Debug, new EventId(10, "NegotiationRequest"), "Sending negotiation response.");
public static void ConnectionDisposed(ILogger logger, string connectionId)
{
_connectionDisposed(logger, connectionId, null);
}
public static void ConnectionAlreadyActive(ILogger logger, string connectionId, string requestId)
{
_connectionAlreadyActive(logger, connectionId, requestId, null);
}
public static void PollCanceled(ILogger logger, string connectionId, string requestId)
{
_pollCanceled(logger, connectionId, requestId, null);
}
public static void EstablishedConnection(ILogger logger)
{
_establishedConnection(logger, null);
}
public static void ResumingConnection(ILogger logger)
{
_resumingConnection(logger, null);
}
public static void ReceivedBytes(ILogger logger, long count)
{
_receivedBytes(logger, count, null);
}
public static void TransportNotSupported(ILogger logger, TransportType transport)
{
_transportNotSupported(logger, transport, null);
}
public static void CannotChangeTransport(ILogger logger, TransportType transport, TransportType requestTransport)
{
_cannotChangeTransport(logger, transport, requestTransport, null);
}
public static void PostNotAllowedForWebSockets(ILogger logger)
{
_postNotallowedForWebsockets(logger, null);
}
public static void NegotiationRequest(ILogger logger)
{
_negotiationRequest(logger, null);
}
}
}
}

View File

@ -20,7 +20,7 @@ using Newtonsoft.Json;
namespace Microsoft.AspNetCore.Sockets
{
public class HttpConnectionDispatcher
public partial class HttpConnectionDispatcher
{
private readonly ConnectionManager _manager;
private readonly ILoggerFactory _loggerFactory;
@ -112,7 +112,7 @@ namespace Microsoft.AspNetCore.Sockets
return;
}
_logger.EstablishedConnection();
Log.EstablishedConnection(_logger);
// ServerSentEvents is a text protocol only
connection.TransportCapabilities = TransferMode.Text;
@ -138,7 +138,7 @@ namespace Microsoft.AspNetCore.Sockets
return;
}
_logger.EstablishedConnection();
Log.EstablishedConnection(_logger);
var ws = new WebSocketsTransport(options.WebSockets, connection.Application, connection, _loggerFactory);
@ -168,7 +168,7 @@ namespace Microsoft.AspNetCore.Sockets
if (connection.Status == DefaultConnectionContext.ConnectionStatus.Disposed)
{
_logger.ConnectionDisposed(connection.ConnectionId);
Log.ConnectionDisposed(_logger, connection.ConnectionId);
// The connection was disposed
context.Response.StatusCode = StatusCodes.Status404NotFound;
@ -179,7 +179,7 @@ namespace Microsoft.AspNetCore.Sockets
if (connection.Status == DefaultConnectionContext.ConnectionStatus.Active)
{
var existing = connection.GetHttpContext();
_logger.ConnectionAlreadyActive(connection.ConnectionId, existing.TraceIdentifier);
Log.ConnectionAlreadyActive(_logger, connection.ConnectionId, existing.TraceIdentifier);
using (connection.Cancellation)
{
@ -189,7 +189,7 @@ namespace Microsoft.AspNetCore.Sockets
// Wait for the previous request to drain
await connection.TransportTask;
_logger.PollCanceled(connection.ConnectionId, existing.TraceIdentifier);
Log.PollCanceled(_logger, connection.ConnectionId, existing.TraceIdentifier);
}
}
@ -199,7 +199,7 @@ namespace Microsoft.AspNetCore.Sockets
// Raise OnConnected for new connections only since polls happen all the time
if (connection.ApplicationTask == null)
{
_logger.EstablishedConnection();
Log.EstablishedConnection(_logger);
connection.Metadata[ConnectionMetadataNames.Transport] = TransportType.LongPolling;
@ -207,7 +207,7 @@ namespace Microsoft.AspNetCore.Sockets
}
else
{
_logger.ResumingConnection();
Log.ResumingConnection(_logger);
}
// REVIEW: Performance of this isn't great as this does a bunch of per request allocations
@ -303,7 +303,7 @@ namespace Microsoft.AspNetCore.Sockets
if (connection.Status == DefaultConnectionContext.ConnectionStatus.Disposed)
{
_logger.ConnectionDisposed(connection.ConnectionId);
Log.ConnectionDisposed(_logger, connection.ConnectionId);
// Connection was disposed
context.Response.StatusCode = StatusCodes.Status404NotFound;
@ -313,7 +313,7 @@ namespace Microsoft.AspNetCore.Sockets
// There's already an active request
if (connection.Status == DefaultConnectionContext.ConnectionStatus.Active)
{
_logger.ConnectionAlreadyActive(connection.ConnectionId, connection.GetHttpContext().TraceIdentifier);
Log.ConnectionAlreadyActive(_logger, connection.ConnectionId, connection.GetHttpContext().TraceIdentifier);
// Reject the request with a 409 conflict
context.Response.StatusCode = StatusCodes.Status409Conflict;
@ -370,7 +370,7 @@ namespace Microsoft.AspNetCore.Sockets
// Get the bytes for the connection id
var negotiateResponseBuffer = Encoding.UTF8.GetBytes(GetNegotiatePayload(connection.ConnectionId, options));
_logger.NegotiationRequest();
Log.NegotiationRequest(_logger);
// Write it out to the response with the right content length
context.Response.ContentLength = negotiateResponseBuffer.Length;
@ -422,7 +422,7 @@ namespace Microsoft.AspNetCore.Sockets
var transport = (TransportType?)connection.Metadata[ConnectionMetadataNames.Transport];
if (transport == TransportType.WebSockets)
{
_logger.PostNotAllowedForWebSockets();
Log.PostNotAllowedForWebSockets(_logger);
context.Response.StatusCode = StatusCodes.Status405MethodNotAllowed;
await context.Response.WriteAsync("POST requests are not allowed for WebSocket connections.");
return;
@ -434,7 +434,7 @@ namespace Microsoft.AspNetCore.Sockets
var pipeWriterStream = new PipeWriterStream(connection.Application.Output);
await context.Request.Body.CopyToAsync(pipeWriterStream);
_logger.ReceivedBytes(pipeWriterStream.Length);
Log.ReceivedBytes(_logger, pipeWriterStream.Length);
await connection.Application.Output.FlushAsync();
}
@ -444,7 +444,7 @@ namespace Microsoft.AspNetCore.Sockets
{
context.Response.ContentType = "text/plain";
context.Response.StatusCode = StatusCodes.Status404NotFound;
_logger.TransportNotSupported(transportType);
Log.TransportNotSupported(_logger, transportType);
await context.Response.WriteAsync($"{transportType} transport not supported by this end point type");
return false;
}
@ -462,7 +462,7 @@ namespace Microsoft.AspNetCore.Sockets
{
context.Response.ContentType = "text/plain";
context.Response.StatusCode = StatusCodes.Status400BadRequest;
_logger.CannotChangeTransport(transport.Value, transportType);
Log.CannotChangeTransport(_logger, transport.Value, transportType);
await context.Response.WriteAsync("Cannot change transports mid-connection");
return false;
}

View File

@ -1,248 +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.Internal
{
internal static class SocketHttpLoggerExtensions
{
// Category: LongPollingTransport
private static readonly Action<ILogger, Exception> _longPolling204 =
LoggerMessage.Define(LogLevel.Information, new EventId(1, nameof(LongPolling204)), "Terminating Long Polling connection by sending 204 response.");
private static readonly Action<ILogger, Exception> _pollTimedOut =
LoggerMessage.Define(LogLevel.Information, new EventId(2, nameof(PollTimedOut)), "Poll request timed out. Sending 200 response to connection.");
private static readonly Action<ILogger, long, Exception> _longPollingWritingMessage =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(3, nameof(LongPollingWritingMessage)), "Writing a {count} byte message to connection.");
private static readonly Action<ILogger, Exception> _longPollingDisconnected =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, nameof(LongPollingDisconnected)), "Client disconnected from Long Polling endpoint for connection.");
private static readonly Action<ILogger, Exception> _longPollingTerminated =
LoggerMessage.Define(LogLevel.Error, new EventId(5, nameof(LongPollingTerminated)), "Long Polling transport was terminated due to an error on connection.");
// Category: HttpConnectionDispatcher
private static readonly Action<ILogger, string, Exception> _connectionDisposed =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(1, nameof(ConnectionDisposed)), "Connection Id {connectionId} was disposed.");
private static readonly Action<ILogger, string, string, Exception> _connectionAlreadyActive =
LoggerMessage.Define<string, string>(LogLevel.Debug, new EventId(2, nameof(ConnectionAlreadyActive)), "Connection Id {connectionId} is already active via {requestId}.");
private static readonly Action<ILogger, string, string, Exception> _pollCanceled =
LoggerMessage.Define<string, string>(LogLevel.Debug, new EventId(3, nameof(PollCanceled)), "Previous poll canceled for {connectionId} on {requestId}.");
private static readonly Action<ILogger, Exception> _establishedConnection =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, nameof(EstablishedConnection)), "Establishing new connection.");
private static readonly Action<ILogger, Exception> _resumingConnection =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, nameof(ResumingConnection)), "Resuming existing connection.");
private static readonly Action<ILogger, long, Exception> _receivedBytes =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(6, nameof(ReceivedBytes)), "Received {count} bytes.");
private static readonly Action<ILogger, TransportType, Exception> _transportNotSupported =
LoggerMessage.Define<TransportType>(LogLevel.Debug, new EventId(7, nameof(TransportNotSupported)), "{transportType} transport not supported by this endpoint type.");
private static readonly Action<ILogger, TransportType, TransportType, Exception> _cannotChangeTransport =
LoggerMessage.Define<TransportType, TransportType>(LogLevel.Debug, new EventId(8, nameof(CannotChangeTransport)), "Cannot change transports mid-connection; currently using {transportType}, requesting {requestedTransport}.");
private static readonly Action<ILogger, Exception> _postNotallowedForWebsockets =
LoggerMessage.Define(LogLevel.Debug, new EventId(9, nameof(PostNotAllowedForWebSockets)), "POST requests are not allowed for websocket connections.");
private static readonly Action<ILogger, Exception> _negotiationRequest =
LoggerMessage.Define(LogLevel.Debug, new EventId(10, nameof(NegotiationRequest)), "Sending negotiation response.");
// Category: WebSocketsTransport
private static readonly Action<ILogger, Exception> _socketOpened =
LoggerMessage.Define(LogLevel.Information, new EventId(1, nameof(SocketOpened)), "Socket opened.");
private static readonly Action<ILogger, Exception> _socketClosed =
LoggerMessage.Define(LogLevel.Information, new EventId(2, nameof(SocketClosed)), "Socket closed.");
private static readonly Action<ILogger, WebSocketCloseStatus?, string, Exception> _clientClosed =
LoggerMessage.Define<WebSocketCloseStatus?, string>(LogLevel.Debug, new EventId(3, nameof(ClientClosed)), "Client closed connection with status code '{status}' ({description}). Signaling end-of-input to application.");
private static readonly Action<ILogger, Exception> _waitingForSend =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, nameof(WaitingForSend)), "Waiting for the application to finish sending data.");
private static readonly Action<ILogger, Exception> _failedSending =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, nameof(FailedSending)), "Application failed during sending. Sending InternalServerError close frame.");
private static readonly Action<ILogger, Exception> _finishedSending =
LoggerMessage.Define(LogLevel.Debug, new EventId(6, nameof(FinishedSending)), "Application finished sending. Sending close frame.");
private static readonly Action<ILogger, Exception> _waitingForClose =
LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(WaitingForClose)), "Waiting for the client to close the socket.");
private static readonly Action<ILogger, Exception> _closeTimedOut =
LoggerMessage.Define(LogLevel.Debug, new EventId(8, nameof(CloseTimedOut)), "Timed out waiting for client to send the close frame, aborting the connection.");
private static readonly Action<ILogger, WebSocketMessageType, int, bool, Exception> _messageReceived =
LoggerMessage.Define<WebSocketMessageType, int, bool>(LogLevel.Debug, new EventId(9, nameof(MessageReceived)), "Message received. Type: {messageType}, size: {size}, EndOfMessage: {endOfMessage}.");
private static readonly Action<ILogger, int, Exception> _messageToApplication =
LoggerMessage.Define<int>(LogLevel.Debug, new EventId(10, nameof(MessageToApplication)), "Passing message to application. Payload size: {size}.");
private static readonly Action<ILogger, long, Exception> _sendPayload =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(11, nameof(SendPayload)), "Sending payload: {size} bytes.");
private static readonly Action<ILogger, Exception> _errorWritingFrame =
LoggerMessage.Define(LogLevel.Error, new EventId(12, nameof(ErrorWritingFrame)), "Error writing frame.");
private static readonly Action<ILogger, Exception> _sendFailed =
LoggerMessage.Define(LogLevel.Trace, new EventId(13, nameof(SendFailed)), "Socket failed to send.");
// Category: ServerSentEventsTransport
private static readonly Action<ILogger, long, Exception> _sseWritingMessage =
LoggerMessage.Define<long>(LogLevel.Debug, new EventId(1, nameof(SSEWritingMessage)), "Writing a {count} byte message.");
public static void LongPolling204(this ILogger logger)
{
_longPolling204(logger, null);
}
public static void PollTimedOut(this ILogger logger)
{
_pollTimedOut(logger, null);
}
public static void LongPollingWritingMessage(this ILogger logger, long count)
{
_longPollingWritingMessage(logger, count, null);
}
public static void LongPollingDisconnected(this ILogger logger)
{
_longPollingDisconnected(logger, null);
}
public static void LongPollingTerminated(this ILogger logger, Exception ex)
{
_longPollingTerminated(logger, ex);
}
public static void ConnectionDisposed(this ILogger logger, string connectionId)
{
_connectionDisposed(logger, connectionId, null);
}
public static void ConnectionAlreadyActive(this ILogger logger, string connectionId, string requestId)
{
_connectionAlreadyActive(logger, connectionId, requestId, null);
}
public static void PollCanceled(this ILogger logger, string connectionId, string requestId)
{
_pollCanceled(logger, connectionId, requestId, null);
}
public static void EstablishedConnection(this ILogger logger)
{
_establishedConnection(logger, null);
}
public static void ResumingConnection(this ILogger logger)
{
_resumingConnection(logger, null);
}
public static void ReceivedBytes(this ILogger logger, long count)
{
_receivedBytes(logger, count, null);
}
public static void TransportNotSupported(this ILogger logger, TransportType transport)
{
_transportNotSupported(logger, transport, null);
}
public static void CannotChangeTransport(this ILogger logger, TransportType transport, TransportType requestTransport)
{
_cannotChangeTransport(logger, transport, requestTransport, null);
}
public static void PostNotAllowedForWebSockets(this ILogger logger)
{
_postNotallowedForWebsockets(logger, null);
}
public static void NegotiationRequest(this ILogger logger)
{
_negotiationRequest(logger, null);
}
public static void SocketOpened(this ILogger logger)
{
_socketOpened(logger, null);
}
public static void SocketClosed(this ILogger logger)
{
_socketClosed(logger, null);
}
public static void ClientClosed(this ILogger logger, WebSocketCloseStatus? closeStatus, string closeDescription)
{
_clientClosed(logger, closeStatus, closeDescription, null);
}
public static void WaitingForSend(this ILogger logger)
{
_waitingForSend(logger, null);
}
public static void FailedSending(this ILogger logger)
{
_failedSending(logger, null);
}
public static void FinishedSending(this ILogger logger)
{
_finishedSending(logger, null);
}
public static void WaitingForClose(this ILogger logger)
{
_waitingForClose(logger, null);
}
public static void CloseTimedOut(this ILogger logger)
{
_closeTimedOut(logger, null);
}
public static void MessageReceived(this ILogger logger, WebSocketMessageType type, int size, bool endOfMessage)
{
_messageReceived(logger, type, size, endOfMessage, null);
}
public static void MessageToApplication(this ILogger logger, int size)
{
_messageToApplication(logger, size, null);
}
public static void SendPayload(this ILogger logger, long size)
{
_sendPayload(logger, size, null);
}
public static void ErrorWritingFrame(this ILogger logger, Exception ex)
{
_errorWritingFrame(logger, ex);
}
public static void SendFailed(this ILogger logger, Exception ex)
{
_sendFailed(logger, ex);
}
public static void SSEWritingMessage(this ILogger logger, long count)
{
_sseWritingMessage(logger, count, null);
}
}
}

View File

@ -2,10 +2,8 @@
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System;
using System.Diagnostics;
using System.IO;
using System.IO.Pipelines;
using System.Runtime.InteropServices;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http;
@ -37,7 +35,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
if (buffer.IsEmpty && result.IsCompleted)
{
_logger.LongPolling204();
Log.LongPolling204(_logger);
context.Response.ContentType = "text/plain";
context.Response.StatusCode = StatusCodes.Status204NoContent;
return;
@ -46,7 +44,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
// We're intentionally not checking cancellation here because we need to drain messages we've got so far,
// but it's too late to emit the 204 required by being cancelled.
_logger.LongPollingWritingMessage(buffer.Length);
Log.LongPollingWritingMessage(_logger, buffer.Length);
context.Response.ContentLength = buffer.Length;
context.Response.ContentType = "application/octet-stream";
@ -72,12 +70,12 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
{
// Don't count this as cancellation, this is normal as the poll can end due to the browser closing.
// The background thread will eventually dispose this connection if it's inactive
_logger.LongPollingDisconnected();
Log.LongPollingDisconnected(_logger);
}
// Case 2
else if (_timeoutToken.IsCancellationRequested)
{
_logger.PollTimedOut();
Log.PollTimedOut(_logger);
context.Response.ContentLength = 0;
context.Response.ContentType = "text/plain";
@ -86,16 +84,59 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
else
{
// Case 3
_logger.LongPolling204();
Log.LongPolling204(_logger);
context.Response.ContentType = "text/plain";
context.Response.StatusCode = StatusCodes.Status204NoContent;
}
}
catch (Exception ex)
{
_logger.LongPollingTerminated(ex);
Log.LongPollingTerminated(_logger, ex);
throw;
}
}
private static class Log
{
private static readonly Action<ILogger, Exception> _longPolling204 =
LoggerMessage.Define(LogLevel.Debug, new EventId(1, "LongPolling204"), "Terminating Long Polling connection by sending 204 response.");
private static readonly Action<ILogger, Exception> _pollTimedOut =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, "PollTimedOut"), "Poll request timed out. Sending 200 response to connection.");
private static readonly Action<ILogger, long, Exception> _longPollingWritingMessage =
LoggerMessage.Define<long>(LogLevel.Trace, new EventId(3, "LongPollingWritingMessage"), "Writing a {count} byte message to connection.");
private static readonly Action<ILogger, Exception> _longPollingDisconnected =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "LongPollingDisconnected"), "Client disconnected from Long Polling endpoint for connection.");
private static readonly Action<ILogger, Exception> _longPollingTerminated =
LoggerMessage.Define(LogLevel.Error, new EventId(5, "LongPollingTerminated"), "Long Polling transport was terminated due to an error on connection.");
public static void LongPolling204(ILogger logger)
{
_longPolling204(logger, null);
}
public static void PollTimedOut(ILogger logger)
{
_pollTimedOut(logger, null);
}
public static void LongPollingWritingMessage(ILogger logger, long count)
{
_longPollingWritingMessage(logger, count, null);
}
public static void LongPollingDisconnected(ILogger logger)
{
_longPollingDisconnected(logger, null);
}
public static void LongPollingTerminated(ILogger logger, Exception ex)
{
_longPollingTerminated(logger, ex);
}
}
}
}

View File

@ -53,7 +53,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
{
if (!buffer.IsEmpty)
{
_logger.SSEWritingMessage(buffer.Length);
Log.SSEWritingMessage(_logger, buffer.Length);
await ServerSentEventsMessageFormatter.WriteMessageAsync(buffer, context.Response.Body);
}
@ -73,5 +73,16 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
// Closed connection
}
}
private static class Log
{
private static readonly Action<ILogger, long, Exception> _sseWritingMessage =
LoggerMessage.Define<long>(LogLevel.Trace, new EventId(1, "SSEWritingMessage"), "Writing a {count} byte message.");
public static void SSEWritingMessage(ILogger logger, long count)
{
_sseWritingMessage(logger, count, null);
}
}
}
}

View File

@ -0,0 +1,120 @@
// 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.Internal.Transports
{
public partial class WebSocketsTransport
{
private static class Log
{
private static readonly Action<ILogger, Exception> _socketOpened =
LoggerMessage.Define(LogLevel.Debug, new EventId(1, "SocketOpened"), "Socket opened.");
private static readonly Action<ILogger, Exception> _socketClosed =
LoggerMessage.Define(LogLevel.Debug, new EventId(2, "SocketClosed"), "Socket closed.");
private static readonly Action<ILogger, WebSocketCloseStatus?, string, Exception> _clientClosed =
LoggerMessage.Define<WebSocketCloseStatus?, string>(LogLevel.Debug, new EventId(3, "ClientClosed"), "Client closed connection with status code '{status}' ({description}). Signaling end-of-input to application.");
private static readonly Action<ILogger, Exception> _waitingForSend =
LoggerMessage.Define(LogLevel.Debug, new EventId(4, "WaitingForSend"), "Waiting for the application to finish sending data.");
private static readonly Action<ILogger, Exception> _failedSending =
LoggerMessage.Define(LogLevel.Debug, new EventId(5, "FailedSending"), "Application failed during sending. Sending InternalServerError close frame.");
private static readonly Action<ILogger, Exception> _finishedSending =
LoggerMessage.Define(LogLevel.Debug, new EventId(6, "FinishedSending"), "Application finished sending. Sending close frame.");
private static readonly Action<ILogger, Exception> _waitingForClose =
LoggerMessage.Define(LogLevel.Debug, new EventId(7, "WaitingForClose"), "Waiting for the client to close the socket.");
private static readonly Action<ILogger, Exception> _closeTimedOut =
LoggerMessage.Define(LogLevel.Debug, new EventId(8, "CloseTimedOut"), "Timed out waiting for client to send the close frame, aborting the connection.");
private static readonly Action<ILogger, WebSocketMessageType, int, bool, Exception> _messageReceived =
LoggerMessage.Define<WebSocketMessageType, int, bool>(LogLevel.Trace, new EventId(9, "MessageReceived"), "Message received. Type: {messageType}, size: {size}, EndOfMessage: {endOfMessage}.");
private static readonly Action<ILogger, int, Exception> _messageToApplication =
LoggerMessage.Define<int>(LogLevel.Trace, new EventId(10, "MessageToApplication"), "Passing message to application. Payload size: {size}.");
private static readonly Action<ILogger, long, Exception> _sendPayload =
LoggerMessage.Define<long>(LogLevel.Trace, new EventId(11, "SendPayload"), "Sending payload: {size} bytes.");
private static readonly Action<ILogger, Exception> _errorWritingFrame =
LoggerMessage.Define(LogLevel.Error, new EventId(12, "ErrorWritingFrame"), "Error writing frame.");
private static readonly Action<ILogger, Exception> _sendFailed =
LoggerMessage.Define(LogLevel.Error, new EventId(13, "SendFailed"), "Socket failed to send.");
public static void SocketOpened(ILogger logger)
{
_socketOpened(logger, null);
}
public static void SocketClosed(ILogger logger)
{
_socketClosed(logger, null);
}
public static void ClientClosed(ILogger logger, WebSocketCloseStatus? closeStatus, string closeDescription)
{
_clientClosed(logger, closeStatus, closeDescription, null);
}
public static void WaitingForSend(ILogger logger)
{
_waitingForSend(logger, null);
}
public static void FailedSending(ILogger logger)
{
_failedSending(logger, null);
}
public static void FinishedSending(ILogger logger)
{
_finishedSending(logger, null);
}
public static void WaitingForClose(ILogger logger)
{
_waitingForClose(logger, null);
}
public static void CloseTimedOut(ILogger logger)
{
_closeTimedOut(logger, null);
}
public static void MessageReceived(ILogger logger, WebSocketMessageType type, int size, bool endOfMessage)
{
_messageReceived(logger, type, size, endOfMessage, null);
}
public static void MessageToApplication(ILogger logger, int size)
{
_messageToApplication(logger, size, null);
}
public static void SendPayload(ILogger logger, long size)
{
_sendPayload(logger, size, null);
}
public static void ErrorWritingFrame(ILogger logger, Exception ex)
{
_errorWritingFrame(logger, ex);
}
public static void SendFailed(ILogger logger, Exception ex)
{
_sendFailed(logger, ex);
}
}
}
}

View File

@ -5,7 +5,6 @@ using System;
using System.Diagnostics;
using System.IO.Pipelines;
using System.Net.WebSockets;
using System.Runtime.InteropServices;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http;
@ -13,7 +12,7 @@ using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Sockets.Internal.Transports
{
public class WebSocketsTransport : IHttpTransport
public partial class WebSocketsTransport : IHttpTransport
{
private readonly WebSocketOptions _options;
private readonly ILogger _logger;
@ -50,7 +49,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
using (var ws = await context.WebSockets.AcceptWebSocketAsync(_options.SubProtocol))
{
_logger.SocketOpened();
Log.SocketOpened(_logger);
try
{
@ -58,7 +57,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
}
finally
{
_logger.SocketClosed();
Log.SocketClosed(_logger);
}
}
}
@ -74,7 +73,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
if (trigger == receiving)
{
_logger.WaitingForSend();
Log.WaitingForSend(_logger);
// We're waiting for the application to finish and there are 2 things it could be doing
// 1. Waiting for application data
@ -90,7 +89,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
if (resultTask != sending)
{
// We timed out so now we're in ungraceful shutdown mode
_logger.CloseTimedOut();
Log.CloseTimedOut(_logger);
// Abort the websocket if we're stuck in a pending send to the client
_aborted = true;
@ -105,7 +104,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
}
else
{
_logger.WaitingForClose();
Log.WaitingForClose(_logger);
// We're waiting on the websocket to close and there are 2 things it could be doing
// 1. Waiting for websocket data
@ -155,7 +154,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
return;
}
_logger.MessageReceived(receiveResult.MessageType, receiveResult.Count, receiveResult.EndOfMessage);
Log.MessageReceived(_logger, receiveResult.MessageType, receiveResult.Count, receiveResult.EndOfMessage);
_application.Output.Advance(receiveResult.Count);
@ -218,7 +217,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
{
try
{
_logger.SendPayload(buffer.Length);
Log.SendPayload(_logger, buffer.Length);
var webSocketMessageType = (_connection.TransferMode == TransferMode.Binary
? WebSocketMessageType.Binary
@ -237,7 +236,7 @@ namespace Microsoft.AspNetCore.Sockets.Internal.Transports
{
if (!_aborted)
{
_logger.ErrorWritingFrame(ex);
Log.ErrorWritingFrame(_logger, ex);
}
break;
}