Changes

This combination PR is both fixing a GC issue (see below, and #2413 for details) and improves timeout exception. Basically if a timeout happens for a message that was in the backlog but was never sent, the user now gets a much more informative message like this:

Exception: The message timed out in the backlog attempting to send because no connection became available - Last Connection Exception: InternalFailure on 127.0.0.1:6379/Interactive, Initializing/NotStarted, last: GET, origin: ConnectedAsync, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 500s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.6.99.22667, command=PING, inst: 0, qu: 0, qs: 0, aw: False, bw: CheckingForTimeout, last-in: 0, cur-in: 0, sync-ops: 1, async-ops: 1, serverEndpoint: 127.0.0.1:6379, conn-sec: n/a, aoc: 0, mc: 1/1/0, mgr: 10 of 10 available, clientName: NAMISTOU-3(SE.Redis-v2.6.99.22667), IOCP: (Busy=0,Free=1000,Min=32,Max=1000), WORKER: (Busy=2,Free=32765,Min=32,Max=32767), POOL: (Threads=18,QueuedItems=0,CompletedItems=65), v: 2.6.99.22667 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)

Today, this isn't intuitive especially for connections with AbortOnConnectFail set to false. What happens is a multiplexer never connects successfully, but the user just gets generic timeouts. This makes the error more specific and includes the inner exception (also as .InnerException) for more details, informing the user of a config/auth/whatever error underneath as to why things are never successfully sending.

Also adds aoc: (0|1) to the exception message for easier advice in issues (reflecting what AbortOnConnectFail is set to).

Performance

Before:

After:

Original hanging issue for anyone curious - fixed in #2413:

Hanging problems

The new tests in this PR currently exhibit an indefinite hang from teardown of infrastructure before an await completes.

To repro indefinite hangs, please comment out this code in PhysicalBridge:

- AbandonPendingBacklog(new ObjectDisposedException("Connection is being finalized"));
+ //AbandonPendingBacklog(new ObjectDisposedException("Connection is being finalized"));

(note: I didn't leave the hang repro intact because it'll hose the build servers)

Take for example an even simpler version of DisconnectAndNoReconnectThrowsConnectionExceptionAsync here:

public async Task HangExample()
{
    using var conn = ConnectionMultiplexer.Connect("localhost:6379,allowAdmin=true");
    var db = conn.GetDatabase();

    conn.AllowConnect = false; // Disconnect and don't allow re-connection
    var server = conn.GetServerSnapshot()[0];
    server.SimulateConnectionFailure(SimulatedFailureType.All);

    // This will never complete, because nothing clears the backlog and activates the async continuations. 
    // Rather than the PhysicalBridge clearing the backlog, everything gets finalized before this test method completes:
    // The ConnectionMultiplexer, ServerEndpoint, and PhysicalBridge are all torn down (we've added finalizers to each to confirm)
    await db.PingAsync();
}

If we restore the AbandonPendingBacklog above as another experiment, we can demo the Task.AsyncState referenced case:

public async Task HangExample2()
{
    using var conn = ConnectionMultiplexer.Connect("localhost:6379,allowAdmin=true");
    var db = conn.GetDatabase(asyncState: conn);

    conn.AllowConnect = false; // Disconnect and don't allow re-connection
    var server = conn.GetServerSnapshot()[0];
    server.SimulateConnectionFailure(SimulatedFailureType.All);

    object? state = null;
    try
    {
        var task = db.PingAsync();
        state = task.AsyncState;
        await task;
    }
    catch (Exception ex)
    {
        Log("Task.AsyncState (" + state?.GetType() + "): " + state?.ToString());
        Log("Exception: " + ex);
    }
}

Logs:

17:15:21.1585: Task.AsyncState (StackExchange.Redis.ConnectionMultiplexer): NAMISTOU-3(SE.Redis-v2.6.101.9028)
17:15:21.1585: Exception: System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'Connection is being finalized'.
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at StackExchange.Redis.Tests.AbortOnConnectFailTests.<HangExample2>d__4.MoveNext() in C:\git\StackExchange\StackExchange.Redis\tests\StackExchange.Redis.Tests\AbortOnConnectFailTests.cs:line 77

For ref, the object hierarchy is:

• ConnectionMultiplexer
  • ServerEndPoint
    • PhysicalBridge (contains the unsent backlog queue)
      • PhysicalConnection
        • Socket

In the above, we've tried:

1. Adding a finalizer to ConnectionMultiplexer, ServerEndPoint, and PhysicalBrdige - all are getting finalized before PingAsync() completes.
2. GC.KeepAlive(...) to each of the above
3. Passing in conn to .GetDatabase() - this passes it as AsyncState all the way down through TaskCompletionSource and correctly sets it on the Task in PingAsync

Notes:

• In 3 above, we can simultaneously see that Task.AsyncState is indeed the ConnectionMultiplexer, so we have a reference to it...and it's still being finalized. It seems like the async state machine isn't being correctly held onto in some way.
• This doesn't reproduce in an isolated test - needs all to run presumably for GC pressure.

Aside notes:

Note also adds aoc: 1/0 to timeout messages - this'll make it easier for us to see if a user is setting abortConnect=false or not when advising them.