MySQL Bugs: #48797: Access Denied after an error on a procedure

Bug #48797	Access Denied after an error on a procedure
Submitted:	16 Nov 2009 10:52	Modified:	1 Dec 2009 15:34
Reporter:	Sergi Casbas	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: General	Severity:	S3 (Non-critical)
Version:	5.1.36 CE	OS:	Windows
Assigned to:		CPU Architecture:	Any
Tags:	access denied, PROCEDURE

Description:
After a logical error (like duplicate key or foreign key constraint fails) inside a procedure any call statment of this session throws an access denied error on every call until you close this conection.

This beahavior occurs interchangeably from odbc or mysql client.

It don't occurs if the user have a global execute privilege.

How to repeat:
- Create schema `bug`.

- Create table `test` as:
  CREATE TABLE `bug`.`test` (`id` INTEGER, PRIMARY KEY(`id`)) ;

- Create a proc (`bug`.`proc`) that fails with a body like:
  INSERT INTO `bug`.`test` (`id`) VALUES (1);

- Insert 1 reg.(calling the previous statment once).

- Create a user with only execute privileges on `bug` schema.

- Connect using the user created in the previous step.

- Execute twice the `bug`.`proc`. At first time it throws an duplicate key error (as expected), at second time it throws an acces denied error.

I can not repeat this. Look:

77-52-1-11:5.1 openxs$ bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.42-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> create table test(c1 int primary key);
Query OK, 0 rows affected (0.41 sec)

mysql> create procedure proc1() insert into test values(1);
Query OK, 0 rows affected (0.38 sec)

mysql> call proc1();
Query OK, 1 row affected (0.00 sec)

mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

What am I doing wrong?

All steps are correct but at least when you are making the call you must be connected with an user without global execute permision and with only permission on the sample schema.

Still can not repeat:

mysql> create user u1@localhost identified by 'u1';
Query OK, 0 rows affected (0.00 sec)

mysql> grant execute on test.* to u1@localhost;
Query OK, 0 rows affected (0.00 sec)

mysql> delete from test;
Query OK, 1 row affected (0.00 sec)

mysql> exit
Bye
77-52-1-11:5.1 openxs$ bin/mysql -uu1 -pu1 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 7
Server version: 5.1.42-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> call proc1();
Query OK, 1 row affected (0.00 sec)

mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

Complete Sequence:

---------------------------------------------------------------------------
Session as root (or admin)
#command-line: mysql.exe --port=3308 --user=root --password
---------------------------------------------------------------------------
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 264
Server version: 5.1.36-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> CREATE SCHEMA `bug`;
Query OK, 1 row affected (0.00 sec)

mysql> CREATE TABLE `bug`.`test` (`id` INTEGER, PRIMARY KEY(`id`)) ;
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE PROCEDURE `bug`.`proc1`() INSERT INTO `bug`.`test` VALUES(1);
Query OK, 0 rows affected (0.00 sec)

mysql> CALL `bug`.`proc1`;
Query OK, 1 row affected (0.00 sec)

mysql> CREATE USER bug_user@127.0.0.1 IDENTIFIED BY 'bug_user';
Query OK, 0 rows affected (0.00 sec)

mysql> SET PASSWORD FOR bug_user@127.0.0.1 = PASSWORD('bug_user');
Query OK, 0 rows affected (0.00 sec)

mysql> GRANT EXECUTE ON bug.* TO bug_user@127.0.0.1;
Query OK, 0 rows affected (0.02 sec)

mysql> EXIT;

---------------------------------------------------------------------------
Session as bug_user
#command-line: mysql.exe --port=3308 --user=bug_user --password=bug_user
---------------------------------------------------------------------------
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 277
Server version: 5.1.36-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

mysql> CALL `bug`.`proc1`;
ERROR 1370 (42000): execute command denied to user 'bug_user'@'127.0.0.1' for routine 'bug.proc1'

mysql> EXIT;

Pleas try latest release I couldn't repeat on current source server 5.0/5.1:

c:\dbs>c:\dbs\5.1\bin\mysql -uroot --port=3510 --prompt="mysql 5.1 >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.42-Win X64-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql 5.1 >CREATE SCHEMA `bug`;
Query OK, 1 row affected (0.00 sec)

