Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save JamesNK/a3899fd68e9b9b6a3c6d3d9e2ae0c1a0 to your computer and use it in GitHub Desktop.
Save JamesNK/a3899fd68e9b9b6a3c6d3d9e2ae0c1a0 to your computer and use it in GitHub Desktop.
SignalR logging
[2018-05-21T23:17:57] [TestLifetime] [Information] Starting test "CanCloseStreamMethodEarly_json_ServerSentEvents_default"
[0.000s] [ServerLogScope] [Information] Server log scope started.
[0.000s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Waiting on Connection Lock in "StartAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":239).
[0.000s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Starting HubConnection.
[0.001s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Starting HttpConnection.
[0.001s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Establishing connection with server at 'http://127.0.0.1:1903/default'.
[0.002s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.LoggingHttpMessageHandler] [Verbose] Sending HTTP request "POST" 'http://127.0.0.1:1903/default/negotiate'.
[0.004s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5H" started.
[0.004s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request starting HTTP/1.1 POST http://127.0.0.1:1903/default/negotiate 0
[0.004s] [SERVER Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler] [Debug] AuthenticationScheme: Bearer was not authenticated.
[0.004s] [SERVER Microsoft.AspNetCore.Routing.RouteBase] [Debug] Request successfully matched the route with name '(null)' and template '/default/negotiate'.
[0.004s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager] [Debug] New connection LgO27VBMZlsKkll__uB4Yg created.
[0.004s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher] [Debug] LgO27VBMZlsKkll__uB4Yg - Sending negotiation response.
[0.005s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5H" completed keep alive response.
[0.005s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request finished in 0.8951ms 200 application/json
[0.005s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Established connection '"LgO27VBMZlsKkll__uB4Yg"' with the server.
[0.006s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Skipping transport "WebSockets" because it was disabled by the client.
[0.006s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Starting transport '"ServerSentEvents"' with Url: http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg.
[0.006s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Information] Starting transport. Transfer mode: Text.
[0.006s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.LoggingHttpMessageHandler] [Verbose] Sending HTTP request "GET" 'http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg'.
[0.006s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request starting HTTP/1.1 GET http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg
[0.006s] [SERVER Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler] [Debug] AuthenticationScheme: Bearer was not authenticated.
[0.006s] [SERVER Microsoft.AspNetCore.Routing.RouteBase] [Debug] Request successfully matched the route with name '(null)' and template '/default'.
[0.007s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher] [Debug] LgO27VBMZlsKkll__uB4Yg - Establishing new connection.
[0.007s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Starting receive loop.
[0.007s] [SERVER Microsoft.AspNetCore.SignalR.HubConnectionHandler] [Debug] LgO27VBMZlsKkll__uB4Yg - OnConnectedAsync started.
[0.007s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Received 3 bytes. Parsing SSE frame.
[0.007s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Starting the send loop.
[0.007s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Transport 'ServerSentEvents' started.
[0.007s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Information] HttpConnection Started.
[0.008s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Information] Using HubProtocol '"json" v1'.
[0.008s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Sending Hub Handshake.
[0.008s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Sending 32 bytes to the server using url: http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg.
[0.008s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.LoggingHttpMessageHandler] [Verbose] Sending HTTP request "POST" 'http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg'.
[0.009s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5I" started.
[0.009s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request starting HTTP/1.1 POST http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg 32
[0.009s] [SERVER Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler] [Debug] AuthenticationScheme: Bearer was not authenticated.
[0.009s] [SERVER Microsoft.AspNetCore.Routing.RouteBase] [Debug] Request successfully matched the route with name '(null)' and template '/default'.
[0.009s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] LgO27VBMZlsKkll__uB4Yg - Connection id "0HLDVE3S42R5I", Request id "0HLDVE3S42R5I:00000001": started reading request body.
[0.010s] [SERVER Microsoft.AspNetCore.SignalR.Internal.DefaultHubProtocolResolver] [Debug] LgO27VBMZlsKkll__uB4Yg - Found protocol implementation for requested protocol: json.
[0.010s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] LgO27VBMZlsKkll__uB4Yg - Connection id "0HLDVE3S42R5I", Request id "0HLDVE3S42R5I:00000001": done reading request body.
[0.010s] [SERVER Microsoft.AspNetCore.SignalR.HubConnectionContext] [Information] LgO27VBMZlsKkll__uB4Yg - Completed connection handshake. Using HubProtocol 'json'.
[0.010s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher] [Verbose] LgO27VBMZlsKkll__uB4Yg - Received 32 bytes.
[0.010s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.Transports.ServerSentEventsTransport] [Verbose] LgO27VBMZlsKkll__uB4Yg - Writing a 3 byte message.
[0.010s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5I" completed keep alive response.
[0.010s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Message(s) sent successfully.
[0.010s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request finished in 1.2521ms 200 text/plain
[0.010s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Received 13 bytes. Parsing SSE frame.
[0.010s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Passing message to application. Payload size: 3.
[0.010s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Handshake with server complete.
[0.010s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Receive loop starting.
[0.010s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Starting server timeout timer. Duration: 30000.00ms
[0.010s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Information] HubConnection started.
[0.010s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Releasing Connection Lock in "StartAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":281).
[0.011s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Waiting on Connection Lock in "StreamAsChannelCoreAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":364).
[0.011s] [Microsoft.AspNetCore.SignalR.Client.Internal.InvocationRequest.Streaming] [Verbose] Invocation "1" created.
[0.011s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Preparing streaming invocation '"1"' of '"Stream"', with return type '"System.Int32"' and 1 argument(s).
[0.011s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Registering Invocation ID '"1"' for tracking.
[0.011s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Issuing Invocation '"1"': "System.Int32" "Stream"("System.Int32").
[0.011s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Sending "StreamInvocationMessage" message '"1"'.
[0.011s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Sending 67 bytes to the server using url: http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg.
[0.011s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Sending "StreamInvocationMessage" message '"1"' completed.
[0.012s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.LoggingHttpMessageHandler] [Verbose] Sending HTTP request "POST" 'http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg'.
[0.012s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Releasing Connection Lock in "StreamAsChannelCoreAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":382).
[0.012s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request starting HTTP/1.1 POST http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg 67
[0.012s] [SERVER Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler] [Debug] AuthenticationScheme: Bearer was not authenticated.
[0.012s] [SERVER Microsoft.AspNetCore.Routing.RouteBase] [Debug] Request successfully matched the route with name '(null)' and template '/default'.
[0.012s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] LgO27VBMZlsKkll__uB4Yg - Connection id "0HLDVE3S42R5I", Request id "0HLDVE3S42R5I:00000002": started reading request body.
[0.012s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] LgO27VBMZlsKkll__uB4Yg - Connection id "0HLDVE3S42R5I", Request id "0HLDVE3S42R5I:00000002": done reading request body.
[0.012s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher] [Verbose] LgO27VBMZlsKkll__uB4Yg - Received 67 bytes.
[0.012s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5I" completed keep alive response.
[0.012s] [SERVER Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher] [Debug] LgO27VBMZlsKkll__uB4Yg - Received stream hub invocation: StreamInvocation { InvocationId: "1", Target: "Stream", Arguments: [ 1000 ] }.
[0.012s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request finished in 0.6575ms 200 text/plain
[0.013s] [SERVER Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher] [Verbose] LgO27VBMZlsKkll__uB4Yg - InvocationId 1: Streaming result of type 'System.Threading.Channels.ChannelReader`1[[System.Int32, System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]]'.
[0.013s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Message(s) sent successfully.
[0.013s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.Transports.ServerSentEventsTransport] [Verbose] LgO27VBMZlsKkll__uB4Yg - Writing a 39 byte message.
[0.013s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Received 49 bytes. Parsing SSE frame.
[0.013s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Passing message to application. Payload size: 39.
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Resetting keep-alive timer, received a message from the server.
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Processing 39 byte message from server.
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Received StreamItem for Invocation "1".
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Waiting on Connection Lock in "StreamAsChannelCoreAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":339).
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Sending Cancellation for Invocation '"1"'.
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Sending "CancelInvocationMessage" message '"1"'.
[0.013s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Sending 30 bytes to the server using url: http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg.
[0.013s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Sending "CancelInvocationMessage" message '"1"' completed.
[0.014s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.LoggingHttpMessageHandler] [Verbose] Sending HTTP request "POST" 'http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg'.
[0.014s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Releasing Connection Lock in "StreamAsChannelCoreAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":356).
[0.014s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request starting HTTP/1.1 POST http://127.0.0.1:1903/default?id=LgO27VBMZlsKkll__uB4Yg 30
[0.014s] [Microsoft.AspNetCore.SignalR.Client.Internal.InvocationRequest.Streaming] [Verbose] Invocation "1" disposed.
[0.014s] [SERVER Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler] [Debug] AuthenticationScheme: Bearer was not authenticated.
[0.014s] [SERVER Microsoft.AspNetCore.Routing.RouteBase] [Debug] Request successfully matched the route with name '(null)' and template '/default'.
[0.014s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] LgO27VBMZlsKkll__uB4Yg - Connection id "0HLDVE3S42R5I", Request id "0HLDVE3S42R5I:00000003": started reading request body.
[0.014s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Waiting on Connection Lock in "StopAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":297).
[0.014s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] LgO27VBMZlsKkll__uB4Yg - Connection id "0HLDVE3S42R5I", Request id "0HLDVE3S42R5I:00000003": done reading request body.
[0.014s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Releasing Connection Lock in "StopAsyncCore" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":324).
[0.014s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher] [Verbose] LgO27VBMZlsKkll__uB4Yg - Received 30 bytes.
[0.014s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5I" completed keep alive response.
[0.014s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Stopping HubConnection.
[0.014s] [SERVER Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request finished in 0.6177ms 200 text/plain
[0.014s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Terminating receive loop.
[0.014s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Waiting for the receive loop to terminate.
[0.014s] [SERVER Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher] [Debug] LgO27VBMZlsKkll__uB4Yg - Canceling stream for invocation 1.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Message(s) sent successfully.
[0.015s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Waiting on Connection Lock in "ReceiveLoop" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":776).
[0.015s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Releasing Connection Lock in "ReceiveLoop" ("/_/src/Microsoft.AspNetCore.SignalR.Client.Core/HubConnection.cs":785).
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Debug] Disposing HttpConnection.
[0.015s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.Transports.ServerSentEventsTransport] [Verbose] LgO27VBMZlsKkll__uB4Yg - Writing a 30 byte message.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Information] Transport is stopping.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Send loop canceled.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Received 40 bytes. Parsing SSE frame.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Passing message to application. Payload size: 30.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Send loop stopped.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Server-Sent Event Stream ended.
[0.015s] [SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets] [Debug] Connection id "0HLDVE3S42R5H" received FIN.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Receive loop stopped.
[0.015s] [SERVER Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLDVE3S42R5H" disconnecting.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.Internal.ServerSentEventsTransport] [Debug] Transport stopped.
[0.015s] [SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets] [Debug] Connection id "0HLDVE3S42R5H" sending FIN.
[0.015s] [Microsoft.AspNetCore.Http.Connections.Client.HttpConnection] [Information] HttpConnection Disposed.
[0.016s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] Canceling all outstanding invocations.
[0.016s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Removing pending invocation "1".
[0.016s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext] [Verbose] LgO27VBMZlsKkll__uB4Yg - Disposing connection LgO27VBMZlsKkll__uB4Yg.
[0.016s] [Microsoft.AspNetCore.SignalR.Client.Internal.InvocationRequest.Streaming] [Verbose] Invocation "1" disposed.
[0.016s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Verbose] Shutting down connection.
[0.016s] [Microsoft.AspNetCore.SignalR.Client.HubConnection] [Debug] HubConnection stopped.
[0.016s] [SERVER Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext] [Verbose] LgO27VBMZlsKkll__uB4Yg - Waiting for application to complete.
[0.016s] [ServerLogScope] [Information] Server log scope stopped.
[0.016s] [TestLifetime] [Information] Finished test "CanCloseStreamMethodEarly_json_ServerSentEvents_default" in 0.0159792s
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment