Bug #93395 ALTER USER succeeds on master but fails on slave.
Submitted: 29 Nov 2018 6:50 Modified: 30 Jul 7:34
Reporter: Jean-François Gagné Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.7.24 OS:Any
Assigned to: CPU Architecture:Any

[29 Nov 2018 6:50] Jean-François Gagné
Description:
Hi,

I have an ALTER USER statement that succeeds on the master but fails on slaves.  This is unexpected: if it succeeds on the master, it should succeed on the slave.  And if this ALTER USER is invalid (which it is according to the error message on slaves), it should fail on the master.  See "How to repeat" for details.

Note: I classified this as S2 because replication breakage is serious.  For the anecdote, I ran this statement by mistake on a master with 20 slaves, and fixing replication on 20 slaves it not fun...

Many thanks for looking into that,

JFG

How to repeat:
-- With below on the master...

master [localhost] {msandbox} ((none)) > select version();
+------------+
| version()  |
+------------+
| 5.7.24-log |
+------------+
1 row in set (0.00 sec)

master [localhost] {msandbox} ((none)) > select password('test_jfg');
+-------------------------------------------+
| password('test_jfg')                      |
+-------------------------------------------+
| *A6421A80AB3C4730E175C200E56176BF66309673 |
+-------------------------------------------+
1 row in set, 1 warning (0.00 sec)

master [localhost] {msandbox} ((none)) > CREATE USER IF NOT EXISTS 'test_jfg'@'localhost';
Query OK, 0 rows affected (0.01 sec)

master [localhost] {msandbox} ((none)) > ALTER USER 'test_jfg'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*' REQUIRE NONE PASSWORD EXPIRE DEFAULT ACCOUNT UNLOCK;
Query OK, 0 rows affected (0.00 sec)

-- Oups, I forgot to paste the password hash in the statement above, let's fix it.

master [localhost] {msandbox} ((none)) > ALTER USER 'test_jfg'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*A6421A80AB3C4730E175C200E56176BF66309673' REQUIRE NONE PASSW
Query OK, 0 rows affected (0.00 sec)

-- But the ALTER with a bad password hash broke slaves.

slave1 [localhost] {msandbox} ((none)) > show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 127.0.0.1
                  Master_User: rsandbox
                  Master_Port: 19125
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 4873
               Relay_Log_File: mysql-relay.000002
                Relay_Log_Pos: 4526
        Relay_Master_Log_File: mysql-bin.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 1827
                   Last_Error: Error 'The password hash doesn't have the expected format. Check if the correct password algorithm is being used with the PASSWORD() function.' on query. Default database: ''. Query: 'ALTER USER 'test_jfg'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*' REQUIRE NONE PASSWORD EXPIRE DEFAULT ACCOUNT UNLOCK'
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 4313
              Relay_Log_Space: 5289
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File:
           Master_SSL_CA_Path:
              Master_SSL_Cert:
            Master_SSL_Cipher:
               Master_SSL_Key:
        Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error:
               Last_SQL_Errno: 1827
               Last_SQL_Error: Error 'The password hash doesn't have the expected format. Check if the correct password algorithm is being used with the PASSWORD() function.' on query. Default database: ''. Query: 'ALTER USER 'test_jfg'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*' REQUIRE NONE PASSWORD EXPIRE DEFAULT ACCOUNT UNLOCK'
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 100
                  Master_UUID: 00019125-1111-1111-1111-111111111111
             Master_Info_File: /home/jgagne/sandboxes/rsandbox_mysql_5_7_24/node1/data/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State:
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp: 181129 06:35:41
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set:
            Executed_Gtid_Set:
                Auto_Position: 0
         Replicate_Rewrite_DB:
                 Channel_Name:
           Master_TLS_Version:
1 row in set (0.00 sec)

Suggested fix:
Fail this statement on the master, or accept it on the slave.
[29 Nov 2018 12:40] Umesh Shastry
Hello Jean-François,

Thank you for the report and test case.
Verified as described.

regards,
Umesh
[29 Nov 2018 12:46] Umesh Shastry
test results

Attachment: 93395_5.7.24.results (application/octet-stream, text), 8.90 KiB.

[23 Jul 7:10] Jean-François Gagné
I have not tested, but this looked fixed in 5.7.27.

From https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-27.html

I can read:

CREATE USER and ALTER USER did not check the validity of a hashed authentication string when used with IDENTIFIED WITH auth_plugin AS 'hash_string' syntax. (Bug #29395944)

This is the 2nd attribution omission I am finding in 5.7.27 release notes (the other one was on Bug#95484).  Is this a new policy not to update public bugs with fixed version and not to mention the public bugs in the release notes ?
[29 Jul 6:35] Erlend Dahl
Duplicate of 

Bug#94440 some function problem while create an user

There is no change in the bug handling process.
[29 Jul 7:39] Jean-François Gagné
Erlend, how can this be a duplicate of a bug created more than 2 months after this one ?

This bug number is 93395, the "duplicate of" is #94440, shouldn't Bug#94440 be marked as a duplicate of this one ?

I understand that some "better report" that are done later can trigger an older bug to be marked as duplicate, but what is wrong in my report ?  Steps to reproduce were there, and Umesh was able to replicate and verify the bug.

I think this deserves a better explanation, thanks in advance for it.
[29 Jul 12:18] Sinisa Milivojevic
Jean-Francois,

The explanation is simple. The other bug was fixed before this one, because it turned out that category is wrong.
[30 Jul 7:34] Jean-François Gagné
The reason I was given for this bug being flagged as a duplicate of a newer bug is the following ([1]):

> Simply because the work was done on the newer bug, presumably because the dev wasn't aware of the older one. Hence the more recent bug was recorded in changelogs etc. Given that, it makes more sense to record 93395 as a duplicate of the newer bug.

[1]: https://mysqlcommunity.slack.com/archives/C8R1336M7/p1564386444100200?thread_ts=1563865915...