MAX_STATEMENT_TIME has no effect in a procedure after an interrupted sleep

Bug #1388533 reported by Elena Stepanova on 2014-11-02
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.6
Triaged
Medium
Unassigned
5.7
Invalid
Undecided
Unassigned

Bug Description

In the procedure below, SELECT SLEEP(..) is interrupted as expected; but SELECT COUNT(*) takes clearly longer that 1 millisecond, however it is not interrupted.

#----------------------------------

MySQL [test]> create table t1 (i int) engine=InnoDB;
Query OK, 0 rows affected (1.12 sec)

MySQL [test]> insert into t1 values (1),(2),(3),(4);
Query OK, 4 rows affected (0.56 sec)
Records: 4 Duplicates: 0 Warnings: 0

MySQL [test]> insert into t1 select a.* from t1 a, t1 b, t1 c, t1 d, t1 e, t1 f, t1 g;
Query OK, 16384 rows affected (4.47 sec)
Records: 16384 Duplicates: 0 Warnings: 0

MySQL [test]>
MySQL [test]> delimiter |
MySQL [test]> create procedure pr()
    -> begin
    -> select sleep(0.5);
    -> select sql_no_cache count(*) from t1;
    -> select sql_no_cache count(*) from t1;
    -> end |
Query OK, 0 rows affected (0.00 sec)

MySQL [test]> delimiter ;
MySQL [test]>
MySQL [test]> set max_statement_time = 1;
Query OK, 0 rows affected (0.00 sec)

MySQL [test]> call pr();
+------------+
| sleep(0.5) |
+------------+
| 1 |
+------------+
1 row in set (0.00 sec)

+----------+
| count(*) |
+----------+
| 16388 |
+----------+
1 row in set (0.29 sec)

+----------+
| count(*) |
+----------+
| 16388 |
+----------+
1 row in set (0.58 sec)

Query OK, 0 rows affected (0.58 sec)

#----------------------------------

Compare with this:

#----------------------------------

MySQL [test]> delimiter |
MySQL [test]> create procedure pr2()
    -> begin
    -> select 1;
    -> select sql_no_cache count(*) from t1;
    -> select sql_no_cache count(*) from t1;
    -> end |
Query OK, 0 rows affected (0.00 sec)

MySQL [test]> delimiter ;
MySQL [test]>
MySQL [test]> set max_statement_time = 1;
Query OK, 0 rows affected (0.00 sec)

MySQL [test]> call pr2();
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)

ERROR 1885 (70101): Query execution was interrupted, max_statement_time exceeded

Elena Stepanova (elenst) on 2014-11-02
description: updated
tags: added: max-statement-time

Able to reproduce the same with 5.6.21

mysql> create table t1 (i int) engine=InnoDB;
Query OK, 0 rows affected (0.04 sec)

mysql> insert into t1 values (1),(2),(3),(4);
Query OK, 4 rows affected (0.01 sec)
Records: 4 Duplicates: 0 Warnings: 0

mysql> insert into t1 select a.* from t1 a, t1 b, t1 c, t1 d, t1 e, t1 f, t1 g;
Query OK, 16384 rows affected (0.35 sec)
Records: 16384 Duplicates: 0 Warnings: 0

mysql> delimiter |
mysql> create procedure pr()
    -> begin
    -> select sleep(0.5);
    -> select sql_no_cache count(*) from t1;
    -> select sql_no_cache count(*) from t1;
    -> end |
Query OK, 0 rows affected (0.00 sec)

mysql> delimiter ;
mysql>
mysql> set max_statement_time = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> call pr();
+------------+
| sleep(0.5) |
+------------+
| 1 |
+------------+
1 row in set (0.00 sec)

+----------+
| count(*) |
+----------+
| 16388 |
+----------+
1 row in set (0.01 sec)

+----------+
| count(*) |
+----------+
| 16388 |
+----------+
1 row in set (0.02 sec)

Query OK, 0 rows affected (0.02 sec)

mysql>
mysql>
mysql>
mysql>
mysql>
mysql> delimiter |
mysql>
mysql> create procedure pr2()
    -> begin
    -> select 1;
    -> select sql_no_cache count(*) from t1;
    -> select sql_no_cache count(*) from t1;
    -> end |
Query OK, 0 rows affected (0.00 sec)

mysql> delimiter ;
mysql>
mysql> set max_statement_time = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> call pr2();
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)

ERROR 1885 (70101): Query execution was interrupted, max_statement_time exceeded
mysql>
mysql> select @@max_statement_time ;
+----------------------+
| @@max_statement_time |
+----------------------+
| 1 |
+----------------------+
1 row in set (0.00 sec)

mysql>

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-3228

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers