Bug #70060 "Access denied using password no" for slave w/ password, can't connect 2 slaves
Submitted: 16 Aug 2013 15:09 Modified: 23 Apr 2018 4:56
Reporter: Nicholas Williams Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Errors Severity:S2 (Serious)
Version:5.6 OS:Any
Assigned to: CPU Architecture:Any
Tags: multiple slaves access denied uuid virtual machine clone

[16 Aug 2013 15:09] Nicholas Williams
Description:
This bug exists in both the documentation and in error codes and messages.

Scenario/Symptoms:
I've been using replication for about 8 years now on MySQL 5.1. I have two slaves:

- "ipAddress1" with server ID 97
- "ipAddress2" with server ID 98

I recently decided to upgrade to MySQL 5.6. I took the opportunity to just completely rebuild my slave machines. First I built one machine ("ipAddress1") I needed with the correct software installed and replication configured. I make sure replication was working, then shut down MySQL.

I then /cloned/ that machine (that's the key) to "ipAddress2" to keep from having to rebuild and reinstall the software all over again. I changed the server ID, started the server up, and replication was working fine.

However, at this exact moment "ipAddress1" stopped replicating. So I stopped and started the slave on "ipAddress1" and at that exact moment "ipAddress2" stopped replicating. I spent the better part of four hours trying to figure out what the heck was going on. The server error log was NOT helpful: It was full of messages like this (duplicates removed):

2013-08-16 08:12:41 7461 [Warning] Access denied for user 'nwtsdns'@'ipAddress2' (using password: NO)
2013-08-16 08:16:09 7461 [Note] Start binlog_dump to master_thread_id(32004) slave_server(98), pos(lynyrd-bin.000026, 4)
2013-08-16 09:36:09 7461 [Warning] Access denied for user 'nwtsdns'@'ipAddress1' (using password: NO)
2013-08-16 09:36:53 7461 [Note] Start binlog_dump to master_thread_id(33392) slave_server(97), pos(lynyrd-bin.000027, 506086)
2013-08-16 09:36:54 7461 [Warning] Access denied for user 'nwtsdns'@'ipAddress2' (using password: NO)
2013-08-16 09:37:23 7461 [Note] Start binlog_dump to master_thread_id(33401) slave_server(98), pos(lynyrd-bin.000027, 520106)
2013-08-16 09:37:23 7461 [Warning] Access denied for user 'nwtsdns'@'ipAddress1' (using password: NO)

How could it be failing with "using password: no?" I very definitely configured the MASTER_PASSWORD in CHANGE MASTER TO. And obviously it worked for a while and then quit. It was like for some reason the master refused to allow more than one slave to be connected at a time.

What I didn't know about at the time was the addition of server UUIDs in 5.6. Before UUIDs, my cloning process would have worked. Replication wasn't ACTUALLY failing due to "using password: no." It was failing because of duplicate UUIDs. Once I figured that out, all I had to do was `rm /var/lib/mysql/auto.cnf` on one of the slaves and restart both slaves. Replication started working fine on both machines at that point.

The Problems:
- The documentation says nothing about duplicate UUIDs causing replication to fail.
- The error messages say nothing about duplicate UUIDs. Instead, they make you think there's something wrong with the slave password configuration.

How to repeat:
1. Create a virtual machine acting as a slave.
2. Clone the virtual machine and change the server ID.
3. Start slave on both machines--only one will be allowed to be connected at a time.

Suggested fix:
The fix is very simple:

1) Change the documentation at https://dev.mysql.com/doc/refman/5.6/en/replication-options.html. In the section talking about UUIDs, mention the problems inherent in cloning machines. A simple sentence like "if you clone a slave virtual machine, make sure you delete the auto.cnf file on the clone before restarting MySQL so that a new UUID is generated."

2) Change the error message. I could have figured it out in two seconds by Googling "mysql 5.6 UUID" and finding the right documentation. The problem was that I didn't /know/ to search for that because I thought the password was the problem. The error message should be changed to say that access was denied because of a duplicate slave UUID.
[16 Aug 2013 15:21] Nicholas Williams
Something else I forgot to mention. The error logs on the slaves were different, but still not helpful:

2013-08-16 00:23:38 2661 [Note] Slave I/O thread: connected to master 'nwtsdns@masterIpAddress:3307',replication started in log 'lynyrd-bin.000027' at position 410730
2013-08-16 00:36:51 3377 [Warning] Access denied for user 'UNKNOWN_MYSQL_USER'@'localhost' (using password: NO)
2013-08-16 00:36:51 3377 [Note] Slave I/O thread: connected to master 'nwtsdns@masterIpAddress:3307',replication started in log 'FIRST' at position 4
2013-08-16 00:48:38 3377 [ERROR] Slave I/O: error reconnecting to master 'nwtsdns@masterIpAddress:3307' - retry-time: 60  retries: 1, Error_code: 1045
2013-08-16 00:49:38 3377 [ERROR] Slave I/O: error reconnecting to master 'nwtsdns@masterIpAddress:3307' - retry-time: 60  retries: 2, Error_code: 1045

It would be fantastic if this log, too, could also mention the UUID duplication problem.
[23 Mar 2018 4:56] MySQL Verification Team
Hello Nicholas,

Thank you for the report and feedback.
Please accept my sincere apologies for missing out this report.
This is most likely duplicate of Bug #72578(Related one Bug #84358), per change log entry this is already fixed.
Posted by developer:
 
The following was added to the 5.6.21 and 5.7.5 change logs with commit 3981: The error messages generated when a duplicate server UUID causes issues during replication have been improved. The slave error now identifies the duplicate server UUID and the master error identifies the zombie thread that has been killed.

I quickly tried to reproduce but not sot seeing any issues on my test box.
Could you please confirm with latest build(5.6/5.7) if you are still seeing this issue at your end?  If you are still seeing this then please report us back with unaltered error log from master/slave, configuration from both master and slaves?

Regards,
Umesh
[24 Apr 2018 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".