DM replica causes mysql connection to die on SHOW SLAVE HOSTS

[dveeden]

What did you do?

When DM is connected running SHOW SLAVE HOSTS fails and causes the connection to fail.

What did you expect to see?

Regular output of SHOW SLAVE HOSTS as described in https://dev.mysql.com/doc/refman/5.7/en/show-slave-hosts.html

What did you see instead?

mysql-5.7.36-log [test] > SHOW PROCESSLIST;
+-----+----------+-----------------+------+-------------+-------+---------------------------------------------------------------+------------------+
| Id  | User     | Host            | db   | Command     | Time  | State                                                         | Info             |
+-----+----------+-----------------+------+-------------+-------+---------------------------------------------------------------+------------------+
|  16 | root     | localhost:47890 | NULL | Sleep       | 10397 |                                                               | NULL             |
|  17 | root     | localhost:47892 | NULL | Sleep       |   149 |                                                               | NULL             |
| 715 | root     | localhost:49378 | NULL | Binlog Dump |   227 | Master has sent all binlog to slave; waiting for more updates | NULL             |
| 724 | msandbox | localhost       | test | Query       |     0 | starting                                                      | SHOW PROCESSLIST |
+-----+----------+-----------------+------+-------------+-------+---------------------------------------------------------------+------------------+
4 rows in set (0.00 sec)

mysql-5.7.36-log [test] > SHOW SLAVE HOSTS;
ERROR 2027 (HY000): Malformed packet
mysql-5.7.36-log [test] > DO 1;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql-5.7.36-log [test] > DO 1;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    737
Current database: test

Query OK, 0 rows affected (0.00 sec)

mysql-5.7.36-log [test] >

Versions of the cluster

DM version (run dmctl -V or dm-worker -V or dm-master -V):

[dvaneeden@dve-carbon ~]$ /home/dvaneeden/dev/pingcap/dm/bin/dm-worker -V
Release Version: v2.0.0-beta.2-562-g63f57436
Git Commit Hash: 63f574362d0aa1452e43eca3feab4a9ca2d32ee2
Git Branch: master
UTC Build Time: 2021-11-11 10:46:55
Go Version: go version go1.16.8 linux/amd64

Upstream MySQL/MariaDB server version:

mysql-5.7.36-log [test] > SELECT VERSION();
+------------+
| VERSION()  |
+------------+
| 5.7.36-log |
+------------+
1 row in set (0.00 sec)

Downstream TiDB cluster version (execute SELECT tidb_version(); in a MySQL client):

tidb-5.7.25-TiDB-v5.2.1 [test] > SELECT tidb_version()\G
*************************** 1. row ***************************
tidb_version(): Release Version: v5.2.1
Edition: Community
Git Commit Hash: cd8fb24c5f7ebd9d479ed228bb41848bd5e97445
Git Branch: heads/refs/tags/v5.2.1
UTC Build Time: 2021-09-08 02:32:56
GoVersion: go1.16.4
Race Enabled: false
TiKV Min Version: v3.0.0-60965b006877ca7234adaced7890d7b029ed1306
Check Table Before Drop: false
1 row in set (0.17 sec)

How did you deploy DM: tiup or manually?

manually

current status of DM cluster (execute query-status <task-name> in dmctl)

