CancellationToken has no effect until Command Timeout while the server doesn't answer the prepended DISCARD ALL · Issue #6662 · npgsql/npgsql · GitHub
Skip to content

CancellationToken has no effect until Command Timeout while the server doesn't answer the prepended DISCARD ALL #6662

Open

Description

@lahma

Summary

When a pooled connection is returned to the pool, DISCARD ALL is prepended to its next command (NpgsqlConnector.cs#L2556). If the user's CancellationToken fires while that prepended response is still outstanding, PerformImmediateUserCancellation only records the request and returns, because ReadingPrependedMessagesMRE.Wait(0) is false (#5032/#5033). The deferred cancellation (#5191/#5774) runs only after the prepended responses have been read.

If the server is unresponsive (frozen, partitioned, overloaded, docker pause), those responses never arrive and the token has no effect. The command ends only at Command Timeout plus the time the (failing) cancel request takes. With default settings this affects the first command of every pooled checkout, so for a pooled application, user cancellation against an unresponsive server is in practice bounded only by Command Timeout.

Steps to reproduce

A TCP proxy sits in front of a real PostgreSQL. Once "frozen", it keeps accepting connections and keeps existing sockets open, but relays no bytes. The repro warms one pooled connection, returns it to the pool, freezes the proxy, then runs ExecuteScalarAsync("select 1", token) with the token canceled at 3 s. Defaults: Command Timeout=30, Timeout=15, Cancellation Timeout=2000.

Program.cs (net10.0, references Npgsql)
// Usage: repro <pgHost:port> "<extra connection string>" <cancelAfterSeconds|none>
using System.Diagnostics;
using System.Net;
using System.Net.Sockets;
using Npgsql;

var upstream = args[0].Split(':');
var extra = args[1];
var cancelAfter = args[2];

var frozen = false;
var listener = new TcpListener(IPAddress.Loopback, 0);
listener.Start();
var proxyPort = ((IPEndPoint)listener.LocalEndpoint).Port;
_ = Task.Run(async () =>
{
    while (true)
    {
        var client = await listener.AcceptTcpClientAsync();
        _ = Task.Run(async () =>
        {
            using var c = client;
            using var server = new TcpClient();
            await server.ConnectAsync(upstream[0], int.Parse(upstream[1]));
            await Task.WhenAny(Pump(c.GetStream(), server.GetStream()), Pump(server.GetStream(), c.GetStream()));
        });
    }
});
async Task Pump(NetworkStream from, NetworkStream to)
{
    var buf = new byte[16384];
    while (true)
    {
        int n;
        try { n = await from.ReadAsync(buf); } catch { return; }
        if (n == 0) return;
        while (Volatile.Read(ref frozen)) await Task.Delay(50); // frozen: hold the bytes, keep the socket open
        try { await to.WriteAsync(buf.AsMemory(0, n)); } catch { return; }
    }
}

var cs = $"Host=127.0.0.1;Port={proxyPort};Username=postgres;Password=pw;Database=postgres;Maximum Pool Size=1;{extra}";
await using var ds = NpgsqlDataSource.Create(cs);

// Warm one pooled connector and return it to the pool: DISCARD ALL is prepended to its next command
await using (var warm = await ds.OpenConnectionAsync())
    await new NpgsqlCommand("select 1", warm).ExecuteScalarAsync();

await using var conn = await ds.OpenConnectionAsync(); // from the pool, no I/O
Volatile.Write(ref frozen, true);
var sw = Stopwatch.StartNew();
using var cts = cancelAfter == "none" ? new CancellationTokenSource() : new CancellationTokenSource(TimeSpan.FromSeconds(double.Parse(cancelAfter)));
try
{
    await using var cmd = new NpgsqlCommand("select 1", conn);
    await cmd.ExecuteScalarAsync(cts.Token);
    Console.WriteLine($"completed after {sw.Elapsed.TotalSeconds:0.0}s");
}
catch (Exception e)
{
    Console.WriteLine($"{e.GetType().Name} after {sw.Elapsed.TotalSeconds:0.0}s: {e.Message} / {e.InnerException?.GetType().Name}");
}
Console.WriteLine($"conn.FullState={conn.FullState}");

Results with the token canceled at 3 s:

Connection string extras Command returns at
(defaults) 60.0 s, OperationCanceledException (inner TimeoutException), connection Broken
GSS Encryption Mode=Disable 45.0 s
GSS Encryption Mode=Disable;Timeout=5 35.0 s
GSS Encryption Mode=Disable;Timeout=5;No Reset On Close=true 8.0 s

The last two rows differ only in the prepended DISCARD ALL. (The extra Timeout on the defaults row comes from the cancel request's GSS fallback; see #6655, I'll comment there separately.)

Root cause

Proposed fix

When the user cancellation is deferred, arm the client-side deadline straight away: ReadBuffer.Timeout = CancellationTimeout; ReadBuffer.Cts.CancelAfter(CancellationTimeout), or cancel immediately when Cancellation Timeout is -1. If that read deadline fires while the deferred user cancellation is pending and the prepended responses are still unread, the read buffer does not send a PostgreSQL cancel request. It breaks the connector with OperationCanceledException. If the prepended responses do arrive in time, PerformDelayedUserCancellation proceeds as it does today and re-arms its own Cancellation Timeout.

Nothing blocks, so #5032 cannot come back, and no cancel request can reach a prepended query, so #4906 cannot either. With this change the defaults row drops from 60 s to 5.0 s (3 s plus the 2 s Cancellation Timeout). The Command Timeout path without a token is unchanged. I'll open a PR with a PgPostmasterMock test.

Related: #3346, #5070.

Further technical details

Npgsql version: 10.0.3, and main @ 3a03670
PostgreSQL version: 17
Operating system: Windows 11, .NET 10

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions