Bug #68626 GRANT statements logged twice in slow query log
Submitted: 10 Mar 2013 16:11 Modified: 11 Mar 2014 21:25
Reporter: Daniël van Eeden (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:5.6.10 OS:Any
Assigned to: CPU Architecture:Any

[10 Mar 2013 16:11] Daniël van Eeden
Description:
mysql [localhost] {root} ((none)) > GRANT ALL PRIVILEGES ON *.* TO 'logtest0001'@'127.0.0.2' IDENTIFIED BY 'secure-pwd';
Query OK, 0 rows affected (0.00 sec)

mysql [localhost] {root} ((none)) > GRANT ALL PRIVILEGES ON *.* TO 'logtest0002'@'127.0.0.2' IDENTIFIED BY 'secure-pwd';
Query OK, 0 rows affected (0.01 sec)

mysql [localhost] {root} ((none)) > GRANT ALL PRIVILEGES ON *.* TO 'logtest0003'@'127.0.0.2' IDENTIFIED BY 'secure-pwd';
Query OK, 0 rows affected (0.00 sec)

mysql [localhost] {root} ((none)) > \q
Bye
$ grep 'logtest000' data/msandbox-slow.log 
GRANT ALL PRIVILEGES ON *.* TO 'logtest0001'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0002'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0003'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0003'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
$ ./my sql -u root -e "GRANT ALL PRIVILEGES ON *.* TO 'logtest0004'@'127.0.0.2' IDENTIFIED BY 'secure-pwd';"
$ ./my sql -u root -e "GRANT ALL PRIVILEGES ON *.* TO 'logtest0005'@'127.0.0.2' IDENTIFIED BY 'secure-pwd';"
$ ./my sql -u root -e "GRANT ALL PRIVILEGES ON *.* TO 'logtest0006'@'127.0.0.2' IDENTIFIED BY 'secure-pwd';"
$ grep 'logtest000' data/msandbox-slow.log 
GRANT ALL PRIVILEGES ON *.* TO 'logtest0001'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0002'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0003'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0003'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0004'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0004'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0005'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0005'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0006'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';
GRANT ALL PRIVILEGES ON *.* TO 'logtest0006'@'127.0.0.2' IDENTIFIED BY PASSWORD '*10B5F2061DEFB160B9B09182F508656CF0FFDCF9';

How to repeat:
Sometimes GRANT statements are logged twice.

This is with long_query_time=0.0
[11 Mar 2013 5:49] MySQL Verification Team
Hello Daniel, 

Thank you for the report.

Verified as described
[11 Mar 2014 21:25] Paul DuBois
Noted in 5.7.5 changelog.

Some statements could be written to the slow query log twice.