[MDEV-18024] Query interruption does not work as expected with sleep() in queries Created: 2018-12-17  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.1.13, 5.5, 10.0, 10.1, 10.2.19, 10.2, 10.3, 10.4
Fix Version/s: 10.4

Type: Bug Priority: Minor
Reporter: Valerii Kravchuk Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: None


 Description   

KB (https://mariadb.com/kb/en/library/aborting-statements/) says:

"MariaDB 10.1.1 introduced the max_statement_time system variable. When set to a non-zero value, any queries taking longer than this time in seconds will be aborted."

Expected result can be illustrated with the following statements (assuming there arte at least 2 rows in mysql.user table):

MariaDB [(none)]> select sleep(12),version() from mysql.user limit 1;
+-----------+-----------------+
| sleep(12) | version()       |
+-----------+-----------------+
|         0 | 10.2.19-MariaDB |
+-----------+-----------------+
1 row in set (12.00 sec)
 
MariaDB [(none)]> set statement max_statement_time = 10 for select sleep(12),version() from mysql.user limit 2;
ERROR 1969 (70100): Query execution was interrupted (max_statement_time exceeded)

But I also get the following somewhat unexpected results:

MariaDB [(none)]> set statement max_statement_time = 10 for select sleep(12),version() from dual;
+-----------+-----------------+
| sleep(12) | version()       |
+-----------+-----------------+
|         1 | 10.2.19-MariaDB |
+-----------+-----------------+
1 row in set (10.00 sec)
 
MariaDB [(none)]> set statement max_statement_time = 10 for select sleep(12),version() from mysql.user limit 1;
+-----------+-----------------+
| sleep(12) | version()       |
+-----------+-----------------+
|         1 | 10.2.19-MariaDB |
+-----------+-----------------+
1 row in set (10.00 sec)

The result of 1 for SELECT() above is expected (sleep was interrupted), but as I stated that the entire statement should not take more than 10 seconds to execute, I expect the same error as in case with LIMIT 2 above.

It seems max_statement_time error is NOT enforced in some code paths.



 Comments   
Comment by Elena Stepanova [ 2018-12-17 ]

I think the presumed inconsistency is related not to max_statement_time, but to sleep function.
max_statement_time is supposed to work the same way as KILL QUERY, and I don't think any of the examples above contradict it.
SLEEP, on the other hand, has admittedly non-obvious variations of behavior depending on certain factors:

When SLEEP() is the only thing invoked by a query that is interrupted, it returns 1 and the query itself returns no error.
...
When SLEEP() is only part of a query that is interrupted, the query returns an error.

Do you want to request change in behavior of SLEEP?

Comment by Valerii Kravchuk [ 2018-12-18 ]

Here SLEEP is a part of the query with other item in SELECT list that was interrupted:

set statement max_statement_time = 10 for select sleep(12),version() from mysql.user limit 1;

and there is no error. But with LIMIT 2:

set statement max_statement_time = 10 for select sleep(12),version() from mysql.user limit 2;

there is an error about interrupted query. Same query, but the result (documented result of SELECT(), 1 vs error) depends on number of rows selected. I think this is inconsistent. I do not want to change SLEEP() behavior, but I expect error in both cases. Query was interrupted, and SLEEP() was not the only item in SELECT list.

Comment by Elena Stepanova [ 2018-12-18 ]

I understand and I don't disagree that it appears inconsistent. My point is, it's not new and it's not related to max_statement_time, it's just how SLEEP works in regard to any interruption. If instead of max_statement_time you'll run KILL QUERY manually from another connection, you'll get the same result. So, whatever change it might require, it won't be on max_statement_time side.

The description of SLEEP is pretty vague in this regard, I won't be surprised if further analysis shows that LIMIT 1 internally falls into the "SLEEP() is the only thing invoked by a query" category (whatever it is supposed to mean), and LIMIT 2 won't. I suppose we can wait for the analysis and then discuss whether a change in behavior is desirable.

Comment by Elena Stepanova [ 2018-12-28 ]

Assigning to serg for dispatching, I suppose anyone can check the code and say "oh yes, it works as designed".

As explained above, it has nothing to do with max_statement_time.
In the essence, the question is why in the test below the first reap returns a result set, and the second reap ends with an error:

--connect (con1,localhost,root,,)
--let $con_id= `SELECT CONNECTION_ID()`
 
--send select sleep(10) from mysql.user limit 1
 
--connection default
--sleep 1
--eval kill query $con_id
  
--connection con1
--reap
--send select sleep(10) from mysql.user limit 2
 
--connection default
--sleep 1
--eval kill query $con_id
 
--connection con1
--reap

connect  con1,localhost,root,,;
select sleep(10) from mysql.user limit 1;
connection default;
kill query 6;
connection con1;
sleep(10)
1
select sleep(10) from mysql.user limit 2;
connection default;
kill query 6;
connection con1;
bug.t3                                   [ fail ]
        Test ended at 2018-12-28 18:05:01
 
CURRENT_TEST: bug.t3
mysqltest: At line 19: query 'reap' failed: 1317: Query execution was interrupted

Generated at Thu Feb 08 08:40:55 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.