[dvaneeden@dve-carbon dm_charset]$ tiup dmctl --master-addr=127.0.0.1:8261 query-status testmig
Starting component `dmctl`: /home/dvaneeden/.tiup/components/dmctl/v2.0.7/dmctl/dmctl --master-addr=127.0.0.1:8261 query-status testmig
{
    "result": true,
    "msg": "",
    "sources": [
        {
            "result": true,
            "msg": "",
            "sourceStatus": {
                "source": "mysql57",
                "worker": "worker1",
                "result": null,
                "relayStatus": null
            },
            "subTaskStatus": [
                {
                    "name": "testmig",
                    "stage": "Running",
                    "unit": "Sync",
                    "result": null,
                    "unresolvedDDLLockID": "",
                    "sync": {
                        "totalEvents": "231",
                        "totalTps": "0",
                        "recentTps": "0",
                        "masterBinlog": "(dve-carbon-bin.000001, 2237)",
                        "masterBinlogGtid": "",
                        "syncerBinlog": "(dve-carbon-bin.000001, 2237)",
                        "syncerBinlogGtid": "",
                        "blockingDDLs": [
                        ],
                        "unresolvedGroups": [
                        ],
                        "synced": true,
                        "binlogType": "remote",
                        "secondsBehindMaster": "0"
                    }
                }
            ]
        }
    ]
}

On the MySQL side GTID has not been enabled.

[lance6716]

related to go-mysql-org/go-mysql#618

[lance6716]

I found a contributor is fixing it go-mysql-org/go-mysql#639

with his PR, show slave status; returns empty result. Not good enough but MySQL connection will not die.

MySQL [(none)]> show processlist;
+------+------+-----------------+------+-------------+------+---------------------------------------------------------------+------------------+
| Id   | User | Host            | db   | Command     | Time | State                                                         | Info             |
+------+------+-----------------+------+-------------+------+---------------------------------------------------------------+------------------+
| 4415 | root | localhost:63887 | NULL | Binlog Dump |   20 | Master has sent all binlog to slave; waiting for more updates | NULL             |
| 4416 | root | localhost:63889 | NULL | Query       |    0 | starting                                                      | show processlist |
+------+------+-----------------+------+-------------+------+---------------------------------------------------------------+------------------+
2 rows in set (0.002 sec)

MySQL [(none)]> show slave status;
Empty set (0.000 sec)

[dveeden]

That at least is a step in the right direction. It would be great if DM would correctly show in that output, however it it is more important that it won't disturb the output of regular replicas as that might be used by tools like Orchestrator ( https://github.com/openark/orchestrator/blob/1a6c3cd6634ce72bb068de81b6af73691e0ce32c/go/inst/instance_dao.go#L666 ) and Percona Toolkit ( https://github.com/percona/percona-toolkit/blob/5a0cbd79fc644357f0b000dcadd77aa0ed514b65/lib/MasterSlave.pm#L302 ). And this might also be used in company specific tools, monitoring, etc.

[lance6716]

waiting go-mysql-org/go-mysql#655

[lance6716]

this problem is also related to mysql-client 🤔

MySQL [(none)]> show slave hosts;
+-----------+----------------------+------+-----------+------------+
| Server_id | Host                 | Port | Master_id | Slave_UUID |
+-----------+----------------------+------+-----------+------------+
|       101 | lance6716-nuc10i7fnh | 3306 |         1 |            |
+-----------+----------------------+------+-----------+------------+
1 row in set (0.001 sec)

mysql  Ver 15.1 Distrib 10.6.5-MariaDB, for Linux (x86_64) using readline 5.1

MySQL [(none)]> show slave hosts;
ERROR 2027 (HY000): Malformed packet

[root@dm-integration-test-6mtwx-j0gwd ~]# mysql --version
mysql  Ver 15.1 Distrib 5.5.68-MariaDB, for Linux (x86_64) using readline 5.1

and for both version

$ mysql -P3306 -h127.0.0.1 -uroot -p123456 --quick

MySQL [(none)]> show slave hosts;
+------------+--------------------------------------------------------------+---------+------------+--------------------------------------------------------------------------------------------------------------+
| Server_id  | Host                                                         | Port    | Master_id  | Slave_UUID                                                                                                   |
+------------+--------------------------------------------------------------+---------+------------+--------------------------------------------------------------------------------------------------------------+
+------------+--------------------------------------------------------------+---------+------------+--------------------------------------------------------------------------------------------------------------+
ERROR 2000 (00000): Unknown error
0 rows in set (0.001 sec)