Merge pull request #1789 from aspnet/release/2.1

Re-enable ConnectionCanSendAndReceiveMessages + logging (#1778)

src/Microsoft.AspNetCore.Sockets.Client.Http/HttpConnection.Log.cs

@@ -62,6 +62,9 @@ namespace Microsoft.AspNetCore.Sockets.Client.Http
             private static readonly Action<ILogger, Exception> _transportThrewExceptionOnStop =
                 LoggerMessage.Define(LogLevel.Error, new EventId(17, "TransportThrewExceptionOnStop"), "The transport threw an exception while stopping.");
 
+            private static readonly Action<ILogger, string, Exception> _transportStarted =
+                LoggerMessage.Define<string>(LogLevel.Debug, new EventId(18, "TransportStarted"), "Transport '{Transport}' started.");
+
             public static void Starting(ILogger logger)
             {
                 _starting(logger, null);
@@ -161,6 +164,14 @@ namespace Microsoft.AspNetCore.Sockets.Client.Http
             {
                 _transportThrewExceptionOnStop(logger, ex);
             }
+
+            public static void TransportStarted(ILogger logger, ITransport transport)
+            {
+                if (logger.IsEnabled(LogLevel.Debug))
+                {
+                    _transportStarted(logger, transport.GetType().Name, null);
+                }
+            }
         }
     }
 }

src/Microsoft.AspNetCore.Sockets.Client.Http/HttpConnection.cs

@@ -348,7 +348,7 @@ namespace Microsoft.AspNetCore.Sockets.Client.Http
             }
             catch (Exception ex)
             {
-                Log.ErrorStartingTransport(_logger, _transport, ex);
+                Log.ErrorStartingTransport(_logger, transport, ex);
                 _transport = null;
                 throw;
             }
@@ -356,6 +356,8 @@ namespace Microsoft.AspNetCore.Sockets.Client.Http
             // We successfully started, set the transport properties (we don't want to set these until the transport is definitely running).
             _transport = transport;
             _transportPipe = pair.Transport;
+
+            Log.TransportStarted(_logger, _transport);
         }
 
         private HttpClient CreateHttpClient()

src/Microsoft.AspNetCore.Sockets.Client.Http/Internal/LongPollingTransport.cs

@@ -93,7 +93,17 @@ namespace Microsoft.AspNetCore.Sockets.Client.Internal
 
             _application.Input.CancelPendingRead();
 
-            await Running;
+            try
+            {
+                await Running;
+            }
+            catch (Exception ex)
+            {
+                Log.TransportStopped(_logger, ex);
+                throw;
+            }
+
+            Log.TransportStopped(_logger, null);
         }
 
         private async Task Poll(Uri pollUrl, CancellationToken cancellationToken)

src/Microsoft.AspNetCore.Sockets.Client.Http/Internal/ServerSentEventsTransport.cs

@@ -200,7 +200,17 @@ namespace Microsoft.AspNetCore.Sockets.Client.Internal
 
             _application.Input.CancelPendingRead();
 
-            await Running;
+            try
+            {
+                await Running;
+            }
+            catch (Exception ex)
+            {
+                Log.TransportStopped(_logger, ex);
+                throw;
+            }
+
+            Log.TransportStopped(_logger, null);
         }
     }
 }

src/Microsoft.AspNetCore.Sockets.Client.Http/Internal/WebSocketsTransport.cs

@@ -348,10 +348,14 @@ namespace Microsoft.AspNetCore.Sockets.Client.Internal
             {
                 await Running;
             }
-            catch
+            catch (Exception ex)
             {
+                Log.TransportStopped(_logger, ex);
                 // exceptions have been handled in the Running task continuation by closing the channel with the exception
+                return;
             }
+
+            Log.TransportStopped(_logger, null);
         }
     }
 }

test/Microsoft.AspNetCore.SignalR.Tests/EndToEndTests.cs

@@ -197,11 +197,11 @@ namespace Microsoft.AspNetCore.SignalR.Tests
             }
         }
 
-        [Theory(Skip = "https://github.com/aspnet/SignalR/issues/1485")]
+        [Theory]
         [MemberData(nameof(TransportTypesAndTransferFormats))]
         public async Task ConnectionCanSendAndReceiveMessages(TransportType transportType, TransferFormat requestedTransferFormat)
         {
-            using (StartLog(out var loggerFactory, testName: $"ConnectionCanSendAndReceiveMessages_{transportType.ToString()}"))
+            using (StartLog(out var loggerFactory, minLogLevel: LogLevel.Trace, testName: $"ConnectionCanSendAndReceiveMessages_{transportType.ToString()}_{requestedTransferFormat.ToString()}"))
             {
                 var logger = loggerFactory.CreateLogger<EndToEndTests>();
 
@@ -230,10 +230,11 @@ namespace Microsoft.AspNetCore.SignalR.Tests
                         // Our solution to this is to just catch OperationCanceledException from the sent message if the race happens
                         // because we know the send went through, and its safe to check the response.
                     }
+
                     logger.LogInformation("Sent message");
 
                     logger.LogInformation("Receiving message");
-                    Assert.Equal(message, Encoding.UTF8.GetString(await connection.Transport.Input.ReadAsync(bytes.Length)));
+                    Assert.Equal(message, Encoding.UTF8.GetString(await connection.Transport.Input.ReadAsync(bytes.Length).OrTimeout()));
                     logger.LogInformation("Completed receive");
                 }
                 catch (Exception ex)