Use RFC 3986 compliant addresses in log messages

When log messages are written with both address and port information, IPv6
addresses can cause confusion if the normal address:port formatting is
used. The RFC 3986 suggests that all IPv6 addresses are expressed as a
bracket enclosed address optionally followed by the port that is separate
from the address by a colon.

In practice, the "all interfaces" address and port number 3306 can be
written in IPv4 numbers-and-dots notation as 0.0.0.0:3306 and in IPv6
notation as [::]:3306. Using the latter format in log messages keeps the
output consistent with all types of addresses.

The details of the standard can be found at the following addresses:

     https://www.ietf.org/rfc/rfc3986.txt

     https://www.rfc-editor.org/std/std66.txt
This commit is contained in:
Markus Mäkelä
2017-03-29 23:30:34 +03:00
parent 32dca26c96
commit cbc1e864d9
23 changed files with 97 additions and 78 deletions

View File

@ -892,7 +892,7 @@ diagnostics(MXS_ROUTER *router, DCB *dcb)
char sync_marker_hex[SYNC_MARKER_SIZE * 2 + 1];
dcb_printf(dcb, "\t\tClient UUID: %s\n", session->uuid);
dcb_printf(dcb, "\t\tClient_host_port: %s:%d\n",
dcb_printf(dcb, "\t\tClient_host_port: [%s]:%d\n",
session->dcb->remote, dcb_get_port(session->dcb));
dcb_printf(dcb, "\t\tUsername: %s\n", session->dcb->user);
dcb_printf(dcb, "\t\tClient DCB: %p\n", session->dcb);

View File

@ -1129,7 +1129,7 @@ closeSession(MXS_ROUTER *instance, MXS_ROUTER_SESSION *router_session)
if (slave->state > 0)
{
MXS_NOTICE("%s: Slave %s:%d, server id %d, disconnected after %ld seconds. "
MXS_NOTICE("%s: Slave [%s]:%d, server id %d, disconnected after %ld seconds. "
"%d SQL commands, %d events sent (%lu bytes), binlog '%s', "
"last position %lu",
router->service->name, slave->dcb->remote, dcb_get_port(slave->dcb),
@ -1532,7 +1532,7 @@ diagnostics(MXS_ROUTER *router, DCB *dcb)
dcb_printf(dcb, "\t\tSlave UUID: %s\n", session->uuid);
}
dcb_printf(dcb,
"\t\tSlave_host_port: %s:%d\n",
"\t\tSlave_host_port: [%s]:%d\n",
session->dcb->remote, dcb_get_port(session->dcb));
dcb_printf(dcb,
"\t\tUsername: %s\n",
@ -1772,7 +1772,7 @@ errorReply(MXS_ROUTER *instance,
dcb_close(backend_dcb);
MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', "
"%s while connecting to master %s:%d",
"%s while connecting to master [%s]:%d",
router->service->name, router->m_errno, router->m_errmsg,
blrm_states[BLRM_TIMESTAMP], msg,
router->service->dbref->server->name,
@ -1821,7 +1821,7 @@ errorReply(MXS_ROUTER *instance,
spinlock_release(&router->lock);
MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', "
"%s attempting reconnect to master %s:%d",
"%s attempting reconnect to master [%s]:%d",
router->service->name, mysql_errno, errmsg,
blrm_states[router->master_state], msg,
router->service->dbref->server->name,
@ -1830,7 +1830,7 @@ errorReply(MXS_ROUTER *instance,
else
{
MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', "
"%s attempting reconnect to master %s:%d",
"%s attempting reconnect to master [%s]:%d",
router->service->name, router->m_errno,
router->m_errmsg ? router->m_errmsg : "(memory failure)",
blrm_states[router->master_state], msg,
@ -2468,7 +2468,7 @@ destroyInstance(MXS_ROUTER *instance)
}
}
MXS_INFO("%s is being stopped by MaxScale shudown. Disconnecting from master %s:%d, "
MXS_INFO("%s is being stopped by MaxScale shudown. Disconnecting from master [%s]:%d, "
"read up to log %s, pos %lu, transaction safe pos %lu",
inst->service->name,
inst->service->dbref->server->name,

View File

@ -203,7 +203,7 @@ blr_start_master(void* data)
}
router->master->remote = MXS_STRDUP_A(router->service->dbref->server->name);
MXS_NOTICE("%s: attempting to connect to master server %s:%d, binlog %s, pos %lu",
MXS_NOTICE("%s: attempting to connect to master server [%s]:%d, binlog %s, pos %lu",
router->service->name, router->service->dbref->server->name,
router->service->dbref->server->port, router->binlog_name, router->current_pos);
@ -706,7 +706,7 @@ blr_master_response(ROUTER_INSTANCE *router, GWBUF *buf)
/* if semisync option is set, check for master semi-sync availability */
if (router->request_semi_sync)
{
MXS_NOTICE("%s: checking Semi-Sync replication capability for master server %s:%d",
MXS_NOTICE("%s: checking Semi-Sync replication capability for master server [%s]:%d",
router->service->name,
router->service->dbref->server->name,
router->service->dbref->server->port);
@ -739,7 +739,7 @@ blr_master_response(ROUTER_INSTANCE *router, GWBUF *buf)
if (router->master_semi_sync == MASTER_SEMISYNC_NOT_AVAILABLE)
{
/* not installed */
MXS_NOTICE("%s: master server %s:%d doesn't have semi_sync capability",
MXS_NOTICE("%s: master server [%s]:%d doesn't have semi_sync capability",
router->service->name,
router->service->dbref->server->name,
router->service->dbref->server->port);
@ -753,7 +753,7 @@ blr_master_response(ROUTER_INSTANCE *router, GWBUF *buf)
if (router->master_semi_sync == MASTER_SEMISYNC_DISABLED)
{
/* Installed but not enabled, right now */
MXS_NOTICE("%s: master server %s:%d doesn't have semi_sync enabled right now, "
MXS_NOTICE("%s: master server [%s]:%d doesn't have semi_sync enabled right now, "
"Requesting Semi-Sync Replication",
router->service->name,
router->service->dbref->server->name,
@ -762,7 +762,7 @@ blr_master_response(ROUTER_INSTANCE *router, GWBUF *buf)
else
{
/* Installed and enabled */
MXS_NOTICE("%s: master server %s:%d has semi_sync enabled, Requesting Semi-Sync Replication",
MXS_NOTICE("%s: master server [%s]:%d has semi_sync enabled, Requesting Semi-Sync Replication",
router->service->name,
router->service->dbref->server->name,
router->service->dbref->server->port);
@ -803,7 +803,7 @@ blr_master_response(ROUTER_INSTANCE *router, GWBUF *buf)
router->master->func.write(router->master, buf);
MXS_NOTICE("%s: Request binlog records from %s at "
"position %lu from master server %s:%d",
"position %lu from master server [%s]:%d",
router->service->name, router->binlog_name,
router->current_pos,
router->service->dbref->server->name,
@ -1512,7 +1512,7 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt)
MXS_DEBUG("%s: binlog record in file %s, pos %lu has "
"SEMI_SYNC_ACK_REQ and needs a Semi-Sync ACK packet to "
"be sent to the master server %s:%d",
"be sent to the master server [%s]:%d",
router->service->name, router->binlog_name,
router->current_pos,
router->service->dbref->server->name,
@ -2144,7 +2144,7 @@ blr_check_heartbeat(ROUTER_INSTANCE *router)
{
if ((t_now - router->stats.lastReply) > (router->heartbeat + BLR_NET_LATENCY_WAIT_TIME))
{
MXS_ERROR("No event received from master %s:%d in heartbeat period (%lu seconds), "
MXS_ERROR("No event received from master [%s]:%d in heartbeat period (%lu seconds), "
"last event (%s %d) received %lu seconds ago. Assuming connection is dead "
"and reconnecting.",
router->service->dbref->server->name,
@ -2408,7 +2408,7 @@ bool blr_send_event(blr_thread_role_t role,
}
else
{
MXS_ERROR("Failed to send an event of %u bytes to slave at %s:%d.",
MXS_ERROR("Failed to send an event of %u bytes to slave at [%s]:%d.",
hdr->event_size, slave->dcb->remote,
dcb_get_port(slave->dcb));
}

View File

@ -2174,7 +2174,7 @@ blr_slave_binlog_dump(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue
slave->state = BLRS_DUMPING;
MXS_NOTICE("%s: Slave %s:%d, server id %d requested binlog file %s from position %lu",
MXS_NOTICE("%s: Slave [%s]:%d, server id %d requested binlog file %s from position %lu",
router->service->name, slave->dcb->remote,
dcb_get_port(slave->dcb),
slave->serverid,
@ -2670,7 +2670,7 @@ blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large)
* but the new binlog file has not yet been created. Therefore
* we ignore these issues during the rotate processing.
*/
MXS_ERROR("%s: Slave %s:%d, server-id %d reached end of file for binlog file %s "
MXS_ERROR("%s: Slave [%s]:%d, server-id %d reached end of file for binlog file %s "
"at %lu which is not the file currently being downloaded. "
"Master binlog is %s, %lu. This may be caused by a "
"previous failure of the master.",
@ -3468,7 +3468,7 @@ blr_stop_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave)
spinlock_release(&router->lock);
MXS_NOTICE("%s: STOP SLAVE executed by %s@%s. Disconnecting from master %s:%d, "
MXS_NOTICE("%s: STOP SLAVE executed by %s@%s. Disconnecting from master [%s]:%d, "
"read up to log %s, pos %lu, transaction safe pos %lu",
router->service->name,
slave->dcb->user,
@ -3626,7 +3626,7 @@ blr_start_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave)
/** Start replication from master */
blr_start_master(router);
MXS_NOTICE("%s: START SLAVE executed by %s@%s. Trying connection to master %s:%d, "
MXS_NOTICE("%s: START SLAVE executed by %s@%s. Trying connection to master [%s]:%d, "
"binlog %s, pos %lu, transaction safe pos %lu",
router->service->name,
slave->dcb->user,

View File

@ -762,14 +762,14 @@ static void clientReply(MXS_ROUTER *instance,
{
bool succp;
MXS_INFO("Backend %s:%d processed reply and starts to execute active cursor.",
MXS_INFO("Backend [%s]:%d processed reply and starts to execute active cursor.",
bref->ref->server->name, bref->ref->server->port);
succp = execute_sescmd_in_backend(bref);
if (!succp)
{
MXS_INFO("Backend %s:%d failed to execute session command.",
MXS_INFO("Backend [%s]:%d failed to execute session command.",
bref->ref->server->name, bref->ref->server->port);
}
}
@ -1087,7 +1087,7 @@ int router_handle_state_switch(DCB *dcb, DCB_REASON reason, void *data)
goto return_rc;
}
MXS_DEBUG("%lu [router_handle_state_switch] %s %s:%d in state %s",
MXS_DEBUG("%lu [router_handle_state_switch] %s [%s]:%d in state %s",
pthread_self(), STRDCBREASON(reason), srv->name, srv->port,
STRSRVSTATUS(srv));
CHK_SESSION(((MXS_SESSION *)dcb->session));
@ -1318,7 +1318,7 @@ static void handleError(MXS_ROUTER *instance,
}
else if (!SERVER_IS_MASTER(srv) && !srv->master_err_is_logged)
{
MXS_ERROR("Server %s:%d lost the master status. Readwritesplit "
MXS_ERROR("Server [%s]:%d lost the master status. Readwritesplit "
"service can't locate the master. Client sessions "
"will be closed.", srv->name, srv->port);
srv->master_err_is_logged = true;
@ -1336,7 +1336,7 @@ static void handleError(MXS_ROUTER *instance,
}
else
{
MXS_ERROR("Server %s:%d lost the master status but could not locate the "
MXS_ERROR("Server [%s]:%d lost the master status but could not locate the "
"corresponding backend ref.", srv->name, srv->port);
}
}

View File

@ -369,7 +369,7 @@ void check_session_command_reply(GWBUF *writebuf, sescmd_cursor_t *scur, backend
ss_dassert(len + 4 == GWBUF_LENGTH(scur->scmd_cur_cmd->my_sescmd_buf));
MXS_ERROR("Failed to execute session command in %s:%d. Error was: %s %s",
MXS_ERROR("Failed to execute session command in [%s]:%d. Error was: %s %s",
bref->ref->server->name,
bref->ref->server->port, err, replystr);
MXS_FREE(err);

View File

@ -209,7 +209,7 @@ bool route_session_write(ROUTER_CLIENT_SES *router_cli_ses,
if (MXS_LOG_PRIORITY_IS_ENABLED(LOG_INFO) &&
BREF_IS_IN_USE((&backend_ref[i])))
{
MXS_INFO("Route query to %s \t%s:%d%s",
MXS_INFO("Route query to %s \t[%s]:%d%s",
(SERVER_IS_MASTER(backend_ref[i].ref->server)
? "master" : "slave"),
backend_ref[i].ref->server->name,
@ -316,7 +316,7 @@ bool route_session_write(ROUTER_CLIENT_SES *router_cli_ses,
if (MXS_LOG_PRIORITY_IS_ENABLED(LOG_INFO))
{
MXS_INFO("Route query to %s \t%s:%d%s",
MXS_INFO("Route query to %s \t[%s]:%d%s",
(SERVER_IS_MASTER(backend_ref[i].ref->server)
? "master" : "slave"),
backend_ref[i].ref->server->name,
@ -339,7 +339,7 @@ bool route_session_write(ROUTER_CLIENT_SES *router_cli_ses,
if (sescmd_cursor_is_active(scur) && &backend_ref[i] != router_cli_ses->rses_master_ref)
{
nsucc += 1;
MXS_INFO("Backend %s:%d already executing sescmd.",
MXS_INFO("Backend [%s]:%d already executing sescmd.",
backend_ref[i].ref->server->name,
backend_ref[i].ref->server->port);
}
@ -351,7 +351,7 @@ bool route_session_write(ROUTER_CLIENT_SES *router_cli_ses,
}
else
{
MXS_ERROR("Failed to execute session command in %s:%d",
MXS_ERROR("Failed to execute session command in [%s]:%d",
backend_ref[i].ref->server->name,
backend_ref[i].ref->server->port);
}
@ -607,7 +607,7 @@ bool rwsplit_get_dcb(DCB **p_dcb, ROUTER_CLIENT_SES *rses, backend_type_t btype,
}
else
{
MXS_INFO("Server %s:%d is too much behind the master, %d s. and can't be chosen.",
MXS_INFO("Server [%s]:%d is too much behind the master, %d s. and can't be chosen.",
b->server->name, b->server->port, b->server->rlag);
}
}
@ -1230,7 +1230,7 @@ handle_got_target(ROUTER_INSTANCE *inst, ROUTER_CLIENT_SES *rses,
ss_dassert(target_dcb != NULL);
MXS_INFO("Route query to %s \t%s:%d <",
MXS_INFO("Route query to %s \t[%s]:%d <",
(SERVER_IS_MASTER(bref->ref->server) ? "master"
: "slave"), bref->ref->server->name, bref->ref->server->port);
/**

View File

@ -277,7 +277,7 @@ bool select_connect_backend_servers(backend_ref_t **p_master_ref,
{
if (BREF_IS_IN_USE((&backend_ref[i])))
{
MXS_INFO("Selected %s in \t%s:%d",
MXS_INFO("Selected %s in \t[%s]:%d",
STRSRVSTATUS(backend_ref[i].ref->server),
backend_ref[i].ref->server->name,
backend_ref[i].ref->server->port);
@ -443,7 +443,7 @@ static bool connect_server(backend_ref_t *bref, MXS_SESSION *session, bool execu
}
else
{
MXS_ERROR("Failed to execute session command in %s (%s:%d). See earlier "
MXS_ERROR("Failed to execute session command in %s ([%s]:%d). See earlier "
"errors for more details.",
bref->ref->server->unique_name,
bref->ref->server->name,
@ -456,7 +456,7 @@ static bool connect_server(backend_ref_t *bref, MXS_SESSION *session, bool execu
}
else
{
MXS_ERROR("Unable to establish connection with server %s:%d",
MXS_ERROR("Unable to establish connection with server [%s]:%d",
serv->name, serv->port);
}
@ -489,26 +489,26 @@ static void log_server_connections(select_criteria_t select_criteria,
switch (select_criteria)
{
case LEAST_GLOBAL_CONNECTIONS:
MXS_INFO("MaxScale connections : %d in \t%s:%d %s",
MXS_INFO("MaxScale connections : %d in \t[%s]:%d %s",
b->server->stats.n_current, b->server->name,
b->server->port, STRSRVSTATUS(b->server));
break;
case LEAST_ROUTER_CONNECTIONS:
MXS_INFO("RWSplit connections : %d in \t%s:%d %s",
MXS_INFO("RWSplit connections : %d in \t[%s]:%d %s",
b->connections, b->server->name,
b->server->port, STRSRVSTATUS(b->server));
break;
case LEAST_CURRENT_OPERATIONS:
MXS_INFO("current operations : %d in \t%s:%d %s",
MXS_INFO("current operations : %d in \t[%s]:%d %s",
b->server->stats.n_current_ops,
b->server->name, b->server->port,
STRSRVSTATUS(b->server));
break;
case LEAST_BEHIND_MASTER:
MXS_INFO("replication lag : %d in \t%s:%d %s",
MXS_INFO("replication lag : %d in \t[%s]:%d %s",
b->server->rlag, b->server->name,
b->server->port, STRSRVSTATUS(b->server));
default:

View File

@ -216,7 +216,7 @@ GWBUF *sescmd_cursor_process_replies(GWBUF *replybuf,
RW_CLOSE_BREF(&ses->rses_backend_ref[i]);
}
*reconnect = true;
MXS_INFO("Disabling slave %s:%d, result differs from "
MXS_INFO("Disabling slave [%s]:%d, result differs from "
"master's result. Master: %d Slave: %d",
ses->rses_backend_ref[i].ref->server->name,
ses->rses_backend_ref[i].ref->server->port,

View File

@ -2065,7 +2065,7 @@ static int routeQuery(MXS_ROUTER* instance,
bref = get_bref_from_dcb(router_cli_ses, target_dcb);
scur = &bref->bref_sescmd_cur;
MXS_INFO("Route query to \t%s:%d <",
MXS_INFO("Route query to \t[%s]:%d <",
bref->bref_backend->server->name,
bref->bref_backend->server->port);
/**
@ -2413,7 +2413,7 @@ static void clientReply(MXS_ROUTER* instance,
ss_dassert(len + 4 == GWBUF_LENGTH(scur->scmd_cur_cmd->my_sescmd_buf));
MXS_ERROR("Failed to execute %s in %s:%d. %s %s",
MXS_ERROR("Failed to execute %s in [%s]:%d. %s %s",
cmdstr,
bref->bref_backend->server->name,
bref->bref_backend->server->port,
@ -2481,7 +2481,7 @@ static void clientReply(MXS_ROUTER* instance,
if (sescmd_cursor_is_active(scur))
{
MXS_INFO("Backend %s:%d processed reply and starts to execute "
MXS_INFO("Backend [%s]:%d processed reply and starts to execute "
"active cursor.",
bref->bref_backend->server->name,
bref->bref_backend->server->port);
@ -2714,7 +2714,7 @@ static bool connect_backend_servers(backend_ref_t* backend_ref,
{
SERVER_REF* b = backend_ref[i].bref_backend;
MXS_INFO("MaxScale connections : %d (%d) in \t%s:%d %s",
MXS_INFO("MaxScale connections : %d (%d) in \t[%s]:%d %s",
b->connections,
b->server->stats.n_current,
b->server->name,
@ -2782,7 +2782,7 @@ static bool connect_backend_servers(backend_ref_t* backend_ref,
{
succp = false;
MXS_ERROR("Unable to establish "
"connection with slave %s:%d",
"connection with slave [%s]:%d",
b->server->name,
b->server->port);
/* handle connect error */
@ -2822,7 +2822,7 @@ static bool connect_backend_servers(backend_ref_t* backend_ref,
if (BREF_IS_IN_USE((&backend_ref[i])))
{
MXS_INFO("Connected %s in \t%s:%d",
MXS_INFO("Connected %s in \t[%s]:%d",
STRSRVSTATUS(b->server),
b->server->name,
b->server->port);
@ -3381,7 +3381,7 @@ static bool route_session_write(ROUTER_CLIENT_SES* router_cli_ses,
if (MXS_LOG_PRIORITY_IS_ENABLED(LOG_INFO))
{
MXS_INFO("Route query to %s\t%s:%d%s",
MXS_INFO("Route query to %s\t[%s]:%d%s",
(SERVER_IS_MASTER(backend_ref[i].bref_backend->server) ?
"master" : "slave"),
backend_ref[i].bref_backend->server->name,
@ -3488,7 +3488,7 @@ static bool route_session_write(ROUTER_CLIENT_SES* router_cli_ses,
if (MXS_LOG_PRIORITY_IS_ENABLED(LOG_INFO))
{
MXS_INFO("Route query to %s\t%s:%d%s",
MXS_INFO("Route query to %s\t[%s]:%d%s",
(SERVER_IS_MASTER(backend_ref[i].bref_backend->server) ?
"master" : "slave"),
backend_ref[i].bref_backend->server->name,
@ -3513,7 +3513,7 @@ static bool route_session_write(ROUTER_CLIENT_SES* router_cli_ses,
{
succp = true;
MXS_INFO("Backend %s:%d already executing sescmd.",
MXS_INFO("Backend [%s]:%d already executing sescmd.",
backend_ref[i].bref_backend->server->name,
backend_ref[i].bref_backend->server->port);
}
@ -3524,7 +3524,7 @@ static bool route_session_write(ROUTER_CLIENT_SES* router_cli_ses,
if (!succp)
{
MXS_ERROR("Failed to execute session "
"command in %s:%d",
"command in [%s]:%d",
backend_ref[i].bref_backend->server->name,
backend_ref[i].bref_backend->server->port);
}