hcq/MaxScale
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Clean up MySQL protocol debug logging

Browse Source 
Removed pthread_self calls from the backend modules. This makes the debug
logging easier to parse when the messages aren't prefixed with the verbose
thread ID.
This commit is contained in:
Markus Mäkelä
2017-04-05 11:14:39 +03:00
parent cf2272f479
commit a88e98035f
3 changed files with 36 additions and 98 deletions
Download Patch File Download Diff File Expand all files Collapse all files

65
server/modules/protocol/MySQL/MySQLBackend/mysql_backend.c
View File

@ -179,9 +179,6 @@ static int gw_create_backend_connection(DCB *backend_dcb,
if (protocol == NULL) if (protocol == NULL)
{ {
MXS_DEBUG("%lu [gw_create_backend_connection] Failed to create "
"protocol object for backend connection.",
pthread_self());
MXS_ERROR("Failed to create protocol object for backend connection."); MXS_ERROR("Failed to create protocol object for backend connection.");
goto return_fd; goto return_fd;
} }
@ -213,10 +210,9 @@ static int gw_create_backend_connection(DCB *backend_dcb,
ss_dassert(fd > 0); ss_dassert(fd > 0);
protocol->fd = fd; protocol->fd = fd;
protocol->protocol_auth_state = MXS_AUTH_STATE_CONNECTED; protocol->protocol_auth_state = MXS_AUTH_STATE_CONNECTED;
MXS_DEBUG("%lu [gw_create_backend_connection] Established " MXS_DEBUG("Established "
"connection to %s:%i, protocol fd %d client " "connection to %s:%i, protocol fd %d client "
"fd %d.", "fd %d.",
pthread_self(),
server->name, server->name,
server->port, server->port,
protocol->fd, protocol->fd,
@ -230,9 +226,8 @@ static int gw_create_backend_connection(DCB *backend_dcb,
ss_dassert(fd > 0); ss_dassert(fd > 0);
protocol->protocol_auth_state = MXS_AUTH_STATE_PENDING_CONNECT; protocol->protocol_auth_state = MXS_AUTH_STATE_PENDING_CONNECT;
protocol->fd = fd; protocol->fd = fd;
MXS_DEBUG("%lu [gw_create_backend_connection] Connection " MXS_DEBUG("Connection "
"pending to %s:%i, protocol fd %d client fd %d.", "pending to %s:%i, protocol fd %d client fd %d.",
pthread_self(),
server->name, server->name,
server->port, server->port,
protocol->fd, protocol->fd,
@ -243,13 +238,6 @@ static int gw_create_backend_connection(DCB *backend_dcb,
/* Failure - the state reverts to its initial value */ /* Failure - the state reverts to its initial value */
ss_dassert(fd == -1); ss_dassert(fd == -1);
ss_dassert(protocol->protocol_auth_state == MXS_AUTH_STATE_INIT); ss_dassert(protocol->protocol_auth_state == MXS_AUTH_STATE_INIT);
MXS_DEBUG("%lu [gw_create_backend_connection] Connection "
"failed to %s:%i, protocol fd %d client fd %d.",
pthread_self(),
server->name,
server->port,
protocol->fd,
session->client_dcb->fd);
break; break;
} /*< switch */ } /*< switch */
@ -303,8 +291,7 @@ static int gw_do_connect_to_backend(char *host, int port, int *fd)
} }
*fd = so; *fd = so;
MXS_DEBUG("%lu [gw_do_connect_to_backend] Connected to backend server " MXS_DEBUG("Connected to backend server [%s]:%d, fd %d.", host, port, so);
"[%s]:%d, fd %d.", pthread_self(), host, port, so);
return rv; return rv;
@ -444,9 +431,8 @@ gw_read_backend_event(DCB *dcb)
MySQLProtocol *proto = (MySQLProtocol *)dcb->protocol; MySQLProtocol *proto = (MySQLProtocol *)dcb->protocol;
CHK_PROTOCOL(proto); CHK_PROTOCOL(proto);
MXS_DEBUG("%lu [gw_read_backend_event] Read dcb %p fd %d protocol state %d, %s.", MXS_DEBUG("Read dcb %p fd %d protocol state %d, %s.", dcb, dcb->fd,
pthread_self(), dcb, dcb->fd, proto->protocol_auth_state, proto->protocol_auth_state, STRPROTOCOLSTATE(proto->protocol_auth_state));
STRPROTOCOLSTATE(proto->protocol_auth_state));
int rc = 0; int rc = 0;
if (proto->protocol_auth_state == MXS_AUTH_STATE_COMPLETE) if (proto->protocol_auth_state == MXS_AUTH_STATE_COMPLETE)
@ -772,10 +758,8 @@ gw_read_and_write(DCB *dcb)
if (!stmt) if (!stmt)
{ {
MXS_ERROR("%lu [gw_read_backend_event] " MXS_ERROR("Read buffer unexpectedly null, even though response "
"Read buffer unexpectedly null, even though response " "not marked as complete. User: %s", dcb->session->client_dcb->user);
"not marked as complete. User: %s",
pthread_self(), dcb->session->client_dcb->user);
return 0; return 0;
} }
} }
@ -844,9 +828,8 @@ static int gw_write_backend_event(DCB *dcb)
} }
else else
{ {
MXS_DEBUG("%lu [gw_write_backend_event] Dcb %p in state %s " MXS_DEBUG("Dcb %p in state %s but there's nothing to write either.",
"but there's nothing to write either.", dcb, STRDCBSTATE(dcb->state));
pthread_self(), dcb, STRDCBSTATE(dcb->state));
} }
} }
else else
@ -862,8 +845,7 @@ static int gw_write_backend_event(DCB *dcb)
dcb_drain_writeq(dcb); dcb_drain_writeq(dcb);
} }
MXS_DEBUG("%lu [gw_write_backend_event] wrote to dcb %p fd %d, return %d", MXS_DEBUG("wrote to dcb %p fd %d, return %d", dcb, dcb->fd, rc);
pthread_self(), dcb, dcb->fd, rc);
} }
return rc; return rc;
@ -959,12 +941,8 @@ static int gw_MySQLWrite_backend(DCB *dcb, GWBUF *queue)
backend_protocol->current_command = client_proto->current_command; backend_protocol->current_command = client_proto->current_command;
} }
MXS_DEBUG("%lu [gw_MySQLWrite_backend] write to dcb %p " MXS_DEBUG("write to dcb %p fd %d protocol state %s.",
"fd %d protocol state %s.", dcb, dcb->fd, STRPROTOCOLSTATE(backend_protocol->protocol_auth_state));
pthread_self(),
dcb,
dcb->fd,
STRPROTOCOLSTATE(backend_protocol->protocol_auth_state));
/** /**
@ -1007,12 +985,8 @@ static int gw_MySQLWrite_backend(DCB *dcb, GWBUF *queue)
default: default:
{ {
MXS_DEBUG("%lu [gw_MySQLWrite_backend] delayed write to " MXS_DEBUG("delayed write to dcb %p fd %d protocol state %s.",
"dcb %p fd %d protocol state %s.", dcb, dcb->fd, STRPROTOCOLSTATE(backend_protocol->protocol_auth_state));
pthread_self(),
dcb,
dcb->fd,
STRPROTOCOLSTATE(backend_protocol->protocol_auth_state));
/** /**
* In case of session commands, store command to DCB's * In case of session commands, store command to DCB's
* protocol struct. * protocol struct.
@ -1463,11 +1437,7 @@ static GWBUF* process_response_data(DCB* dcb,
srvcmd = protocol_get_srv_command(p, false); srvcmd = protocol_get_srv_command(p, false);
MXS_DEBUG("%lu [process_response_data] Read command %s for DCB %p fd %d.", MXS_DEBUG("Read command %s for DCB %p fd %d.", STRPACKETTYPE(srvcmd), dcb, dcb->fd);
pthread_self(),
STRPACKETTYPE(srvcmd),
dcb,
dcb->fd);
/** /**
* Read values from protocol structure, fails if values are * Read values from protocol structure, fails if values are
* uninitialized. * uninitialized.
@ -1565,9 +1535,8 @@ static GWBUF* process_response_data(DCB* dcb,
wait for more data from the backend server.*/ wait for more data from the backend server.*/
if (*readbuf == NULL || gwbuf_length(*readbuf) < 3) if (*readbuf == NULL || gwbuf_length(*readbuf) < 3)
{ {
MXS_DEBUG("%lu [%s] Read %d packets. Waiting for %d more " MXS_DEBUG("[%s] Read %d packets. Waiting for %d more "
"packets for a total of %d packets.", "packets for a total of %d packets.", __FUNCTION__,
pthread_self(), __FUNCTION__,
initial_packets - npackets_left, initial_packets - npackets_left,
npackets_left, initial_packets); npackets_left, initial_packets);

52
server/modules/protocol/MySQL/MySQLClient/mysql_client.c
View File

@ -447,11 +447,7 @@ int gw_read_client_event(DCB* dcb)
protocol = (MySQLProtocol *)dcb->protocol; protocol = (MySQLProtocol *)dcb->protocol;
CHK_PROTOCOL(protocol); CHK_PROTOCOL(protocol);
#ifdef SS_DEBUG MXS_DEBUG("Protocol state: %s", gw_mysql_protocol_state2string(protocol->protocol_auth_state));
MXS_DEBUG("[gw_read_client_event] Protocol state: %s",
gw_mysql_protocol_state2string(protocol->protocol_auth_state));
#endif
/** /**
* The use of max_bytes seems like a hack, but no better option is available * The use of max_bytes seems like a hack, but no better option is available
@ -1051,16 +1047,14 @@ mysql_client_auth_error_handling(DCB *dcb, int auth_val, int packet_number)
switch (auth_val) switch (auth_val)
{ {
case MXS_AUTH_NO_SESSION: case MXS_AUTH_NO_SESSION:
MXS_DEBUG("%lu [gw_read_client_event] session creation failed. fd %d, " MXS_DEBUG("session creation failed. fd %d, state = MYSQL_AUTH_NO_SESSION.", dcb->fd);
"state = MYSQL_AUTH_NO_SESSION.", pthread_self(), dcb->fd);
/** Send ERR 1045 to client */ /** Send ERR 1045 to client */
mysql_send_auth_error(dcb, packet_number, 0, "failed to create new session"); mysql_send_auth_error(dcb, packet_number, 0, "failed to create new session");
break; break;
case MXS_AUTH_FAILED_DB: case MXS_AUTH_FAILED_DB:
MXS_DEBUG("%lu [gw_read_client_event] database specified was not valid. fd %d, " MXS_DEBUG("database specified was not valid. fd %d, state = MYSQL_FAILED_AUTH_DB.", dcb->fd);
"state = MYSQL_FAILED_AUTH_DB.", pthread_self(), dcb->fd);
/** Send error 1049 to client */ /** Send error 1049 to client */
message_len = 25 + MYSQL_DATABASE_MAXLEN; message_len = 25 + MYSQL_DATABASE_MAXLEN;
@ -1072,18 +1066,17 @@ mysql_client_auth_error_handling(DCB *dcb, int auth_val, int packet_number)
break; break;
case MXS_AUTH_FAILED_SSL: case MXS_AUTH_FAILED_SSL:
MXS_DEBUG("%lu [gw_read_client_event] client is " MXS_DEBUG("client is "
"not SSL capable for SSL listener. fd %d, " "not SSL capable for SSL listener. fd %d, "
"state = MYSQL_FAILED_AUTH_SSL.", pthread_self(), dcb->fd); "state = MYSQL_FAILED_AUTH_SSL.", dcb->fd);
/** Send ERR 1045 to client */ /** Send ERR 1045 to client */
mysql_send_auth_error(dcb, packet_number, 0, "Access without SSL denied"); mysql_send_auth_error(dcb, packet_number, 0, "Access without SSL denied");
break; break;
case MXS_AUTH_SSL_INCOMPLETE: case MXS_AUTH_SSL_INCOMPLETE:
MXS_DEBUG("%lu [gw_read_client_event] unable to " MXS_DEBUG("unable to complete SSL authentication. fd %d, "
"complete SSL authentication. fd %d, " "state = MYSQL_AUTH_SSL_INCOMPLETE.", dcb->fd);
"state = MYSQL_AUTH_SSL_INCOMPLETE.", pthread_self(), dcb->fd);
/** Send ERR 1045 to client */ /** Send ERR 1045 to client */
mysql_send_auth_error(dcb, packet_number, 0, mysql_send_auth_error(dcb, packet_number, 0,
@ -1091,8 +1084,7 @@ mysql_client_auth_error_handling(DCB *dcb, int auth_val, int packet_number)
break; break;
case MXS_AUTH_FAILED: case MXS_AUTH_FAILED:
MXS_DEBUG("%lu [gw_read_client_event] authentication failed. fd %d, " MXS_DEBUG("authentication failed. fd %d, state = MYSQL_FAILED_AUTH.", dcb->fd);
"state = MYSQL_FAILED_AUTH.", pthread_self(), dcb->fd);
/** Send error 1045 to client */ /** Send error 1045 to client */
fail_str = create_auth_fail_str(session->user, dcb->remote, fail_str = create_auth_fail_str(session->user, dcb->remote,
session->auth_token_len > 0, session->auth_token_len > 0,
@ -1101,8 +1093,7 @@ mysql_client_auth_error_handling(DCB *dcb, int auth_val, int packet_number)
break; break;
default: default:
MXS_DEBUG("%lu [gw_read_client_event] authentication failed. fd %d, " MXS_DEBUG("authentication failed. fd %d, state unrecognized.", dcb->fd);
"state unrecognized.", pthread_self(), dcb->fd);
/** Send error 1045 to client */ /** Send error 1045 to client */
fail_str = create_auth_fail_str(session->user, dcb->remote, fail_str = create_auth_fail_str(session->user, dcb->remote,
session->auth_token_len > 0, session->auth_token_len > 0,
@ -1241,9 +1232,7 @@ static void gw_process_one_new_client(DCB *client_dcb)
{ {
/** delete client_dcb */ /** delete client_dcb */
dcb_close(client_dcb); dcb_close(client_dcb);
MXS_ERROR("%lu [gw_MySQLAccept] Failed to create " MXS_ERROR("Failed to create protocol object for client connection.");
"protocol object for client connection.",
pthread_self());
return; return;
} }
CHK_PROTOCOL(protocol); CHK_PROTOCOL(protocol);
@ -1280,20 +1269,14 @@ static void gw_process_one_new_client(DCB *client_dcb)
dcb_close(client_dcb); dcb_close(client_dcb);
/** Previous state is recovered in poll_add_dcb. */ /** Previous state is recovered in poll_add_dcb. */
MXS_ERROR("%lu [gw_MySQLAccept] Failed to add dcb %p for " MXS_ERROR("Failed to add dcb %p for fd %d to epoll set.",
"fd %d to epoll set.", client_dcb, client_dcb->fd);
pthread_self(),
client_dcb,
client_dcb->fd);
return; return;
} }
else else
{ {
MXS_DEBUG("%lu [gw_MySQLAccept] Added dcb %p for fd " MXS_DEBUG("Added dcb %p for fd %d to epoll set.",
"%d to epoll set.", client_dcb, client_dcb->fd);
pthread_self(),
client_dcb,
client_dcb->fd);
} }
return; return;
} }
@ -1306,13 +1289,6 @@ static int gw_error_client_event(DCB* dcb)
session = dcb->session; session = dcb->session;
MXS_DEBUG("%lu [gw_error_client_event] Error event handling for DCB %p "
"in state %s, session %p.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state),
(session != NULL ? session : NULL));
if (session != NULL && session->state == SESSION_STATE_STOPPING) if (session != NULL && session->state == SESSION_STATE_STOPPING)
{ {
goto retblock; goto retblock;

17
server/modules/protocol/MySQL/mysql_common.c
View File

@ -458,11 +458,8 @@ int mysql_send_auth_error(DCB *dcb,
if (dcb->state != DCB_STATE_POLLING) if (dcb->state != DCB_STATE_POLLING)
{ {
MXS_DEBUG("%lu [mysql_send_auth_error] dcb %p is in a state %s, " MXS_DEBUG("dcb %p is in a state %s, and it is not in epoll set anymore. Skip error sending.",
"and it is not in epoll set anymore. Skip error sending.", dcb, STRDCBSTATE(dcb->state));
pthread_self(),
dcb,
STRDCBSTATE(dcb->state));
return 0; return 0;
} }
mysql_error_msg = "Access denied!"; mysql_error_msg = "Access denied!";
@ -792,10 +789,7 @@ mysql_server_cmd_t protocol_get_srv_command(MySQLProtocol* p,
{ {
protocol_remove_srv_command(p); protocol_remove_srv_command(p);
} }
MXS_DEBUG("%lu [protocol_get_srv_command] Read command %s for fd %d.", MXS_DEBUG("Read command %s for fd %d.", STRPACKETTYPE(cmd), p->owner_dcb->fd);
pthread_self(),
STRPACKETTYPE(cmd),
p->owner_dcb->fd);
return cmd; return cmd;
} }
@ -1045,9 +1039,8 @@ bool gw_get_shared_session_auth_info(DCB* dcb, MYSQL_session* session)
else else
{ {
ss_dassert(false); ss_dassert(false);
MXS_ERROR("%lu [gw_get_shared_session_auth_info] Couldn't get " MXS_ERROR("Couldn't get session authentication info. Session in a wrong state %s.",
"session authentication info. Session in a wrong state %d.", STRSESSIONSTATE(dcb->session->state));
pthread_self(), dcb->session->state);
rval = false; rval = false;
} }