Re: [EXTERNAL] Re: Add non-blocking version of PQcancel
Andres Freund <andres@anarazel.de>
Hi,
On 2024-10-01 15:00:00 +0300, Alexander Lakhin wrote:
> Hello Tom and Jelte,
>
> 31.08.2024 07:04, Alexander Lakhin wrote:
> > I've tested your fix with the modification I proposed upthread:
> > idle_session_timeout_enabled = false;
> > }
> > +if (rand() % 10 == 0) pg_usleep(10000);
> > /*
> > * (5) disable async signal conditions again.
> >
> > and can confirm that the issue is gone. On 8749d850f~1, the test failed
> > on iterations 3, 3. 12 for me, but on current REL_17_STABLE, 100 test
> > iterations succeeded.
> >
>
> One month later, treehopper has found a way to break that test: [1].
> The failure log contains:
> 2024-09-30 19:34:31.347 UTC [3201034:13] fdw_retry_check LOG: execute <unnamed>: DECLARE c2 CURSOR FOR
> SELECT count(*) FROM ((("S 1"."T 1" r1 INNER JOIN "S 1"."T 1" r2 ON
> (TRUE)) INNER JOIN "S 1"."T 1" r4 ON (TRUE)) INNER JOIN "S 1"."T 1" r6 ON
> (TRUE))
> 2024-09-30 19:34:31.464 UTC [3201033:10] pg_regress/query_cancel ERROR: canceling statement due to statement timeout
> 2024-09-30 19:34:31.464 UTC [3201033:11] pg_regress/query_cancel STATEMENT:
> SELECT count(*) FROM ft1 a CROSS JOIN ft1 b CROSS JOIN ft1 c CROSS JOIN ft1
> d;
> 2024-09-30 19:34:31.466 UTC [3201035:1] [unknown] LOG: connection received: host=[local]
> 2024-09-30 19:34:31.474 UTC [3201034:14] fdw_retry_check LOG: statement: FETCH 100 FROM c2
> 2024-09-30 19:35:01.485 UTC [3201033:12] pg_regress/query_cancel WARNING:
> could not get result of cancel request due to timeout
Another failure in CI, that cleared up after a retry:
https://cirrus-ci.com/task/5725647677423616
https://api.cirrus-ci.com/v1/artifact/task/5725647677423616/log/contrib/postgres_fdw/regression.diffs
https://api.cirrus-ci.com/v1/artifact/task/5725647677423616/log/contrib/postgres_fdw/log/postmaster.log
diff -U3 /tmp/cirrus-ci-build/contrib/postgres_fdw/expected/query_cancel.out /tmp/cirrus-ci-build/contrib/postgres_fdw/results/query_cancel.out
--- /tmp/cirrus-ci-build/contrib/postgres_fdw/expected/query_cancel.out 2024-11-16 22:13:32.174593005 +0000
+++ /tmp/cirrus-ci-build/contrib/postgres_fdw/results/query_cancel.out 2024-11-16 22:21:20.165877954 +0000
@@ -29,4 +29,5 @@
-- This would take very long if not canceled:
SELECT count(*) FROM ft1 a CROSS JOIN ft1 b CROSS JOIN ft1 c CROSS JOIN ft1 d;
ERROR: canceling statement due to statement timeout
+WARNING: could not get result of cancel request due to timeout
COMMIT;
Statement logging isn't enabled for the test, so the log isn't that helpful:
2024-11-16 22:20:49.962 UTC [38643][not initialized] [[unknown]][:0] LOG: connection received: host=[local]
2024-11-16 22:20:49.964 UTC [38643][client backend] [[unknown]][67/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/contrib/postgres_fdw/tmp_check/data/pg_hba.conf:117)
2024-11-16 22:20:49.964 UTC [38643][client backend] [[unknown]][67/1:0] LOG: connection authorized: user=postgres database=contrib_regression application_name=pg_regress/query_cancel
2024-11-16 22:20:50.007 UTC [38645][not initialized] [[unknown]][:0] LOG: connection received: host=[local]
2024-11-16 22:20:50.010 UTC [38645][client backend] [[unknown]][68/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/contrib/postgres_fdw/tmp_check/data/pg_hba.conf:117)
2024-11-16 22:20:50.010 UTC [38645][client backend] [[unknown]][68/1:0] LOG: connection authorized: user=postgres database=contrib_regression application_name=fdw_retry_check
2024-11-16 22:20:50.148 UTC [38643][client backend] [pg_regress/query_cancel][67/4:0] ERROR: canceling statement due to statement timeout
2024-11-16 22:20:50.148 UTC [38643][client backend] [pg_regress/query_cancel][67/4:0] STATEMENT: SELECT count(*) FROM ft1 a CROSS JOIN ft1 b CROSS JOIN ft1 c CROSS JOIN ft1 d;
2024-11-16 22:20:50.159 UTC [38656][not initialized] [[unknown]][:0] LOG: connection received: host=[local]
2024-11-16 22:21:20.167 UTC [38643][client backend] [pg_regress/query_cancel][67/0:0] WARNING: could not get result of cancel request due to timeout
2024-11-16 22:21:20.170 UTC [38643][client backend] [pg_regress/query_cancel][:0] LOG: disconnection: session time: 0:00:30.211 user=postgres database=contrib_regression host=[local]
2024-11-16 22:21:20.315 UTC [36800][postmaster] LOG: received fast shutdown request
Greetings,
Andres Freund
Commits
-
postgres_fdw: re-issue cancel requests a few times if necessary.
- c431986de16c 18.0 landed
- 89962bfef624 17.3 landed
-
Make postgres_fdw's query_cancel test less flaky.
- 8749d850f962 17.0 landed
- 0e5c823806a3 18.0 landed
-
postgres_fdw: Split out the query_cancel test to its own file
- d329a515f490 17.0 landed
- 90c1ba52e06d 18.0 landed
-
Fix copy-paste mistake in PQcancelCreate
- 6d2ac554911d 17.0 landed
- 3497c87b05a6 18.0 landed
-
Make libpqsrv_cancel's return const char *, not char *
- b8b37e41ba4a 17.0 landed
-
Stabilize postgres_fdw test
- ecf741cfae06 17.0 landed
-
libpq-be-fe-helpers.h: wrap new cancel APIs
- 2466d6654f85 17.0 landed
-
dblink/isolationtester/fe_utils: Use new cancel API
- 66ab9371a233 17.0 landed
-
Put libpq_pipeline cancel test back
- 6b3678d3474f 17.0 landed
-
Hopefully make libpq_pipeline's new cancel test more reliable
- 1ee910ce4371 17.0 landed
-
libpq: Add encrypted and non-blocking query cancellation routines
- 61461a300c1c 17.0 landed
-
libpq: Move pg_cancel to fe-cancel.c
- 4dec98c2af64 17.0 landed
-
Add tests for libpq query cancellation APIs
- 319e9e53f379 17.0 landed
-
Add missing connection statuses to docs
- 095493a3771a 17.0 landed
-
libpq: Change some static functions to extern
- 774bcffe4a98 17.0 landed
-
libpq: Add pqReleaseConnHosts function
- 53747f722228 17.0 landed
-
libpq: Move cancellation related functions to fe-cancel.c
- 6d4565a05f3f 17.0 landed
-
Make spelling of cancelled/cancellation consistent
- 8c9da1441df1 17.0 landed
-
Be more wary about OpenSSL not setting errno on error.
- 0a5c46a7a488 17.0 cited
-
libpq: Use modern socket flags, if available.
- bfc9497ece01 16.0 cited
-
Drop test view when done with it.
- 71a75626d527 16.0 cited
-
Doc: add some doco about using the libpq_pipeline test module.
- f40346ff0bae 16.0 landed
-
postgres_fdw: Allow cancellation of transaction control commands.
- ae9bfc5d6512 10.0 cited