Description:
We cannot connect with MySQL CLI client (mysql) to server with LDAP/SASL authentication.
Getting nonsense error mesage:
ERROR 2000 (HY000): Unknown MySQL error
O/S side everything seems to work.
How to repeat:
* Kerberos on O/S level (OK):
shell> vastool klist
klist: No ccache exists with name: FILE:/tmp/krb5cc_8800
shell> vastool kinit App1_DEV_Read_User1@BASE.INT
Password for app1_dev_read_user1@BASE.INT:
shell> vastool klist
Credentials cache: FILE:/tmp/krb5cc_8800
Principal: app1_dev_read_user1@BASE.INT
Issued Expires Principal
Jan 7 10:07:23 Jan 7 20:07:23 krbtgt/BASE.INT@BASE.INT
shell> /usr/bin/ldapsearch -h base.int -Y GSSAPI -b "OU=Test,DC=base,DC=int" > /dev/null
SASL/GSSAPI authentication started
SASL username: app1_dev_write_user1@BASE.INT
SASL SSF: 256
SASL data security layer installed.
* Linux syslog messages (OK):
Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 1
Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 1
Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 1
Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 2
Jan 7 10:15:08 mtzhldgiam05 ldapsearch: DIGEST-MD5 common mech free
* Supported Mechanisms of the AD/LDAP:
supportedSASLMechanisms: GSSAPI
supportedSASLMechanisms: GSS-SPNEGO
supportedSASLMechanisms: EXTERNAL
supportedSASLMechanisms: DIGEST-MD5
----
* Kerberos/SASL authentication with mysql CLI
shell> mysql --version
mysql Ver 8.0.22-commercial for Linux on x86_64 (MySQL Enterprise Server - Commercial)
shell> mysql -h mtzhldgiam05 --plugin-dir=/u00/app/mysql/product/latest/lib/plugin/ --default-auth=authentication_ldap_sasl_client
ERROR 2000 (HY000): Unknown MySQL error
shell> vastool klist
Credentials cache: FILE:/tmp/krb5cc_8800
Principal: app1_dev_read_user1@BASE.INT
Issued Expires Principal
Jan 7 10:07:23 Jan 7 20:07:23 krbtgt/BASE.INT@BASE.INT
shell> mysql -h mtzhldgiam05 --default-auth=authentication_ldap_sasl_client --plugin-dir=/u00/app/mysql/product/latest/lib/plugin/ --user=App1_DEV_Write_User1@BASE.INT --password
Enter password:
ERROR 2000 (HY000): Unknown MySQL error
Somehow it looks like the basic authentication works (switch from read to write user):
shell> vastool klist
Credentials cache: FILE:/tmp/krb5cc_8800
Principal: App1_DEV_Write_User1@BASE.INT
Issued Expires Principal
Jan 7 10:12:02 Jan 7 20:12:02 krbtgt/BASE.INT@BASE.INT
* Linux syslog messages (from mysql CLI on client side):
Jan 7 10:02:48 mtzhldgiam01 mysql: Attempt to disable security layers (maxoutbuf == 0) with min_ssf > 0
Jan 7 10:02:48 mtzhldgiam01 mysql: No worthy mechs found
* Strace of this part:
29554 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 4
29554 connect(4, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110) = 0
29554 sendto(4, "<37>Jan 7 10:19:53 mysql: Attem"..., 95, MSG_NOSIGNAL, NULL, 0) = 95
29554 sendto(4, "<37>Jan 7 10:19:53 mysql: No wo"..., 48, MSG_NOSIGNAL, NULL, 0) = 48
29554 shutdown(3, SHUT_RDWR) = 0 -> 3 = MySQL Server
29554 close(3) = 0
* MySQL Server Error Log
2021-01-07T09:13:22.009827Z 83936 [Note] [MY-011754] [Server] Plugin authentication_ldap_sasl reported: 'Setting LDAP user name as : App1_DEV_Write_User1@BASE.INT'
2021-01-07T09:13:22.010054Z 83936 [Note] [MY-011795] [Server] Plugin authentication_ldap_sasl reported: 'LDAP authentication started for user name: App1_DEV_Write_User1@BASE.INT'
2021-01-07T09:13:22.010172Z 83936 [Note] [MY-011791] [Server] Plugin authentication_ldap_sasl reported: 'Sending authentication method to client : GSSAPI'
2021-01-07T09:13:22.010317Z 83936 [Note] [MY-013342] [Server] Plugin authentication_ldap_sasl reported: 'Get user proxy: configured mapping info: App2_QA_Admin=App2_QA_Admin,App2_QA_Write=App2_QA_Write,App2_QA_Read=App2_QA_Read,MySQLTestGroup-Read=App2_QA_Read'
2021-01-07T09:13:22.010433Z 83936 [Note] [MY-011755] [Server] Plugin authentication_ldap_sasl reported: 'User authentication data: +OU=Test,DC=base,DC=int# App2_QA_Admin=App2_QA_Admin,App2_QA_Write=App2_QA_Write,App2_QA_Read=App2_QA_Read,MySQLTestGroup-Read=App2_QA_Read size: 140'
2021-01-07T09:13:22.010541Z 83936 [Note] [MY-011778] [Server] Plugin authentication_ldap_sasl reported: 'Ldap_authentication::initialize: getting connection from pool. '
2021-01-07T09:13:22.010646Z 83936 [Note] [MY-011252] [Server] Plugin authentication_ldap_sasl reported: 'Checking if re-initialization of connection pool is required.'
2021-01-07T09:13:22.010777Z 83936 [Note] [MY-011788] [Server] Plugin authentication_ldap_sasl reported: ' Ldap_connection_pool::get pooled connection key: 16099270622384178'
2021-01-07T09:13:22.010897Z 83936 [Note] [MY-011252] [Server] Plugin authentication_ldap_sasl reported: 'Processing LDAP SASL step.'
2021-01-07T09:13:22.036349Z 83936 [ERROR] [MY-011776] [Server] Plugin authentication_ldap_sasl reported: 'Plug-in has failed to read the packet from client'
ldap_err2string
2021-01-07T09:13:22.036430Z 83936 [ERROR] [MY-011798] [Server] Plugin authentication_ldap_sasl reported: 'LDAP authentication failed or group retrieval failed: LDAP error: Operations error'
2021-01-07T09:13:22.036446Z 83936 [Note] [MY-011783] [Server] Plugin authentication_ldap_sasl reported: 'Ldap_connection_pool::put connection in pushed in the pool'
2021-01-07T09:13:22.036467Z 83936 [Note] [MY-011779] [Server] Plugin authentication_ldap_sasl reported: 'Ldap_authentication::de_initialize putting back connection in the pool'
2021-01-07T09:13:22.036496Z 83936 [Note] [MY-010914] [Server] Got an error reading communication packets
Suggested fix:
Make authentication work.
Description: We cannot connect with MySQL CLI client (mysql) to server with LDAP/SASL authentication. Getting nonsense error mesage: ERROR 2000 (HY000): Unknown MySQL error O/S side everything seems to work. How to repeat: * Kerberos on O/S level (OK): shell> vastool klist klist: No ccache exists with name: FILE:/tmp/krb5cc_8800 shell> vastool kinit App1_DEV_Read_User1@BASE.INT Password for app1_dev_read_user1@BASE.INT: shell> vastool klist Credentials cache: FILE:/tmp/krb5cc_8800 Principal: app1_dev_read_user1@BASE.INT Issued Expires Principal Jan 7 10:07:23 Jan 7 20:07:23 krbtgt/BASE.INT@BASE.INT shell> /usr/bin/ldapsearch -h base.int -Y GSSAPI -b "OU=Test,DC=base,DC=int" > /dev/null SASL/GSSAPI authentication started SASL username: app1_dev_write_user1@BASE.INT SASL SSF: 256 SASL data security layer installed. * Linux syslog messages (OK): Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 1 Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 1 Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 1 Jan 7 10:15:08 mtzhldgiam05 ldapsearch: GSSAPI client step 2 Jan 7 10:15:08 mtzhldgiam05 ldapsearch: DIGEST-MD5 common mech free * Supported Mechanisms of the AD/LDAP: supportedSASLMechanisms: GSSAPI supportedSASLMechanisms: GSS-SPNEGO supportedSASLMechanisms: EXTERNAL supportedSASLMechanisms: DIGEST-MD5 ---- * Kerberos/SASL authentication with mysql CLI shell> mysql --version mysql Ver 8.0.22-commercial for Linux on x86_64 (MySQL Enterprise Server - Commercial) shell> mysql -h mtzhldgiam05 --plugin-dir=/u00/app/mysql/product/latest/lib/plugin/ --default-auth=authentication_ldap_sasl_client ERROR 2000 (HY000): Unknown MySQL error shell> vastool klist Credentials cache: FILE:/tmp/krb5cc_8800 Principal: app1_dev_read_user1@BASE.INT Issued Expires Principal Jan 7 10:07:23 Jan 7 20:07:23 krbtgt/BASE.INT@BASE.INT shell> mysql -h mtzhldgiam05 --default-auth=authentication_ldap_sasl_client --plugin-dir=/u00/app/mysql/product/latest/lib/plugin/ --user=App1_DEV_Write_User1@BASE.INT --password Enter password: ERROR 2000 (HY000): Unknown MySQL error Somehow it looks like the basic authentication works (switch from read to write user): shell> vastool klist Credentials cache: FILE:/tmp/krb5cc_8800 Principal: App1_DEV_Write_User1@BASE.INT Issued Expires Principal Jan 7 10:12:02 Jan 7 20:12:02 krbtgt/BASE.INT@BASE.INT * Linux syslog messages (from mysql CLI on client side): Jan 7 10:02:48 mtzhldgiam01 mysql: Attempt to disable security layers (maxoutbuf == 0) with min_ssf > 0 Jan 7 10:02:48 mtzhldgiam01 mysql: No worthy mechs found * Strace of this part: 29554 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 4 29554 connect(4, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110) = 0 29554 sendto(4, "<37>Jan 7 10:19:53 mysql: Attem"..., 95, MSG_NOSIGNAL, NULL, 0) = 95 29554 sendto(4, "<37>Jan 7 10:19:53 mysql: No wo"..., 48, MSG_NOSIGNAL, NULL, 0) = 48 29554 shutdown(3, SHUT_RDWR) = 0 -> 3 = MySQL Server 29554 close(3) = 0 * MySQL Server Error Log 2021-01-07T09:13:22.009827Z 83936 [Note] [MY-011754] [Server] Plugin authentication_ldap_sasl reported: 'Setting LDAP user name as : App1_DEV_Write_User1@BASE.INT' 2021-01-07T09:13:22.010054Z 83936 [Note] [MY-011795] [Server] Plugin authentication_ldap_sasl reported: 'LDAP authentication started for user name: App1_DEV_Write_User1@BASE.INT' 2021-01-07T09:13:22.010172Z 83936 [Note] [MY-011791] [Server] Plugin authentication_ldap_sasl reported: 'Sending authentication method to client : GSSAPI' 2021-01-07T09:13:22.010317Z 83936 [Note] [MY-013342] [Server] Plugin authentication_ldap_sasl reported: 'Get user proxy: configured mapping info: App2_QA_Admin=App2_QA_Admin,App2_QA_Write=App2_QA_Write,App2_QA_Read=App2_QA_Read,MySQLTestGroup-Read=App2_QA_Read' 2021-01-07T09:13:22.010433Z 83936 [Note] [MY-011755] [Server] Plugin authentication_ldap_sasl reported: 'User authentication data: +OU=Test,DC=base,DC=int# App2_QA_Admin=App2_QA_Admin,App2_QA_Write=App2_QA_Write,App2_QA_Read=App2_QA_Read,MySQLTestGroup-Read=App2_QA_Read size: 140' 2021-01-07T09:13:22.010541Z 83936 [Note] [MY-011778] [Server] Plugin authentication_ldap_sasl reported: 'Ldap_authentication::initialize: getting connection from pool. ' 2021-01-07T09:13:22.010646Z 83936 [Note] [MY-011252] [Server] Plugin authentication_ldap_sasl reported: 'Checking if re-initialization of connection pool is required.' 2021-01-07T09:13:22.010777Z 83936 [Note] [MY-011788] [Server] Plugin authentication_ldap_sasl reported: ' Ldap_connection_pool::get pooled connection key: 16099270622384178' 2021-01-07T09:13:22.010897Z 83936 [Note] [MY-011252] [Server] Plugin authentication_ldap_sasl reported: 'Processing LDAP SASL step.' 2021-01-07T09:13:22.036349Z 83936 [ERROR] [MY-011776] [Server] Plugin authentication_ldap_sasl reported: 'Plug-in has failed to read the packet from client' ldap_err2string 2021-01-07T09:13:22.036430Z 83936 [ERROR] [MY-011798] [Server] Plugin authentication_ldap_sasl reported: 'LDAP authentication failed or group retrieval failed: LDAP error: Operations error' 2021-01-07T09:13:22.036446Z 83936 [Note] [MY-011783] [Server] Plugin authentication_ldap_sasl reported: 'Ldap_connection_pool::put connection in pushed in the pool' 2021-01-07T09:13:22.036467Z 83936 [Note] [MY-011779] [Server] Plugin authentication_ldap_sasl reported: 'Ldap_authentication::de_initialize putting back connection in the pool' 2021-01-07T09:13:22.036496Z 83936 [Note] [MY-010914] [Server] Got an error reading communication packets Suggested fix: Make authentication work.