Bug #64776 Stored procedures are not ACID compliant
Submitted: 27 Mar 2012 11:12 Modified: 31 Mar 2012 10:56
Reporter: Patrick Mulvany (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Stored Routines Severity:S3 (Non-critical)
Version:5.5.21 OS:Any
Assigned to: CPU Architecture:Any

[27 Mar 2012 11:12] Patrick Mulvany
Description:
When using any engine (e.g.InnoDB) nested stored procedures have an implicit savepoint on entry to an inner stored procedure. If the stored procedure errors the rollback occures to the implicit savepoint rather than the whole transaction.

In some ways MySQL stored procedures are behaving like Oracle does when using :-
  pragma autonomous_transaction;

This is would be very useful feature in itself i.e. for logging errors etc. but you should be able to get the same result by using a non transactional engine for the log tables.

Discovered when investigating another possibly related bug :-
NOW() returns inconsitent times when used with nested stored procedures
http://bugs.mysql.com/bug.php?id=64761

How to repeat:
CREATE TABLE t1 (id INT NOT NULL AUTO_INCREMENT, level VARCHAR(50),dt_sysdate
DATETIME,dt_outer DATETIME,
  PRIMARY KEY (id));

DELIMITER $$

CREATE PROCEDURE inner1 (p_date DATETIME)
  BEGIN
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('inner1', sysdate(),p_date);
  END
;

$$

CREATE PROCEDURE inner2 (p_date DATETIME)
  BEGIN
 	  INSERT INTO t1 (id,level,dt_sysdate,dt_outer) VALUES (-1, 'inner2', sysdate(),p_date);
  END
;

$$

CREATE PROCEDURE outer1 ()
  BEGIN
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-1', sysdate(),NOW());
    CALL inner2(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-2', sysdate(),NOW());
    CALL inner1(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-3', sysdate(),NOW());
    CALL inner2(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-4', sysdate(),NOW());
    END
;
    
$$

DELIMITER ;

mysql> call outer1();
ERROR 1062 (23000): Duplicate entry '-1' for key 'PRIMARY'
mysql>
mysql> SELECT * FROM t1;
+----+----------+---------------------+---------------------+
| id | level    | dt_sysdate          | dt_outer            |
+----+----------+---------------------+---------------------+
| -1 | inner2   | 2012-03-27 12:01:49 | 2012-03-27 12:01:49 |
|  1 | outer1-1 | 2012-03-27 12:01:49 | 2012-03-27 12:01:49 |
|  2 | outer1-2 | 2012-03-27 12:01:49 | 2012-03-27 12:01:49 |
|  3 | inner1   | 2012-03-27 12:01:49 | 2012-03-27 12:01:49 |
|  4 | outer1-3 | 2012-03-27 12:01:49 | 2012-03-27 12:01:49 |
+----+----------+---------------------+---------------------+
5 rows in set (0.00 sec)

mysql> rollback;
Query OK, 0 rows affected (0.05 sec)

mysql> SELECT * FROM t1;
Empty set (0.00 sec)

mysql> call outer1();
ERROR 1062 (23000): Duplicate entry '-1' for key 'PRIMARY'
mysql> SELECT * FROM t1;
+----+----------+---------------------+---------------------+
| id | level    | dt_sysdate          | dt_outer            |
+----+----------+---------------------+---------------------+
| -1 | inner2   | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  5 | outer1-1 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  6 | outer1-2 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  7 | inner1   | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  8 | outer1-3 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
+----+----------+---------------------+---------------------+
5 rows in set (0.00 sec)

mysql> commit;
Query OK, 0 rows affected (0.04 sec)

mysql> SELECT * FROM t1;
+----+----------+---------------------+---------------------+
| id | level    | dt_sysdate          | dt_outer            |
+----+----------+---------------------+---------------------+
| -1 | inner2   | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  5 | outer1-1 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  6 | outer1-2 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  7 | inner1   | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  8 | outer1-3 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
+----+----------+---------------------+---------------------+
5 rows in set (0.00 sec)

mysql> call outer1();
ERROR 1062 (23000): Duplicate entry '-1' for key 'PRIMARY'
mysql> SELECT * FROM t1;
+----+----------+---------------------+---------------------+
| id | level    | dt_sysdate          | dt_outer            |
+----+----------+---------------------+---------------------+
| -1 | inner2   | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  5 | outer1-1 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  6 | outer1-2 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  7 | inner1   | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  8 | outer1-3 | 2012-03-27 12:03:15 | 2012-03-27 12:03:15 |
|  9 | outer1-1 | 2012-03-27 12:03:40 | 2012-03-27 12:03:40 |
+----+----------+---------------------+---------------------+
6 rows in set (0.00 sec)
[27 Mar 2012 12:22] Patrick Mulvany
A dirty work arround is to do an explicit rollback and resignal within an exit handler. Note this appears to work on 5.5.21 but is not covered by the docs.

CREATE PROCEDURE outer1 ()
  BEGIN
    DECLARE EXIT HANDLER FOR SQLEXCEPTION 
		BEGIN
			ROLLBACK;
			RESIGNAL;
		END; 
    INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-1', sysdate(),NOW());
    CALL inner2(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-2', sysdate(),NOW());
    CALL inner1(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-3', sysdate(),NOW());
    CALL inner2(NOW());
 	INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer1-4', sysdate(),NOW());
    END
;
[27 Mar 2012 22:25] Patrick Mulvany
Probably S3 not S2 but might mean issue with entire Stored Procedure stack
[28 Mar 2012 5:47] Valeriy Kravchuk
I had repeated your results (with autcommit=0), but unfortunately I fail to understand what exactly is a bug here. You had committed the results inserted successfully before the duplicate key -1. Then you call procedure again, it inserts one row and again fails at call to inner2() that tries to insert duplicate key -1. In case of error user gets error message and can decide if it is OK to commit or entire transaction should be rolled back. So, what is the problem?
[28 Mar 2012 8:26] Patrick Mulvany
Altered Synopsis from: 'nested stored procedures are asynchronously committed' to 'Stored procedures are not ACID compliant'

Further investigation indicates the general case is simply that stored procedures on an ACID compliant engine and not ACID.

Further examples following
[28 Mar 2012 8:28] Patrick Mulvany
Example script of ACID and non ACID actions

Attachment: example-sp.sql (application/octet-stream, text), 1.99 KiB.

[28 Mar 2012 8:29] Patrick Mulvany
Example output of script of ACID and non ACID actions

Attachment: example.log (application/octet-stream, text), 7.42 KiB.

[28 Mar 2012 8:32] Patrick Mulvany
Should have had at start of sql script

mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)

darn copy and paste
[28 Mar 2012 9:17] Patrick Mulvany
The following is a better work around to produce an ACID compliant stored procedure that rolls back updates and resignals.

DELIMITER $$

CREATE PROCEDURE outer2 ()
  BEGIN
    DECLARE EXIT HANDLER FOR SQLEXCEPTION 
		BEGIN
			ROLLBACK TO SAVEPOINT savepoint_outer2;
			RESIGNAL;
		END; 
	SAVEPOINT savepoint_outer2;
		
    INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer2-1', sysdate(),NOW());
    CALL inner2(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer2-2', sysdate(),NOW());
    CALL inner1(NOW());
 	  INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer2-3', sysdate(),NOW());
    CALL inner2(NOW());
 	INSERT INTO t1 (level,dt_sysdate,dt_outer) VALUES ('outer2-4', sysdate(),NOW());
    END
;

$$

DELIMITER ;
[31 Mar 2012 10:56] Sveta Smirnova
Thank you for the feedback.

Actually this behavior is documented at http://dev.mysql.com/doc/refman/5.5/en/begin-end.html: "The optional [NOT] ATOMIC clause is not supported. This means that no transactional savepoint is set at the start of the instruction block and the BEGIN clause used in this context has no effect on the current transaction."

So this is not a bug.

But your request is valid, so I change it to feature request: add support for [NOT] ATOMIC clause for stored procedures.