mysql 5.1 >CREATE TABLE `bug`.`test` (`id` INTEGER, PRIMARY KEY(`id`)) ;
Query OK, 0 rows affected (0.10 sec)

mysql 5.1 >CREATE PROCEDURE `bug`.`proc1`() INSERT INTO `bug`.`test` VALUES(1);
Query OK, 0 rows affected (0.10 sec)

mysql 5.1 >CALL `bug`.`proc1`;
Query OK, 1 row affected (0.01 sec)

mysql 5.1 >CREATE USER bug_user@127.0.0.1 IDENTIFIED BY 'bug_user';
Query OK, 0 rows affected (0.01 sec)

mysql 5.1 >SET PASSWORD FOR bug_user@127.0.0.1 = PASSWORD('bug_user');
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >GRANT EXECUTE ON bug.* TO bug_user@127.0.0.1;
Query OK, 0 rows affected (0.02 sec)

mysql 5.1 >EXIT;
Bye

c:\dbs>5.1\bin\mysql --port=3510 --user=bug_user --password=bug_user
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.1.42-Win X64-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql>

I'm going to upgrade our server and i will try it again. It can take me some time. I say you something on few days.

Please re-open when you have an update regarding the upgrade. Thanks in advance.

After a lot of hours of upgrade, restoring installation, search and investigations, i found it!!!

This behaviour only occurs when:
  - The user that execute the procedure don't have global execute privileges.
  - The procedure has defined sql_mode as 'STRICT_TRANS_TABLES'.

In the next sample, you can see that i define two procedures, one without sql mode, and the other with STRIC_TRANS_TABLES. Only the second statment fails.

This is the sequence:

---------------------------------------------------------------------------
Session as root (or admin)
#command-line: mysql.exe --port=3333 --user=root --password
---------------------------------------------------------------------------
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.1.40-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE SCHEMA `bug`;
Query OK, 1 row affected (0.02 sec)

mysql> CREATE TABLE `bug`.`test` (`id` INTEGER, PRIMARY KEY(`id`)) ;
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE PROCEDURE `bug`.`proc1`() INSERT INTO `bug`.`test` VALUES(1);
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE PROCEDURE `bug`.`proc2`() INSERT INTO `bug`.`test` VALUES(1);
Query OK, 0 rows affected (0.00 sec)

mysql> UPDATE mysql.proc SET sql_mode='' WHERE db='bug' AND name='proc1';
Query OK, 0 rows affected (0.00 sec)
Rows matched: 1  Changed: 0  Warnings: 0

mysql> UPDATE mysql.proc SET sql_mode='STRICT_TRANS_TABLES' WHERE db='bug' AND name='proc2';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> CALL `bug`.`proc1`;
Query OK, 1 row affected (0.00 sec)

mysql> CREATE USER bug_user@127.0.0.1 IDENTIFIED BY 'bug_user';
Query OK, 0 rows affected (0.00 sec)

mysql> SET PASSWORD FOR bug_user@127.0.0.1 = PASSWORD('');
Query OK, 0 rows affected (0.00 sec)

mysql> GRANT EXECUTE ON bug.* TO bug_user@127.0.0.1;
Query OK, 0 rows affected (0.00 sec)

mysql> EXIT;

---------------------------------------------------------------------------
Session as bug_user
#command-line: mysql.exe --port=3333 --user=bug_user
---------------------------------------------------------------------------
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.1.40-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

mysql> CALL `bug`.`proc2`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

mysql> CALL `bug`.`proc2`;
ERROR 1370 (42000): execute command denied to user 'bug_user'@'127.0.0.1' for routine 'bug.proc2'

mysql> CALL `bug`.`proc2`;
ERROR 1370 (42000): execute command denied to user 'bug_user'@'127.0.0.1' for routine 'bug.proc2'

mysql> EXIT;

Please, check with 5.1.41. I still can NOT repeat with recent version. Look:

77-52-12-228:5.1 openxs$ bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.1.42-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> set session sql_mode='STRICT_TRANS_TABLES';
Query OK, 0 rows affected (0.00 sec)

mysql> show create procedure proc1\G
*************************** 1. row ***************************
           Procedure: proc1
            sql_mode: 
    Create Procedure: CREATE DEFINER=`root`@`localhost` PROCEDURE `proc1`()
