Query cancellation not working

[hlinnaka]

Run this slow query, and try to cancel it by hitting CTRL-C. It doesn't get cancelled:

postgres=# create table itbl(i int4);
CREATE TABLE
postgres=# insert into itbl select g from generate_series(1, 1000000) g;
INSERT 0 1000000
postgres=# select avg(gcd(a.i, b.i + 1)+cbrt(a.i)) from itbl a, itbl b;
^CCancel request sent
^CCancel request sent
^CCancel request sent
^CCancel request sent
^CCancel request sent

[japinli]

Yeah, it can be reproduced.

It seems that occurs at pending->ExecuteTask(), which takes a long time to run, however, it does not have any chance to handle query cancellation, because it is running in DuckDB.

[Tishj]

Debugging this is somewhat difficult because when lldb is attached the SIGINT the client sends gets intercepted. I don't think the ExecuteTask is the issue, that is designed to do partial processing exactly so it can respond to interrupts more quickly

@JelteF I think this is somehow related to postgres <-> c++ interactions similar to #93 The implementation of this interrupt also faced these same issues and I was already confident this was not sturdy enough

See https://github.com/duckdb/pg_duckdb/pull/58

---

Important to note: I can't reproduce this on MacOS M2, seems to cancel instantly for me

[JelteF]

It reproduces a bit inconsistently. But I can get a reproducing case quite easily by adding the following line:

--- a/src/pgduckdb_node.cpp
+++ b/src/pgduckdb_node.cpp
@@ -71,6 +71,7 @@ ExecuteQuery(DuckdbScanState *state) {
    duckdb::PendingExecutionResult execution_result;
    do {
        execution_result = pending->ExecuteTask();
+       elog(WARNING, "pending->ExecuteTask() returned");
        if (QueryCancelPending) {
            // Send an interrupt
            connection->Interrupt();

And then waiting until output stops being flooded with logs. If that doesn't happen within 30 seconds, try again. After a few times you'll see no output being shown anymore (so ExecuteTask() never returns anymore), but still a single core is being maxed out. Pressing Ctrl+C doesn't do anything in that case, obviously because we never get to the the QueryCancelPending check below the log line anymore.

I did a basic perf flamegraph and got the following. All I can really see in it is that it doesn't seem to be stuck in a tight loop in a single function.

[Tishj]

elog(WARNING, "pending->ExecuteTask() returned");

Thanks for this, I can reproduce it, though very seldomly on a debug build, much more frequently on release. The flame graph you provided is likely from a debug build because it contains DataChunk::Verify which is optimized out in a release build.

Since this occurs much more often in release I can't imagine the verification code is relevant here. I'm not entirely sure what is causing this still, but my hunch so far from debugging is that the PhysicalCrossProduct is processing far too much before it returns from ExecuteTask

[Tishj]

I think the reason this isn't caught (/ isn't a problem) in the duckdb CLI is that there is no disconnect between the client<->server. The client (shell) receives a sigint and immediately calls db->Interrupt(), the interrupted flag is properly being checked during execution, so in the CLI this correctly stops.

In pg_duckdb we have to call Interrupt() ourselves, which we do after ExecuteTask returns, the problem is that ExecuteTask is doing way too much before returning in this case, so Interrupt() doesn't get called and thus the interrupted flag stays off

[Tishj]

I've made a PR to fix this upstream in DuckDB, it likely won't land until 1.2 even if it passes CI because it's very close to the core and deemed too risky for a bug fix release

I verified that pg_duckdb does not suffer from this issue with the diff applied to the duckdb submodule

[JelteF]

It sounds like maybe we should be swapping out the postgres signal handler for SIGINT and SIGTERM for one that calls db->Interrupt().

[Tishj]

I thought about that, but I think I read that's ill-advised?

Another thing we could do is make a change to duckdb that allows a callback to be registered for interrupt checking instead, then we can check the interrupt flag that postgres has set in there

Either way I think it's good to fix this upstream because I imagine python and other clients could suffer from this same issue where they're relying on ExecuteTask to return relatively quick before they can check for interrupts

[JelteF]

Leaving this in the 0.2.0 milestone. Hopefully by the time that 0.2.0 gets released DuckDB 1.2.0 will be released as well and we can benefit from https://github.com/duckdb/duckdb/pull/14034

If that turns out to not be enough. We need to rethink how to fix this, possibly by swapping out the signal handlers.

[JelteF]

Should get fixed automatically by #548

[JelteF]

This is fixed now by #548