[MXS-2883] session closed by maxscale when it received "auth switch request" packet from backend server Created: 2020-02-10  Updated: 2020-02-10  Resolved: 2020-02-10

Status: Closed
Project: MariaDB MaxScale
Component/s: Authenticator
Affects Version/s: 2.4.6
Fix Version/s: 2.3.18, 2.4.7, 2.5.0

Type: Bug Priority: Major
Reporter: Judy Yu Assignee: markus makela
Resolution: Fixed Votes: 0
Labels: auth_plugin
Environment:

mysql 8.0.16
Centos 7

Attachments: File 1-client.pcap     File 1-server.pcap    

 Description   

maxscale.cnf like this:
[maxscale]
threads=auto
...
[server1]
type=server
address=10.197.0.230
port=3306
protocol=MariaDBBackend
[server2]
type=server
address=10.197.0.110
port=3307
protocol=MariaDBBackend
[server3]
type=server
address=10.197.0.33
port=3307
protocol=MariaDBBackend

[MariaDB-Monitor]
type=monitor
module=mariadbmon
servers=server1,server2,server3
user=maxscale
password=xxx
monitor_interval=10000

[Splitter-Service]
type=service
router=readwritesplit
servers=server1,server2,server3
user=maxscale
password=xxx
enable_root_user=1

[Splitter-Listener]
type=listener
service=Splitter-Service
protocol=MariaDBClient
port=4006

When use "mysql -ubackmanager -pxxx -hmaxscale-host -P4006" from one mysql slave node like server2, it is OK to enter mysql command line. But return "ERROR 1927 (08S01): Connection killed by MaxScale: Router could not recover from connection errors" when input any sql statement.
I tried to catch packet between maxscale and server, and fund maxscale get "auth switch request" packet from server, then maxscale send fin packet to server to finish this session. The packet I got is attached.

 Comments   
Comment by markus makela [ 2020-02-10 ]

Do you have the MaxScale log? Did it log any errors?

Comment by Judy Yu [ 2020-02-10 ]

The log shows:
2020-02-10 15:52:56.611 info : (1) [MariaDBAuth] (mysql_auth_set_client_data): Client 'backmanager'@[::ffff:10.197.0.110] is using an unsupported authenticator plugin 'caching_sha2_password'. Trying to switch to 'mysql_native_password'.
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (log_server_connections): Servers and router connection counts:
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (log_server_connections): current operations : 0 in [10.197.0.230]:3306 Master, Running
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (log_server_connections): current operations : 0 in [10.197.0.110]:3307 Slave, Running
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (log_server_connections): current operations : 0 in [10.197.0.33]:3307 Slave, Running
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (prepare_connection): Connected to 'server1'
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (open_connections): Selected Master: server1
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (prepare_connection): Connected to 'server2'
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (open_connections): Selected Slave: server2
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (prepare_connection): Connected to 'server3'
2020-02-10 15:52:56.612 info : (1) [readwritesplit] (open_connections): Selected Slave: server3
2020-02-10 15:52:56.612 info : (1) (session_start): Started Splitter-Service client session [1] for 'backmanager' from ::ffff:10.197.0.110
2020-02-10 15:52:56.613 info : (1) (log_transaction_status): > Autocommit: [enabled], trx is [not open], cmd: (0x03) COM_QUERY, plen: 37, type: QUERY_TYPE_READ|QUERY_TYPE_SYSVAR_READ, stmt: select @@version_comment limit 1
2020-02-10 15:52:56.613 info : (1) [readwritesplit] (handle_got_target): Route query to slave: server2 [10.197.0.110]:3307 <
2020-02-10 15:52:56.614 info : (1) (gw_decode_mysql_server_handshake): Connected to 'server2' with thread id 7249271
2020-02-10 15:52:56.614 info : (1) (gw_decode_mysql_server_handshake): Connected to 'server1' with thread id 1171978
2020-02-10 15:52:56.614 info : (1) (gw_decode_mysql_server_handshake): Connected to 'server3' with thread id 839471
2020-02-10 15:52:56.616 info : (session_free): Stopped Splitter-Service client session [1]

Comment by markus makela [ 2020-02-10 ]

What is the default auth plugin you have configured? MaxScale does not support the caching_sha2_password plugin.

Comment by Judy Yu [ 2020-02-10 ]

In mysql I set mysql_native_password to user backmanager.
But default auth plugin is caching_sha2_password.

Comment by markus makela [ 2020-02-10 ]

You should probably change the default auth plugin to mysql_native_password, I think that will fix the immediate problem. I'll investigate the AuthSwitchRequest packet not being handled correctly.

Comment by Judy Yu [ 2020-02-10 ]

I change mysql default auth plugin to mysql_native_password, and it is OK to access mysql 8.0. Thanks.
When will maxscale support caching_sha2_password?

Comment by markus makela [ 2020-02-10 ]

To my knowledge there are currently no plans to support it.

Comment by markus makela [ 2020-02-10 ]

Fixed MaxScale to correctly process the AuthSwitchRequest. This should allow MaxScale to work even with a non-default authentication plugin set as the default.

Generated at Thu Feb 08 04:17:22 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.