Adding several debug information

pull/2209/head
René Cannaò 7 years ago
parent 6e67c21224
commit 9971dc5b47

@ -1511,7 +1511,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
db = (*myds)->myconn->userinfo->schemaname;
(*myds)->switching_auth_stage=2;
charset=(*myds)->tmp_charset;
proxy_debug(PROXY_DEBUG_MYSQL_PROTOCOL,2,"Encrypted: %d , switching_auth: %d, auth_plugin_id: %d\n", (*myds)->encrypted, (*myds)->switching_auth_stage, auth_plugin_id);
proxy_debug(PROXY_DEBUG_MYSQL_PROTOCOL,2,"Session=%p , DS=%p . Encrypted: %d , switching_auth: %d, auth_plugin_id: %d\n", (*myds)->sess, (*myds), (*myds)->encrypted, (*myds)->switching_auth_stage, auth_plugin_id);
goto __do_auth;
}
@ -1526,6 +1526,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
(*myds)->encrypted = true;
use_ssl = true;
ret = false;
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' . goto __exit_process_pkt_handshake_response\n", (*myds), (*myds)->sess, user);
goto __exit_process_pkt_handshake_response;
}
}
@ -1549,12 +1550,14 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
pkt += pass_len_enc;
if (pass_len > (len - (pkt - _ptr))) {
ret = false;
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' . goto __exit_process_pkt_handshake_response\n", (*myds), (*myds)->sess, user);
goto __exit_process_pkt_handshake_response;
}
} else {
pass_len = (capabilities & CLIENT_SECURE_CONNECTION ? *pkt++ : strlen((char *)pkt));
if (pass_len > (len - (pkt - _ptr))) {
ret = false;
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' . goto __exit_process_pkt_handshake_response\n", (*myds), (*myds)->sess, user);
goto __exit_process_pkt_handshake_response;
}
}
@ -1591,6 +1594,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
auth_plugin_id = 1;
}
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' , auth_plugin_id=%d\n", (*myds), (*myds)->sess, user, auth_plugin_id);
if (auth_plugin_id == 0) {
if (strncmp((char *)auth_plugin,(char *)"mysql_native_password",strlen((char *)"mysql_native_password"))==0) {
auth_plugin_id = 1;
@ -1602,6 +1606,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
}
}
//__switch_auth_plugin:
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' , auth_plugin_id=%d\n", (*myds), (*myds)->sess, user, auth_plugin_id);
if (auth_plugin_id == 0) {
if ((*myds)->switching_auth_stage == 0) {
(*myds)->switching_auth_stage = 1;
@ -1616,6 +1621,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
} else {
#endif /* PROXYSQLCLICKHOUSE */
user_exists = GloMyAuth->exists((char *)user);
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user_exists=%d , user='%s'\n", (*myds), (*myds)->sess, user_exists, user);
//password=GloMyAuth->lookup((char *)user, USERNAME_FRONTEND, &_ret_use_ssl, &default_hostgroup, &default_schema, &schema_locked, &transaction_persistent, &fast_forward, &max_connections, &sha1_pass);
#ifdef PROXYSQLCLICKHOUSE
}
@ -1626,6 +1632,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
} else {
(*myds)->switching_auth_type = 2; // mysql_clear_password
}
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user_exists=%d , user='%s' , setting switching_auth_type=%d\n", (*myds), (*myds)->sess, user_exists, user, (*myds)->switching_auth_type);
generate_pkt_auth_switch_request(true, NULL, NULL);
(*myds)->myconn->userinfo->set((char *)user, NULL, db, NULL);
ret = false;
@ -1654,6 +1661,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
generate_pkt_auth_switch_request(true, NULL, NULL);
(*myds)->myconn->userinfo->set((char *)user, NULL, db, NULL);
ret = false;
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' . goto __exit_process_pkt_handshake_response. User does not exist\n", (*myds), (*myds)->sess, user);
goto __exit_process_pkt_handshake_response;
}
}
@ -1662,6 +1670,7 @@ bool MySQL_Protocol::process_pkt_handshake_response(unsigned char *pkt, unsigned
}
if (auth_plugin_id == 0) { // unknown plugin
ret = false;
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' . goto __exit_process_pkt_handshake_response . Unknown auth plugin\n", (*myds), (*myds)->sess, user);
goto __exit_process_pkt_handshake_response;
}
//char reply[SHA_DIGEST_LENGTH+1];
@ -1681,6 +1690,7 @@ __do_auth:
const MARIADB_CHARSET_INFO * c = proxysql_find_charset_nr(charset);
if (!c) {
proxy_error("Client %s:%d is trying to use unknown charset %d. Disconnecting\n", (*myds)->addr.addr, (*myds)->addr.port, charset);
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , user='%s' . Client %s:%d is trying to use unknown charset %d. Disconnecting\n", (*myds), (*myds)->sess, user, (*myds)->addr.addr, (*myds)->addr.port, charset);
ret = false;
goto __exit_do_auth;
}
@ -1694,6 +1704,15 @@ __do_auth:
}
//assert(default_hostgroup>=0);
if (password) {
#ifdef DEBUG
char *tmp_pass=strdup(password);
int lpass = strlen(tmp_pass);
for (int i=2; i<lpass-1; i++) {
tmp_pass[i]='*';
}
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , username='%s' , password='%s'\n", (*myds), (*myds)->sess, user, tmp_pass);
free(tmp_pass);
#endif // debug
(*myds)->sess->default_hostgroup=default_hostgroup;
(*myds)->sess->default_schema=default_schema; // just the pointer is passed
(*myds)->sess->schema_locked=schema_locked;
@ -1736,6 +1755,15 @@ __do_auth:
(*myds)->sess->ldap_ctx = GloMyLdapAuth->ldap_ctx_init();
password = GloMyLdapAuth->lookup((*myds)->sess->ldap_ctx, (char *)user, (char *)pass, USERNAME_FRONTEND, &_ret_use_ssl, &default_hostgroup, &default_schema, &schema_locked, &transaction_persistent, &fast_forward, &max_connections, &sha1_pass, &backend_username);
if (password) {
#ifdef DEBUG
char *tmp_pass=strdup(password);
int lpass = strlen(tmp_pass);
for (int i=2; i<lpass-1; i++) {
tmp_pass[i]='*';
}
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , username='%s' , password='%s'\n", (*myds), (*myds)->sess, backend_username, tmp_pass);
free(tmp_pass);
#endif // debug
(*myds)->sess->default_hostgroup=default_hostgroup;
(*myds)->sess->default_schema=default_schema; // just the pointer is passed
(*myds)->sess->schema_locked=schema_locked;
@ -1777,7 +1805,17 @@ __do_auth:
} else {
if (pass_len==0 && strlen(password)==0) {
ret=true;
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , username='%s' , password=''\n", (*myds), (*myds)->sess, user);
} else {
#ifdef DEBUG
char *tmp_pass=strdup(password);
int lpass = strlen(tmp_pass);
for (int i=2; i<lpass-1; i++) {
tmp_pass[i]='*';
}
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , username='%s' , password='%s' , auth_plugin_id=%d\n", (*myds), (*myds)->sess, user, tmp_pass, auth_plugin_id);
free(tmp_pass);
#endif // debug
if (password[0]!='*') { // clear text password
if (auth_plugin_id == 1) { // mysql_native_password
proxy_scramble(reply, (*myds)->myconn->scramble_buff, password);
@ -1813,6 +1851,7 @@ __do_auth:
uint8 hash_stage2[SHA_DIGEST_LENGTH];
unhex_pass(hash_stage2,sha1_2);
*/
proxy_debug(PROXY_DEBUG_MYSQL_AUTH, 5, "Session=%p , DS=%p , username='%s' , session_type=%d\n", (*myds), (*myds)->sess, user, session_type);
uint8 hash_stage1[SHA_DIGEST_LENGTH];
uint8 hash_stage2[SHA_DIGEST_LENGTH];
SHA_CTX sha1_context;

@ -4112,13 +4112,13 @@ void MySQL_Session::handler___status_CHANGING_USER_CLIENT___STATE_CLIENT_HANDSHA
client_myds->myprot.process_pkt_auth_swich_response((unsigned char *)pkt->ptr,pkt->size)==true
) {
l_free(pkt->size,pkt->ptr);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . Successful connection\n", this, client_myds);
client_myds->myprot.generate_pkt_OK(true,NULL,NULL,2,0,0,0,0,NULL);
GloMyLogger->log_audit_entry(PROXYSQL_MYSQL_CHANGE_USER_OK, this, NULL);
status=WAITING_CLIENT_DATA;
client_myds->DSS=STATE_SLEEP;
} else {
l_free(pkt->size,pkt->ptr);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Wrong credentials for frontend: disconnecting\n");
*wrong_pass=true;
// FIXME: this should become close connection
client_myds->setDSS_STATE_QUERY_SENT_NET();
@ -4153,6 +4153,19 @@ void MySQL_Session::handler___status_CHANGING_USER_CLIENT___STATE_CLIENT_HANDSHA
sprintf(_s,"ProxySQL Error: Access denied for user '%s'@'%s' (using password: %s)", client_myds->myconn->userinfo->username, client_addr, (client_myds->myconn->userinfo->password ? "YES" : "NO"));
proxy_error("ProxySQL Error: Access denied for user '%s'@'%s' (using password: %s)", client_myds->myconn->userinfo->username, client_addr, (client_myds->myconn->userinfo->password ? "YES" : "NO"));
client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,2,1045,(char *)"28000", _s, true);
#ifdef DEBUG
if (client_myds->myconn->userinfo->password) {
char *tmp_pass=strdup(client_myds->myconn->userinfo->password);
int lpass = strlen(tmp_pass);
for (int i=2; i<lpass-1; i++) {
tmp_pass[i]='*';
}
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . Wrong credentials for frontend: %s:%s . Password=%s . Disconnecting\n", this, client_myds, client_myds->myconn->userinfo->username, client_addr, tmp_pass);
free(tmp_pass);
} else {
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . Wrong credentials for frontend: %s:%s . No password. Disconnecting\n", this, client_myds, client_myds->myconn->userinfo->username, client_addr);
}
#endif //DEBUG
GloMyLogger->log_audit_entry(PROXYSQL_MYSQL_CHANGE_USER_ERR, this, NULL);
free(_s);
__sync_fetch_and_add(&MyHGM->status.access_denied_wrong_password, 1);
@ -4163,9 +4176,11 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
bool is_encrypted = client_myds->encrypted;
bool handshake_response_return = client_myds->myprot.process_pkt_handshake_response((unsigned char *)pkt->ptr,pkt->size);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p , handshake_response=%d , switching_auth_stage=%d , is_encrypted=%d , client_encrypted=%d\n", this, client_myds, handshake_response_return, client_myds->switching_auth_stage, is_encrypted, client_myds->encrypted);
if (
(handshake_response_return == false) && (client_myds->switching_auth_stage == 1)
) {
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p . Returning\n", this, client_myds);
return;
}
@ -4175,6 +4190,7 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
(client_myds->encrypted == true) // client is asking for encryption
) {
// use SSL
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p . SSL_INIT\n", this, client_myds);
client_myds->DSS=STATE_SSL_INIT;
client_myds->rbio_ssl = BIO_new(BIO_s_mem());
client_myds->wbio_ssl = BIO_new(BIO_s_mem());
@ -4275,6 +4291,7 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
break;
#endif // TEST_AURORA || TEST_GALERA
case PROXYSQL_SESSION_MYSQL:
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p , session_type=PROXYSQL_SESSION_MYSQL\n", this, client_myds);
if (ldap_ctx==NULL) {
free_users=GloMyAuth->increase_frontend_user_connections(client_myds->myconn->userinfo->username, &used_users);
} else {
@ -4294,20 +4311,21 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
free_users=1;
}
if (max_connections_reached==true || free_users<=0) {
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p , max_connections_reached=%d , free_users=%d\n", this, client_myds, max_connections_reached, free_users);
client_authenticated=false;
*wrong_pass=true;
client_myds->setDSS_STATE_QUERY_SENT_NET();
uint8_t _pid = 2;
if (client_myds->switching_auth_stage) _pid+=2;
if (max_connections_reached==true) {
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Too many connections\n");
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p , Too many connections\n", this, client_myds);
client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,_pid,1040,(char *)"08004", (char *)"Too many connections", true);
proxy_warning("mysql-max_connections reached. Returning 'Too many connections'\n");
GloMyLogger->log_audit_entry(PROXYSQL_MYSQL_AUTH_ERR, this, NULL, (char *)"mysql-max_connections reached");
__sync_fetch_and_add(&MyHGM->status.access_denied_max_connections, 1);
} else { // see issue #794
__sync_fetch_and_add(&MyHGM->status.access_denied_max_user_connections, 1);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "User '%s' has exceeded the 'max_user_connections' resource (current value: %d)\n", client_myds->myconn->userinfo->username, used_users);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . User '%s' has exceeded the 'max_user_connections' resource (current value: %d)\n", this, client_myds, client_myds->myconn->userinfo->username, used_users);
char *a=(char *)"User '%s' has exceeded the 'max_user_connections' resource (current value: %d)";
char *b=(char *)malloc(strlen(a)+strlen(client_myds->myconn->userinfo->username)+16);
GloMyLogger->log_audit_entry(PROXYSQL_MYSQL_AUTH_ERR, this, NULL, b);
@ -4398,12 +4416,14 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
sprintf(_s, _a, client_myds->myconn->userinfo->username, (client_myds->myconn->userinfo->password ? "YES" : "NO"));
client_myds->myprot.generate_pkt_ERR(true,NULL,NULL, _pid, 1045,(char *)"28000", _s, true);
proxy_error("ProxySQL Error: Access denied for user '%s' (using password: %s). SSL is required", client_myds->myconn->userinfo->username, (client_myds->myconn->userinfo->password ? "YES" : "NO"));
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p . Access denied for user '%s' (using password: %s). SSL is required\n", this, client_myds, client_myds->myconn->userinfo->username, (client_myds->myconn->userinfo->password ? "YES" : "NO"));
__sync_add_and_fetch(&MyHGM->status.client_connections_aborted,1);
free(_s);
__sync_fetch_and_add(&MyHGM->status.access_denied_wrong_password, 1);
} else {
// we are good!
//client_myds->myprot.generate_pkt_OK(true,NULL,NULL, (is_encrypted ? 3 : 2), 0,0,0,0,NULL);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION,8,"Session=%p , DS=%p . STATE_CLIENT_AUTH_OK\n", this, client_myds);
GloMyLogger->log_audit_entry(PROXYSQL_MYSQL_AUTH_OK, this, NULL);
client_myds->myprot.generate_pkt_OK(true,NULL,NULL, _pid, 0,0,0,0,NULL);
status=WAITING_CLIENT_DATA;
@ -4426,7 +4446,7 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
// }
} else {
l_free(pkt->size,pkt->ptr);
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Wrong credentials for frontend: disconnecting\n");
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . Wrong credentials for frontend: disconnecting\n", this, client_myds);
*wrong_pass=true;
// FIXME: this should become close connection
client_myds->setDSS_STATE_QUERY_SENT_NET();
@ -4462,6 +4482,19 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(
uint8_t _pid = 2;
if (client_myds->switching_auth_stage) _pid+=2;
if (is_encrypted) _pid++;
#ifdef DEBUG
if (client_myds->myconn->userinfo->password) {
char *tmp_pass=strdup(client_myds->myconn->userinfo->password);
int lpass = strlen(tmp_pass);
for (int i=2; i<lpass-1; i++) {
tmp_pass[i]='*';
}
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . Error: Access denied for user '%s'@'%s' , Password='%s'. Disconnecting\n", this, client_myds, client_myds->myconn->userinfo->username, client_addr, tmp_pass);
free(tmp_pass);
} else {
proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session=%p , DS=%p . Error: Access denied for user '%s'@'%s' . No password. Disconnecting\n", this, client_myds, client_myds->myconn->userinfo->username, client_addr);
}
#endif // DEBUG
sprintf(_s,"ProxySQL Error: Access denied for user '%s'@'%s' (using password: %s)", client_myds->myconn->userinfo->username, client_addr, (client_myds->myconn->userinfo->password ? "YES" : "NO"));
client_myds->myprot.generate_pkt_ERR(true,NULL,NULL, _pid, 1045,(char *)"28000", _s, true);
proxy_error("ProxySQL Error: Access denied for user '%s'@'%s' (using password: %s)\n", client_myds->myconn->userinfo->username, client_addr, (client_myds->myconn->userinfo->password ? "YES" : "NO"));

Loading…
Cancel
Save