Re: [EXTERNAL] Re: Add non-blocking version of PQcancel

Andres Freund <andres@anarazel.de>

From: Andres Freund <andres@anarazel.de>
To: Alexander Lakhin <exclusion@gmail.com>
Cc: Tom Lane <tgl@sss.pgh.pa.us>, Jelte Fennema-Nio <postgres@jeltef.nl>, Alvaro Herrera <alvherre@alvh.no-ip.org>, Noah Misch <noah@leadboat.com>, Jacob Champion <jacob.champion@enterprisedb.com>, Denis Laxalde <denis.laxalde@dalibo.com>, vignesh C <vignesh21@gmail.com>, Thomas Munro <thomas.munro@gmail.com>, Greg Stark <stark@mit.edu>, "Gregory Stark (as CFM)" <stark.cfm@gmail.com>, Daniel Gustafsson <daniel@yesql.se>, Peter Eisentraut <peter@eisentraut.org>, Justin Pryzby <pryzby@telsasoft.com>, Robert Haas <robertmhaas@gmail.com>, PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>, Etsuro Fujita <etsuro.fujita@gmail.com>
Date: 2024-11-17T01:37:57Z
Lists: pgsql-hackers
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

  1. postgres_fdw: re-issue cancel requests a few times if necessary.

  2. Make postgres_fdw's query_cancel test less flaky.

  3. postgres_fdw: Split out the query_cancel test to its own file

  4. Fix copy-paste mistake in PQcancelCreate

  5. Make libpqsrv_cancel's return const char *, not char *

  6. Stabilize postgres_fdw test

  7. libpq-be-fe-helpers.h: wrap new cancel APIs

  8. dblink/isolationtester/fe_utils: Use new cancel API

  9. Put libpq_pipeline cancel test back

  10. Hopefully make libpq_pipeline's new cancel test more reliable

  11. libpq: Add encrypted and non-blocking query cancellation routines

  12. libpq: Move pg_cancel to fe-cancel.c

  13. Add tests for libpq query cancellation APIs

  14. Add missing connection statuses to docs

  15. libpq: Change some static functions to extern

  16. libpq: Add pqReleaseConnHosts function

  17. libpq: Move cancellation related functions to fe-cancel.c

  18. Make spelling of cancelled/cancellation consistent

  19. Be more wary about OpenSSL not setting errno on error.

  20. libpq: Use modern socket flags, if available.

  21. Drop test view when done with it.

  22. Doc: add some doco about using the libpq_pipeline test module.

  23. postgres_fdw: Allow cancellation of transaction control commands.