MySQL Bugs: #83207: mysqlsh: dba.validateInstance() gives strange errors and outputs data twice

Bug #83207	mysqlsh: dba.validateInstance() gives strange errors and outputs data twice
Submitted:	29 Sep 2016 14:36	Modified:	24 Mar 2017 13:17
Reporter:	Kenny Gryp	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Document Store: MySQL Shell	Severity:	S3 (Non-critical)
Version:	5.7.15 Preview MIC	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	mic, mysql innodb cluster

Description:

When I run ` dba.validateInstance('root@mysql3:3306')`, it seems to run properly. however:

- I get the output twice
- There is an ArgumentError with authentication somehow (but there's no problem)
- The last lines indicate that the command failed somehow

How to repeat:
my.cnf:
```
# For advice on how to change settings please see
# http://dev.mysql.com/doc/refman/5.7/en/server-configuration-defaults.html

[mysqld]
#
# Remove leading # and set to the amount of RAM for the most important data
# cache in MySQL. Start at 70% of total RAM for dedicated server, else 10%.
# innodb_buffer_pool_size = 128M
#
# Remove leading # to turn on a very important data integrity option: logging
# changes to the binary log between backups.
# log_bin
#
# Remove leading # to set options mainly useful for reporting servers.
# The server defaults are faster for transactions and fast SELECTs.
# Adjust sizes as needed, experiment to find the optimal values.
# join_buffer_size = 128M
# sort_buffer_size = 2M
# read_rnd_buffer_size = 2M
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock

# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0

log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

[mysqld]
server_id=3
enforce_gtid_consistency = on
gtid_mode = on
log_bin
log_slave_updates
```

```
[root@mysql3 ~]# mysqlsh
Welcome to MySQL Shell 1.0.5-labs Development Preview

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type '\help', '\h' or '\?' for help, type '\quit' or '\q' to exit.

Currently in JavaScript mode. Use \sql to switch to SQL mode and execute queries.
mysql-js> dba.validateInstance('root@mysql3:3306')
Please provide a password for 'root@mysql3:3306':
Validating instance...

Running check command.
Checking Group Replication prerequisites.
* Comparing options compatibility with Group Replication... FAIL
Incompatible server configuration was found.
* Checking server version... PASS
Server is 5.7.15

* Checking that server_id is unique... PASS
The server_id is valid.

* Checking compliance of existing tables... PASS

ERROR: Error executing the 'check' command: The operation could not continue due to the following requirements not being met:
Some active options on server 'mysql3@3306' are incompatible with Group Replication.
Please restart the server 'mysql3@3306' with the updated options file and try again.
Option name Required Value Current Value Result
------------------------------- --------------- --------------- -----
binlog_checksum NONE CRC32 FAIL
master_info_repository TABLE FILE FAIL
relay_log_info_repository TABLE FILE FAIL
transaction_write_set_extraction XXHASH64 OFF FAIL
ArgumentError: validateInstance: Enter the password for server (root@mysql3:3306):

* Checking that server_id is unique... PASS
The server_id is valid.

* Checking compliance of existing tables... PASS

ERROR: Error executing the 'check' command: The operation could not continue due to the following requirements not being met:
Some active options on server 'mysql3@3306' are incompatible with Group Replication.
Please restart the server 'mysql3@3306' with the updated options file and try again.
Option name Required Value Current Value Result
------------------------------- --------------- --------------- -----
binlog_checksum NONE CRC32 FAIL
master_info_repository TABLE FILE FAIL
relay_log_info_repository TABLE FILE FAIL
transaction_write_set_extraction XXHASH64 OFF FAIL
at (shell):1:4
in dba.validateInstance('root@mysql3:3306')
^
```

Suggested fix:

As soon as we get into the line that starts with `ArgumentError`, which is confusing on it's own. the same output is repeated.

And there is also some kind of stacktrace on the last 2 lines:
```
at (shell):1:4
in dba.validateInstance('root@mysql3:3306')
```

I do not expect this output twice, nor expect those errors. I only expect

```
ERROR: Error executing the 'check' command: The operation could not continue due to the following requirements not being met:
```

Hello Kenny,

Thank you for the report.
Verified as described.

Thanks,
Umesh

This seems to happen every time there is an error. This is quite confusing to read:

mysql-js> cluster.addInstance("root@mysql2:3306")
A new instance will be added to the InnoDB cluster. Depending on the amount of
data on the cluster this might take from a few seconds to several hours.

Please provide the password for 'root@mysql2:3306':
Adding instance to the cluster ...

Enter the password for server (root@mysql2:3306):
Enter the password for replication_user (mysql_innodb_cluster_rpl_user):
Enter the password for peer_server (root@mysql3:3306):

Running join command on 'mysql2@3306'.
Joining Group Replication group: "9446dd3f-8652-11e6-85dc-08002718d305"
* Comparing options compatibility with Group Replication... PASS
Server configuration is compliant with the requirements.
* Comparing options compatibility with the group of the given peer-instance... PASS
Server configuration is compliant with current group configuration.
* Checking server version... PASS
Server is 5.7.15

* Checking that server_id is unique... PASS
The server_id is valid.

The user root@'mysql2' does not exists and requires to be created.
* Checking user privileges... PASS
* Checking compliance of existing tables... PASS

* Verifying Group Replication plugin for server 'mysql2@3306' ...
Initializing group_replication plugin on 'mysql2@3306'
* Running change master command
Attempting to join to Group Replication group...
ERROR:
Group Replication join failed.
ERROR: Group Replication plugin failed to start. Server error log contains the following errors:
2016-09-30T10:48:00.239813Z 0 [ERROR] Plugin group_replication reported: 'This member has more executed transactions than those present in the group. Local transactions: 50c0c583-862a-11e6-9515-08002718d305:1-34947,
2016-09-30T10:48:00.239858Z 0 [ERROR] Plugin group_replication reported: 'The member contains transactions not present in the group. The member will now exit the group.'
2016-09-30T10:48:00.239880Z 0 [ERROR] Plugin group_replication reported: 'Message received while the plugin is not ready, message discarded'
2016-09-30T10:48:00.239887Z 0 [ERROR] Plugin group_replication reported: 'Message received while the plugin is not ready, message discarded'

ERROR: Error executing the 'join-replicaset' command: 'mysql2@3306' - Query failed. 3092 (HY000): The server is not configured properly to be an active member of the group. Please see more details on error log.. Query: START group_replication
ArgumentError: Cluster.addInstance: ERROR:
ERROR: Group Replication plugin failed to start. Server error log contains the following errors:
2016-09-30T10:48:00.239813Z 0 [ERROR] Plugin group_replication reported: 'This member has more executed transactions than those present in the group. Local transactions: 50c0c583-862a-11e6-9515-08002718d305:1-34947,
2016-09-30T10:48:00.239858Z 0 [ERROR] Plugin group_replication reported: 'The member contains transactions not present in the group. The member will now exit the group.'
2016-09-30T10:48:00.239880Z 0 [ERROR] Plugin group_replication reported: 'Message received while the plugin is not ready, message discarded'
2016-09-30T10:48:00.239887Z 0 [ERROR] Plugin group_replication reported: 'Message received while the plugin is not ready, message discarded'
'mysql2@3306' - Query failed. 3092 (HY000): The server is not configured properly to be an active member of the group. Please see more details on error log.. Query: START group_replication
at (shell):1:8
in cluster.addInstance("root@mysql2:3306")
^

( the error itself is fine. I'm playing with it :) )

Posted by developer:
 
*FIXED*
MySQL Shell 1.0.8-rc

**validateInstance() changes**
dba.validateInstance() renamed to dba.checkInstanceConfig()

Right now for a MySQL server without the required options in the my.ini, you will get the error info

mysql-js> dba.checkInstanceConfiguration('root:msandbox@localhost:5717')
Validating instance...

The instance 'localhost:5717' is not valid for Cluster usage.

The following issues were encountered:

 - 3 table(s) do not have a Primary Key
 - Some configuration options need to be fixed.

+----------------------------------+---------------+----------------+--------------------------------------------------+
| Variable                         | Current Value | Required Value | Note                                             |
+----------------------------------+---------------+----------------+--------------------------------------------------+
| binlog_checksum                  | CRC32         | NONE           | Update the server variable or restart the server |
| enforce_gtid_consistency         | OFF           | ON             | Restart the server                               |
| gtid_mode                        | OFF           | ON             | Restart the server                               |
| log_bin                          | 0             | 1              | Restart the server                               |
| log_slave_updates                | 0             | ON             | Restart the server                               |
| master_info_repository           | FILE          | TABLE          | Restart the server                               |
| relay_log_info_repository        | FILE          | TABLE          | Restart the server                               |
| transaction_write_set_extraction | OFF           | XXHASH64       | Restart the server                               |
+----------------------------------+---------------+----------------+--------------------------------------------------+

Please fix these issues , restart the server and try again.

{
    "config_errors": [
        {
            "action": "server_update", 
            "current": "CRC32", 
            "option": "binlog_checksum", 
            "required": "NONE"
        },
        {
            "action": "restart", 
            "current": "OFF", 
            "option": "enforce_gtid_consistency", 
            "required": "ON"
        },
        {
            "action": "restart", 
            "current": "OFF", 
            "option": "gtid_mode", 
            "required": "ON"
        },
        {
            "action": "restart", 
            "current": "0", 
            "option": "log_bin", 
            "required": "1"
        },
        {
            "action": "restart", 
            "current": "0", 
            "option": "log_slave_updates", 
            "required": "ON"
        },
        {
            "action": "restart", 
            "current": "FILE", 
            "option": "master_info_repository", 
            "required": "TABLE"
        },
        {
            "action": "restart", 
            "current": "FILE", 
            "option": "relay_log_info_repository", 
            "required": "TABLE"
        },
        {
            "action": "restart", 
            "current": "OFF", 
            "option": "transaction_write_set_extraction", 
            "required": "XXHASH64"
        }
    ], 
    "errors": [
        "3 table(s) do not have a Primary Key"
    ], 
    "restart_required": true, 
    "status": "error"
}

Posted by developer:
 
Fixed for first AdminAPI release with 1.0.8. No changelog entry required.