insert into test values(1)
character_set_client: latin1
collation_connection: latin1_swedish_ci
  Database Collation: latin1_swedish_ci
1 row in set (0.37 sec)

mysql> create procedure proc2() insert into test values(2);
Query OK, 0 rows affected (0.00 sec)

mysql> grant execute on test.* to u1@'%';
Query OK, 0 rows affected (0.00 sec)

mysql> exit
Bye
77-52-12-228:5.1 openxs$ bin/mysql -uu1 -pu1 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.1.42-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc1();
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> call proc2();
Query OK, 1 row affected (0.02 sec)

mysql> call proc2();
ERROR 1062 (23000): Duplicate entry '2' for key 'PRIMARY'
mysql> call proc2();
ERROR 1062 (23000): Duplicate entry '2' for key 'PRIMARY'
mysql> call proc2();
ERROR 1062 (23000): Duplicate entry '2' for key 'PRIMARY'
mysql> call proc2();
ERROR 1062 (23000): Duplicate entry '2' for key 'PRIMARY'
mysql> exit
Bye
77-52-12-228:5.1 openxs$ bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.1.42-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select name, sql_mode from mysql.proc where db='test' and name like 'proc%';
+-------+---------------------+
| name  | sql_mode            |
+-------+---------------------+
| proc1 |                     |
| proc2 | STRICT_TRANS_TABLES |
+-------+---------------------+
2 rows in set (0.00 sec)

Table test can be MyISAM or InnoDB one, but results are the same in my case.

I test on 5.1.41-community with the empty data set and was the same. 
I' uploading a 7z file with all database files, i hope that it can help.

- Folder mysql 
- Ini config file.
- Scripts used as root and as user.
- Logs of the execution of these scripts and the server log.

Database with logs

Attachment: mysql_bug.7z (application/octet-stream, text), 116.37 KiB.

Thank you for the feedback. Now I was able to repeat with fresh install:

Microsoft Windows [Version 6.0.6002]
Copyright (c) 2006 Microsoft Corporation.  All rights reserved.

c:\dbs>51

c:\dbs>c:\dbs\5.1\bin\mysql -uroot --port=3510 --prompt="mysql 5.1 >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.1.42-Win X64-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql 5.1 >CREATE SCHEMA `bug`;
Query OK, 1 row affected (0.00 sec)

mysql 5.1 >CREATE TABLE `bug`.`test` (`id` INTEGER, PRIMARY KEY(`id`)) ;
Query OK, 0 rows affected (0.09 sec)

mysql 5.1 >CREATE PROCEDURE `bug`.`proc1`() INSERT INTO `bug`.`test` VALUES(1);
Query OK, 0 rows affected (0.01 sec)

mysql 5.1 >CREATE PROCEDURE `bug`.`proc2`() INSERT INTO `bug`.`test` VALUES(1);
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >UPDATE mysql.proc SET sql_mode='' WHERE db='bug' AND name='proc1';
Query OK, 0 rows affected (0.00 sec)
Rows matched: 1  Changed: 0  Warnings: 0

mysql 5.1 >UPDATE mysql.proc SET sql_mode='STRICT_TRANS_TABLES' WHERE db='bug' AND
    -> name='proc2';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql 5.1 >CALL `bug`.`proc1`;
Query OK, 1 row affected (0.00 sec)

mysql 5.1 >CREATE USER bug_user@127.0.0.1 IDENTIFIED BY 'bug_user';
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >SET PASSWORD FOR bug_user@127.0.0.1 = PASSWORD('');
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >GRANT EXECUTE ON bug.* TO bug_user@127.0.0.1;
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >EXIT;
Bye

c:\dbs>5.1\bin\mysql --port=3510 --user=bug_user
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.1.42-Win X64-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> CALL `bug`.`proc1`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> CALL `bug`.`proc2`;
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> CALL `bug`.`proc2`;
ERROR 1370 (42000): execute command denied to user 'bug_user'@'127.0.0.1' for routine 'bug.proc2'
mysql> CALL `bug`.`proc2`;
ERROR 1370 (42000): execute command denied to user 'bug_user'@'127.0.0.1' for routine 'bug.proc2'
mysql> exit
Bye

c:\dbs>