sysown / proxysql

High-performance MySQL proxy with a GPL license.
http://www.proxysql.com
GNU General Public License v3.0
6.04k stars 983 forks source link

[ERROR] RECEIVED AN UNKNOWN COMMAND: 18 -- PLEASE REPORT A BUG #3098

Open houndegnonm opened 4 years ago

houndegnonm commented 4 years ago

We started using AWS DMS to perform a one-time data load and then ongoing replication between MySQL and Redshift. we use proxySQL version 2.0.7 and started noticing below intermittent Error in proxySQL log each time the DMS process starts running causing the DMS job to fail at the end.

2020-10-07 14:17:55 MySQL_Session.cpp:3607:handler(): [ERROR] RECEIVED AN UNKNOWN COMMAND: 18 -- PLEASE REPORT A BUG
2020-10-07 14:18:01 MySQL_Session.cpp:5308:handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo(): [WARNING] Unable to parse multi-statements command with SET statement: setting lock hostgroup . Command: set SESSION net_write_timeout=1800;
2020-10-07 14:18:01 MySQL_Session.cpp:3607:handler(): [ERROR] RECEIVED AN UNKNOWN COMMAND: 18 -- PLEASE REPORT A BUG
2020-10-07 14:18:06 MySQL_Session.cpp:5308:handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo(): [WARNING] Unable to parse multi-statements command with SET statement: setting lock hostgroup . Command: set SESSION net_write_timeout=1800;

I also enabled MySQL general Query log to gather any SQL statements coming from DMS that may not be compatible with proxySQL

2020-10-07T14:26:15.783585-05:00        203319 Connect  dms@172.30.177.107 on  using SSL/TLS
2020-10-07T14:26:15.804134-05:00        203319 Query    SET time_zone='+00:00'
2020-10-07T14:26:15.824636-05:00        203319 Query    SET NAMES utf8
2020-10-07T14:26:15.847431-05:00        203319 Query    SET character_set_results = NULL
2020-10-07T14:26:15.871753-05:00        203319 Query    SET SQL_AUTO_IS_NULL = 0
2020-10-07T14:26:15.896351-05:00        203319 Query    select database()
2020-10-07T14:17:06.307288-05:00        203223 Query    set SESSION net_write_timeout=1800
2020-10-07T14:17:06.328670-05:00        203223 Query    set SESSION net_read_timeout=1800
2020-10-07T14:26:15.916885-05:00        203319 Query    SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED
2020-10-07T14:26:15.937507-05:00        203319 Query    set @@max_execution_time=60000
2020-10-07T14:26:15.958008-05:00        203319 Query    set @@sql_select_limit=DEFAULT
2020-10-07T14:26:15.978410-05:00        203319 Query    set SESSION net_write_timeout=1800
2020-10-07T14:26:15.998907-05:00        203319 Query    set @@max_execution_time=60000
2020-10-07T14:26:16.019661-05:00        203319 Query    set SESSION net_read_timeout=1800

Thank you!

renecannao commented 4 years ago

18 = COM_BINLOG_DUMP . AWS DMS is trying to be a replication slave while connecting to ProxySQL . ProxySQL doesn't support replication commands yet, therefore it won't work this way. On the other hand, you can configure mysql_users.fast_forward=1 for the user that is used by AWS DMS , assuming you are using a dedicated user for it.

joao-teixeira-cvt commented 3 years ago

Hi @renecannao, I'm facing the same issue as well and changing fast_forward to 1 for the user used by DMS does not solve the issue. In fact by doing that even a full load doesn't work. Any ideas? Thanks

ernstae commented 2 years ago

This feels oddly similar to an issue I'm tracking right now.

We're using MySQL 8.0.28 group replication, with ProxySQL configured for

hostgroup 0: [primary mysql host, rw] hostgroup 2: [read replicas, ro]

We have a debezium client hitting ProxySQL in one of our deployments, and when it connects (with fast_forward=1 for that user), we're seeing ProxySQL move all the back-end mysql hosts into hostgroup 3, and knocking the primary out of hostgroup 0 (resulting in downtime).

I'm still trying to gather the details and make a bug report, but I've reverted the cluster back to proxysql 2.3.2 and back to 2.4.2, and both versions are affected by the same issue.

This is revealed in the logs, and there is no recovery until proxysql service is restarted.

2022-08-09 01:49:33 MySQL_Session.cpp:3758:handler_ProcessingQueryError_CheckBackendConnectionStatus(): [ERROR] Detected an offline server during query: 10.x.x.x, 3306
2022-08-09 01:49:33 MySQL_Session.cpp:3758:handler_ProcessingQueryError_CheckBackendConnectionStatus(): [ERROR] Detected an offline server during query: 10.x.x.x, 3306
2022-08-09 01:49:33 MySQL_Session.cpp:3758:handler_ProcessingQueryError_CheckBackendConnectionStatus(): [ERROR] Detected an offline server during query: 10.x.x.x 3306
2022-08-09 01:49:33 MySQL_Session.cpp:3758:handler_ProcessingQueryError_CheckBackendConnectionStatus(): [ERROR] Detected an offline server during query: 10.x.x.x 3306
2022-08-09 01:49:33 MySQL_Session.cpp:3768:handler_ProcessingQueryError_CheckBackendConnectionStatus(): [WARNING] Retrying query.

This just continues spewing in the logs, despite the hosts being connectable (for all three hosts)

2022-08-09 23:28:23 MySQL_Session.cpp:2594:handler_again___status_CONNECTING_SERVER(): [ERROR] Max connect timeout reached while reaching hostgroup 0 after 30000ms . HG status: [{"Bytes_recv":"52390382511","Bytes_sent":"6200149862","ConnERR":
"0","ConnFree":"0","ConnOK":"21247","ConnUsed":"0","Latency_us":"450","MaxConnUsed":"258","Queries":"23759993","Queries_GTID_sync":"0","hostgroup":"0","srv_host":"10.x.x.x","srv_port":"3306","status":"OFFLINE_HARD"},{"Bytes_recv":"0","Bytes_
sent":"0","ConnERR":"0","ConnFree":"0","ConnOK":"0","ConnUsed":"0","Latency_us":"383","MaxConnUsed":"0","Queries":"0","Queries_GTID_sync":"0","hostgroup":"0","srv_host":"10.x.x.y","srv_port":"3306","status":"OFFLINE_HARD"}]
renecannao commented 2 years ago

Hi @ernstae . Full error log may help, possibly there is more useful information there. Thanks