Re: Can not cancel a call to a function that has opened a refcursor

From: Mike Knowsley <mike(dot)knowsley(at)bidorbuy(dot)co(dot)za>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, davecramer(at)postgres(dot)rocks
Cc: pgsql-bugs(at)lists(dot)postgresql(dot)org
Subject: Re: Can not cancel a call to a function that has opened a refcursor
Date: 2021-08-05 22:52:51
Message-ID: 63AC651E-88A2-4B48-A3A7-9EA7AFE5CC80@bidorbuy.co.za
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Thanks for the quick response Tom and Dave,

I did wonder if it was something like what you have described.

Although the JDBC lib appears to mask this from my test code.

In the first test case below (test1).
The plsql function has a 5 second pg_sleep delay on the select into the refcursor.
The Java logic traces before it calls callableStatement.execute() then immediately after the callableStatement.execute() returns but before the call to get the ResultSet.
The trace shows the JDBC callableStatement.execute() does not return for the functions full 5 second of the pg_sleep delay in the select into the refcursor. In that time the statements 2 second timeout does not interrupt this call.

So Postgres may return the refcursor almost immediately as you say, but the JDBC CallableStament.execute() doesn’t return immediately, it only returns when the query has found results.

Maybe not a bug but my essential problem remains. A function with a slow select into a refcursor can not be timed-out or cancelled.

BTW:
The second test case below (test7), shows a possible workaround for my use-case.
I alter the initial query to select into a temp table then select the temp table into the the open refcursor.
The timeout/cancel does work if it occurs during the (potentially slow) initial select into the temp table.

thanks again
Mike Knowsley
bidorbuy

---------

create or replace function test_delay_in_refcursor()
returns refcursor
as $$
declare
cursorReference refcursor;
begin

open cursorReference for
select 'test', pg_sleep(20);

return cursorReference;

end;
$$ language plpgsql;

/**
*/
private static void test1() {

log("------ test1 --------");

Connection connection = null;
CallableStatement callableStatement = null;
ResultSet resultSet = null;
try {
connection = DriverManager.getConnection(CONNECTION_URL);
connection.setAutoCommit(false);
callableStatement = connection.prepareCall("{ ? = call test_delay_in_refcursor }");
callableStatement.setQueryTimeout(2);
callableStatement.registerOutParameter(1, Types.REF_CURSOR);
log("test1 callableStatement.execute() test_delay_in_refcursor with 2 second timeout");
callableStatement.execute();
log("test1 callableStatement.execute() returned - not cancelled");
resultSet = (ResultSet) callableStatement.getObject(1);
}
catch(Exception e) {
if(e.getMessage().toLowerCase().contains("canceling statement")) {
log("test1 callableStatement cancelled");
}
else {
log("test1 Exception : " + e.getMessage());
}
}
finally {
try {
if(resultSet != null) resultSet.close();
if(callableStatement != null) callableStatement.close();
if(connection != null) connection.close();
}
catch(Exception e2) {}
}
}

2021-08-04T16:03:59.940 main ------ test1 --------
2021-08-04T16:04:00.058 main test1 callableStatement.execute() test_delay_in_refcursor with 2 second timeout
2021-08-04T16:04:05.074 main test1 callableStatement.execute() returned - not cancelled
————

create or replace function test_delay_with_temp_table()
returns refcursor
as $$
declare
cursorReference refcursor;
begin

create temp table results as
select test from (
select 'test' as test, pg_sleep(5)
) x;

open cursorReference for
select * from results;

return cursorReference;

end;
$$ language plpgsql;

private static void test7() {

log("------ test7 --------");

Connection connection = null;
CallableStatement callableStatement = null;
ResultSet resultSet = null;
try {
connection = DriverManager.getConnection(CONNECTION_URL);
connection.setAutoCommit(false);
callableStatement = connection.prepareCall("{ ? = call test_delay_with_temp_table }");
callableStatement.setQueryTimeout(2);
callableStatement.registerOutParameter(1, Types.REF_CURSOR);
log("test7 callableStatement.execute() test_delay_with_temp_table with 2 second timeout");
callableStatement.execute();
log("test7 callableStatement.execute() returned - not cancelled");
resultSet = (ResultSet) callableStatement.getObject(1);
}
catch(Exception e) {
if(e.getMessage().toLowerCase().contains("canceling statement")) {
log("test7 callableStatement cancelled");
}
else {
log("test7 Exception : " + e.getMessage());
}
}
finally {
try {
if(resultSet != null) resultSet.close();
if(callableStatement != null) callableStatement.close();
if(connection != null) connection.close();
}
catch(Exception e2) {}
}
}

2021-08-06T10:22:48.076 main ------ test7 --------
2021-08-06T10:22:48.199 main test7 callableStatement.execute() test_delay_with_temp_table with 2 second timeout
2021-08-06T10:22:50.221 main test7 callableStatement cancelled
J/J 06/08/21 10:22:50 Completed job!

> On 6/08/2021, at 3:19 AM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>
> Mike Knowsley <mike(dot)knowsley(at)bidorbuy(dot)co(dot)za> writes:
>> A request to cancel a call to a function does not cancel the function if the function has opened a refcursor which it is returning.
>
> As far as I can see, there is no such bug; you're just misunderstanding
> when the query referenced by the cursor will execute. The function
> test_delay_in_refcursor() sets up the cursor and returns basically
> immediately (certainly in much less than 2 seconds), so the timeout
> you have in the JDBC code will never fire. The expected pg_sleep(5)
> won't execute till you try to fetch something from the refcursor.
>
> Trying this manually in psql, I get
>
> ...
> CREATE FUNCTION
> regression=# \timing
> Timing is on.
> regression=# begin;
> BEGIN
> Time: 0.306 ms
> regression=*# select test_delay_in_refcursor();
> test_delay_in_refcursor
> -------------------------
> <unnamed portal 1>
> (1 row)
>
> Time: 0.314 ms
> regression=*# fetch from "<unnamed portal 1>";
> ?column? | pg_sleep
> ----------+----------
> test |
> (1 row)
>
> Time: 5005.475 ms (00:05.005)
>
> I could have canceled the FETCH (and doing so works);
> but I'm way too old and slow to cancel the submillisecond
> setup step.
>
> regards, tom lane

In response to

Browse pgsql-bugs by date

  From Date Subject
Next Message PG Bug reporting form 2021-08-06 03:17:40 BUG #17136: set shared_preload_libraries = 'pg_stat_statements,pg_prewarm,pg_trgm' , postgresql Cannot Startup
Previous Message Bruce Salgado 2021-08-05 18:09:56 Initializing Database Cluster Failed