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

binlogrouter: All LOGIFs and skygw_log_writes replaced.

Browse Source 
All LOGIFs and skygw_log_writes replaced with the equivalent
MXS_[ERROR|WARNING|NOTICE|INFO|DEBUG] macros.
This commit is contained in:
Johan Wikman
2015-11-18 09:43:11 +02:00
parent d59c6a3570
commit afdeb6fa5b
5 changed files with 758 additions and 983 deletions
Download Patch File Download Diff File Expand all files Collapse all files

239
server/modules/routing/binlog/blr.c
View File

@ -157,9 +157,7 @@ version()
void void
ModuleInit() ModuleInit()
{ {
LOGIF(LM, (skygw_log_write( MXS_NOTICE("Initialise binlog router module %s.\n", version_str);
LOGFILE_MESSAGE,
"Initialise binlog router module %s.\n", version_str)));
spinlock_init(&instlock); spinlock_init(&instlock);
instances = NULL; instances = NULL;
} }
@ -206,7 +204,7 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
if(service->credentials.name == NULL || if(service->credentials.name == NULL ||
service->credentials.authdata == NULL) service->credentials.authdata == NULL)
{ {
skygw_log_write(LE,"%s: Error: Service is missing user credentials." MXS_ERROR("%s: Error: Service is missing user credentials."
" Add the missing username or passwd parameter to the service.", " Add the missing username or passwd parameter to the service.",
service->name); service->name);
return NULL; return NULL;
@ -214,8 +212,7 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
if(options == NULL || options[0] == NULL) if(options == NULL || options[0] == NULL)
{ {
skygw_log_write(LE, MXS_ERROR("%s: Error: No router options supplied for binlogrouter",
"%s: Error: No router options supplied for binlogrouter",
service->name); service->name);
return NULL; return NULL;
} }
@ -227,11 +224,10 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
*/ */
if (service->dbref != NULL) if (service->dbref != NULL)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("%s: backend database server is provided by master.ini file "
"%s: Warning: backend database server is provided by master.ini file "
"for use with the binlog router." "for use with the binlog router."
" Server section is no longer required.", " Server section is no longer required.",
service->name))); service->name);
server_free(service->dbref->server); server_free(service->dbref->server);
free(service->dbref); free(service->dbref);
@ -239,9 +235,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
} }
if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) { if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("%s: Error: failed to allocate memory for router instance.",
"%s: Error: failed to allocate memory for router instance.", service->name);
service->name)));
return NULL; return NULL;
} }
@ -328,10 +323,9 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
{ {
if ((value = strchr(options[i], '=')) == NULL) if ((value = strchr(options[i], '=')) == NULL)
{ {
LOGIF(LE, (skygw_log_write( MXS_WARNING("Unsupported router "
LOGFILE_ERROR, "Warning : Unsupported router "
"option %s for binlog router.", "option %s for binlog router.",
options[i]))); options[i]);
} }
else else
{ {
@ -345,20 +339,16 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
{ {
inst->serverid = atoi(value); inst->serverid = atoi(value);
if (strcmp(options[i], "server-id") == 0) { if (strcmp(options[i], "server-id") == 0) {
LOGIF(LE, (skygw_log_write_flush( MXS_WARNING("Configuration setting '%s' in router_options is deprecated"
LOGFILE_ERROR,
"WARNING: Configuration setting '%s' in router_options is deprecated"
" and will be removed in a later version of MaxScale. " " and will be removed in a later version of MaxScale. "
"Please use the new setting '%s' instead.", "Please use the new setting '%s' instead.",
"server-id", "server_id"))); "server-id", "server_id");
} }
if (inst->serverid <= 0) { if (inst->serverid <= 0) {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Service %s, invalid server-id '%s'. "
LOGFILE_ERROR,
"Error : Service %s, invalid server-id '%s'. "
"Please configure it with a unique positive integer value (1..2^32-1)", "Please configure it with a unique positive integer value (1..2^32-1)",
service->name, value))); service->name, value);
free(inst); free(inst);
return NULL; return NULL;
@ -384,12 +374,10 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
inst->set_master_server_id = strdup(value); inst->set_master_server_id = strdup(value);
} }
if (strcmp(options[i], "master-id") == 0) { if (strcmp(options[i], "master-id") == 0) {
LOGIF(LE, (skygw_log_write_flush( MXS_WARNING("Configuration setting '%s' in router_options is deprecated"
LOGFILE_ERROR,
"WARNING: Configuration setting '%s' in router_options is deprecated"
" and will be removed in a later version of MaxScale. " " and will be removed in a later version of MaxScale. "
"Please use the new setting '%s' instead.", "Please use the new setting '%s' instead.",
"master-id", "master_id"))); "master-id", "master_id");
} }
} }
else if (strcmp(options[i], "master_uuid") == 0) else if (strcmp(options[i], "master_uuid") == 0)
@ -466,11 +454,9 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
int h_val = (int)strtol(value, NULL, 10); int h_val = (int)strtol(value, NULL, 10);
if (h_val <= 0 || (errno == ERANGE)) { if (h_val <= 0 || (errno == ERANGE)) {
LOGIF(LE, (skygw_log_write_flush( MXS_WARNING("Invalid heartbeat period %s."
LOGFILE_ERROR,
"Warning : invalid heartbeat period %s."
" Setting it to default value %ld.", " Setting it to default value %ld.",
value, inst->heartbeat))); value, inst->heartbeat);
} else { } else {
inst->heartbeat = h_val; inst->heartbeat = h_val;
} }
@ -485,20 +471,17 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
} }
else else
{ {
LOGIF(LE, (skygw_log_write( MXS_WARNING("Unsupported router "
LOGFILE_ERROR,
"Warning : Unsupported router "
"option %s for binlog router.", "option %s for binlog router.",
options[i]))); options[i]);
} }
} }
} }
} }
else else
{ {
LOGIF(LE, (skygw_log_write( MXS_ERROR("%s: Error: No router options supplied for binlogrouter",
LOGFILE_ERROR, "%s: Error: No router options supplied for binlogrouter", service->name);
service->name)));
} }
if (inst->fileroot == NULL) if (inst->fileroot == NULL)
@ -520,16 +503,14 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
strcpy(inst->prevbinlog, ""); strcpy(inst->prevbinlog, "");
if ((inst->binlogdir == NULL) || (inst->binlogdir != NULL && !strlen(inst->binlogdir))) { if ((inst->binlogdir == NULL) || (inst->binlogdir != NULL && !strlen(inst->binlogdir))) {
skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Service %s, binlog directory is not specified",
"Error : Service %s, binlog directory is not specified",
service->name); service->name);
free(inst); free(inst);
return NULL; return NULL;
} }
if (inst->serverid <= 0) { if (inst->serverid <= 0) {
skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Service %s, server-id is not configured. "
"Error : Service %s, server-id is not configured. "
"Please configure it with a unique positive integer value (1..2^32-1)", "Please configure it with a unique positive integer value (1..2^32-1)",
service->name); service->name);
free(inst); free(inst);
@ -545,8 +526,7 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
mkdir_rval = mkdir(inst->binlogdir, 0700); mkdir_rval = mkdir(inst->binlogdir, 0700);
if (mkdir_rval == -1) { if (mkdir_rval == -1) {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Service %s, Failed to create binlog directory '%s': [%d] %s",
"Error : Service %s, Failed to create binlog directory '%s': [%d] %s",
service->name, service->name,
inst->binlogdir, inst->binlogdir,
errno, errno,
@ -561,9 +541,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
if (service->users == NULL) { if (service->users == NULL) {
service->users = (void *)mysql_users_alloc(); service->users = (void *)mysql_users_alloc();
if (service->users == NULL) { if (service->users == NULL) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("%s: Error allocating dbusers in createInstance",
"%s: Error allocating dbusers in createInstance", inst->service->name);
inst->service->name)));
free(inst); free(inst);
return NULL; return NULL;
@ -576,9 +555,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
SERVER *server; SERVER *server;
server = server_alloc("_none_", "MySQLBackend", (int)3306); server = server_alloc("_none_", "MySQLBackend", (int)3306);
if (server == NULL) { if (server == NULL) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("%s: Error for server_alloc in createInstance",
"%s: Error for server_alloc in createInstance", inst->service->name);
inst->service->name)));
if (service->users) { if (service->users) {
users_free(service->users); users_free(service->users);
service->users = NULL; service->users = NULL;
@ -605,11 +583,10 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
rc = ini_parse(filename, blr_handler_config, inst); rc = ini_parse(filename, blr_handler_config, inst);
LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, MXS_INFO("%s: %s parse result is %d",
"%s: %s parse result is %d",
inst->service->name, inst->service->name,
filename, filename,
rc))); rc);
/* /*
* retcode: * retcode:
@ -618,17 +595,15 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
if (rc != 0) { if (rc != 0) {
if (rc == -1) { if (rc == -1) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("%s: master.ini file not found in %s."
"%s: master.ini file not found in %s."
" Master registration cannot be started." " Master registration cannot be started."
" Configure with CHANGE MASTER TO ...", " Configure with CHANGE MASTER TO ...",
inst->service->name, inst->binlogdir))); inst->service->name, inst->binlogdir);
} else { } else {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("%s: master.ini file with errors in %s."
"%s: master.ini file with errors in %s."
" Master registration cannot be started." " Master registration cannot be started."
" Fix errors in it or configure with CHANGE MASTER TO ...", " Fix errors in it or configure with CHANGE MASTER TO ...",
inst->service->name, inst->binlogdir))); inst->service->name, inst->binlogdir);
} }
/* Set service user or load db users */ /* Set service user or load db users */
@ -652,11 +627,9 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
/* Find latest binlog file or create a new one (000001) */ /* Find latest binlog file or create a new one (000001) */
if (blr_file_init(inst) == 0) if (blr_file_init(inst) == 0)
{ {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("%s: Service not started due to lack of binlog directory %s",
LOGFILE_ERROR,
"%s: Service not started due to lack of binlog directory %s",
service->name, service->name,
inst->binlogdir))); inst->binlogdir);
if (service->users) { if (service->users) {
users_free(service->users); users_free(service->users);
@ -696,10 +669,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
/* Log whether the transaction safety option value is on*/ /* Log whether the transaction safety option value is on*/
if (inst->trx_safe) { if (inst->trx_safe) {
LOGIF(LT, (skygw_log_write_flush( MXS_INFO("%s: Service has transaction safety option set to ON",
LOGFILE_TRACE, service->name);
"%s: Service has transaction safety option set to ON",
service->name)));
} }
/** /**
@ -707,9 +678,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
*/ */
if (inst->master_state == BLRM_UNCONNECTED) { if (inst->master_state == BLRM_UNCONNECTED) {
/* Check current binlog */ /* Check current binlog */
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("Validating binlog file '%s' ...",
LOGFILE_MESSAGE, "Validating binlog file '%s' ...", inst->binlog_name);
inst->binlog_name)));
if (inst->trx_safe && !blr_check_binlog(inst)) { if (inst->trx_safe && !blr_check_binlog(inst)) {
/* Don't start replication, just return */ /* Don't start replication, just return */
@ -717,15 +687,11 @@ char task_name[BLRM_TASK_NAME_LEN+1] = "";
} }
if (!inst->trx_safe) { if (!inst->trx_safe) {
LOGIF(LT, (skygw_log_write_flush( MXS_INFO("Current binlog file is %s, current pos is %lu\n",
LOGFILE_TRACE, inst->binlog_name, inst->binlog_position);
"Current binlog file is %s, current pos is %lu\n",
inst->binlog_name, inst->binlog_position)));
} else { } else {
LOGIF(LT, (skygw_log_write_flush( MXS_INFO("Current binlog file is %s, safe pos %lu, current pos is %lu\n",
LOGFILE_TRACE, inst->binlog_name, inst->binlog_position, inst->current_pos);
"Current binlog file is %s, safe pos %lu, current pos is %lu\n",
inst->binlog_name, inst->binlog_position, inst->current_pos)));
} }
/* Start replication from master server */ /* Start replication from master server */
@ -752,20 +718,16 @@ newSession(ROUTER *instance, SESSION *session)
ROUTER_INSTANCE *inst = (ROUTER_INSTANCE *)instance; ROUTER_INSTANCE *inst = (ROUTER_INSTANCE *)instance;
ROUTER_SLAVE *slave; ROUTER_SLAVE *slave;
LOGIF(LD, (skygw_log_write_flush( MXS_DEBUG("binlog router: %lu [newSession] new router session with "
LOGFILE_DEBUG,
"binlog router: %lu [newSession] new router session with "
"session %p, and inst %p.", "session %p, and inst %p.",
pthread_self(), pthread_self(),
session, session,
inst))); inst);
if ((slave = (ROUTER_SLAVE *)calloc(1, sizeof(ROUTER_SLAVE))) == NULL) if ((slave = (ROUTER_SLAVE *)calloc(1, sizeof(ROUTER_SLAVE))) == NULL)
{ {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Insufficient memory to create new slave session for binlog router");
LOGFILE_ERROR,
"Insufficient memory to create new slave session for binlog router")));
return NULL; return NULL;
} }
@ -849,14 +811,12 @@ int prev_val;
} }
spinlock_release(&router->lock); spinlock_release(&router->lock);
LOGIF(LD, (skygw_log_write_flush( MXS_DEBUG("%lu [freeSession] Unlinked router_client_session %p from "
LOGFILE_DEBUG,
"%lu [freeSession] Unlinked router_client_session %p from "
"router %p. Connections : %d. ", "router %p. Connections : %d. ",
pthread_self(), pthread_self(),
slave, slave,
router, router,
prev_val-1))); prev_val-1);
if (slave->hostname) if (slave->hostname)
free(slave->hostname); free(slave->hostname);
@ -886,16 +846,12 @@ ROUTER_SLAVE *slave = (ROUTER_SLAVE *)router_session;
/* /*
* We must be closing the master session. * We must be closing the master session.
*/ */
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: Master %s disconnected after %ld seconds. "
LOGFILE_MESSAGE,
"%s: Master %s disconnected after %ld seconds. "
"%lu events read,", "%lu events read,",
router->service->name, router->service->dbref->server->name, router->service->name, router->service->dbref->server->name,
time(0) - router->connect_time, router->stats.n_binlogs_ses))); time(0) - router->connect_time, router->stats.n_binlogs_ses);
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Binlog router close session with master server %s",
LOGFILE_ERROR, router->service->dbref->server->unique_name);
"Binlog router close session with master server %s",
router->service->dbref->server->unique_name)));
blr_master_reconnect(router); blr_master_reconnect(router);
return; return;
} }
@ -910,10 +866,9 @@ ROUTER_SLAVE *slave = (ROUTER_SLAVE *)router_session;
atomic_add(&router->stats.n_registered, -1); atomic_add(&router->stats.n_registered, -1);
if (slave->state > 0) { if (slave->state > 0) {
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: Slave %s, server id %d, disconnected after %ld seconds. "
LOGFILE_MESSAGE, "%d SQL commands, %d events sent (%lu bytes), binlog '%s', "
"%s: Slave %s, server id %d, disconnected after %ld seconds. " "last position %lu",
"%d SQL commands, %d events sent (%lu bytes), binlog '%s', last position %lu",
router->service->name, slave->dcb->remote, router->service->name, slave->dcb->remote,
slave->serverid, slave->serverid,
time(0) - slave->connect_time, time(0) - slave->connect_time,
@ -921,16 +876,14 @@ ROUTER_SLAVE *slave = (ROUTER_SLAVE *)router_session;
slave->stats.n_events, slave->stats.n_events,
slave->stats.n_bytes, slave->stats.n_bytes,
slave->binlogfile, slave->binlogfile,
(unsigned long)slave->binlog_pos))); (unsigned long)slave->binlog_pos);
} else { } else {
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: Slave %s, server id %d, disconnected after %ld seconds. "
LOGFILE_MESSAGE,
"%s: Slave %s, server id %d, disconnected after %ld seconds. "
"%d SQL commands", "%d SQL commands",
router->service->name, slave->dcb->remote, router->service->name, slave->dcb->remote,
slave->serverid, slave->serverid,
time(0) - slave->connect_time, time(0) - slave->connect_time,
slave->stats.n_queries))); slave->stats.n_queries);
} }
/* /*
@ -1440,33 +1393,29 @@ unsigned long mysql_errno;
free(router->m_errmsg); free(router->m_errmsg);
router->m_errmsg = strdup(errmsg); router->m_errmsg = strdup(errmsg);
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', "
LOGFILE_ERROR, "%s: Master connection error %lu '%s' in state '%s', "
"%sattempting reconnect to master %s:%d", "%sattempting reconnect to master %s:%d",
router->service->name, mysql_errno, errmsg, router->service->name, mysql_errno, errmsg,
blrm_states[router->master_state], msg, blrm_states[router->master_state], msg,
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port))); router->service->dbref->server->port);
} else { } else {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', "
LOGFILE_ERROR, "%s: Master connection error %lu '%s' in state '%s', "
"%sattempting reconnect to master %s:%d", "%sattempting reconnect to master %s:%d",
router->service->name, router->m_errno, router->m_errmsg, router->service->name, router->m_errno, router->m_errmsg,
blrm_states[router->master_state], msg, blrm_states[router->master_state], msg,
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port))); router->service->dbref->server->port);
} }
if (errmsg) if (errmsg)
free(errmsg); free(errmsg);
*succp = true; *succp = true;
dcb_close(backend_dcb); dcb_close(backend_dcb);
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: Master %s disconnected after %ld seconds. "
LOGFILE_MESSAGE,
"%s: Master %s disconnected after %ld seconds. "
"%lu events read.", "%lu events read.",
router->service->name, router->service->dbref->server->name, router->service->name, router->service->dbref->server->name,
time(0) - router->connect_time, router->stats.n_binlogs_ses))); time(0) - router->connect_time, router->stats.n_binlogs_ses);
blr_master_reconnect(router); blr_master_reconnect(router);
} }
@ -1734,10 +1683,10 @@ SERVICE *service;
{ {
return blr_handle_config_item(name, value, inst); return blr_handle_config_item(name, value, inst);
} else { } else {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("master.ini has an invalid section [%s], it should be [binlog_configuration]. "
"Error : master.ini has an invalid section [%s], it should be [binlog_configuration]. Service %s", "Service %s",
section, section,
service->name))); service->name);
return 0; return 0;
} }
@ -1796,9 +1745,8 @@ char *service_user = NULL;
char *service_passwd = NULL; char *service_passwd = NULL;
if (serviceGetUser(service, &service_user, &service_passwd) == 0) { if (serviceGetUser(service, &service_user, &service_passwd) == 0) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("failed to get service user details for service %s",
"failed to get service user details for service %s", service->name);
service->name)));
return 1; return 1;
} }
@ -1806,10 +1754,9 @@ char *service_passwd = NULL;
dpwd = decryptPassword(service->credentials.authdata); dpwd = decryptPassword(service->credentials.authdata);
if (!dpwd) { if (!dpwd) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("decrypt password failed for service user %s, service %s",
"decrypt password failed for service user %s, service %s",
service_user, service_user,
service->name))); service->name);
return 1; return 1;
} }
@ -1817,9 +1764,8 @@ char *service_passwd = NULL;
newpasswd = create_hex_sha1_sha1_passwd(dpwd); newpasswd = create_hex_sha1_sha1_passwd(dpwd);
if (!newpasswd) { if (!newpasswd) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("create hex_sha1_sha1_password failed for service user %s",
"create hex_sha1_sha1_password failed for service user %s", service_user);
service_user)));
free(dpwd); free(dpwd);
return 1; return 1;
@ -1859,10 +1805,8 @@ SERVICE *service;
if (loaded < 0) if (loaded < 0)
{ {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Unable to load users for service %s",
LOGFILE_ERROR, service->name);
"Error : Unable to load users for service %s",
service->name)));
/* Try loading authentication data from file cache */ /* Try loading authentication data from file cache */
@ -1870,29 +1814,23 @@ SERVICE *service;
if (loaded != -1) if (loaded != -1)
{ {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Service %s, Using cached credential information file %s.",
LOGFILE_ERROR,
"Service %s, Using cached credential information file %s.",
service->name, service->name,
path))); path);
} else { } else {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Service %s, Unable to read cache credential information from %s."
LOGFILE_ERROR,
"Error: Service %s, Unable to read cache credential information from %s."
" No database user added to service users table.", " No database user added to service users table.",
service->name, service->name,
path))); path);
} }
} else { } else {
/* don't update cache if no user was loaded */ /* don't update cache if no user was loaded */
if (loaded == 0) if (loaded == 0)
{ {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Service %s: failed to load any user "
LOGFILE_ERROR,
"Service %s: failed to load any user "
"information. Authentication will " "information. Authentication will "
"probably fail as a result.", "probably fail as a result.",
service->name))); service->name);
} else { } else {
/* update cached data */ /* update cached data */
blr_save_dbusers(router); blr_save_dbusers(router);
@ -1936,8 +1874,7 @@ int mkdir_rval = 0;
if (mkdir_rval == -1) if (mkdir_rval == -1)
{ {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Service %s, Failed to create directory '%s': [%d] %s",
"Error : Service %s, Failed to create directory '%s': [%d] %s",
service->name, service->name,
path, path,
errno, errno,
@ -1999,9 +1936,7 @@ static int blr_check_binlog(ROUTER_INSTANCE *router) {
n = blr_read_events_all_events(router, 0, 0); n = blr_read_events_all_events(router, 0, 0);
LOGIF(LD, (skygw_log_write_flush( MXS_DEBUG("blr_read_events_all_events() ret = %i\n", n);
LOGFILE_DEBUG,
"blr_read_events_all_events() ret = %i\n", n)));
if (n != 0) { if (n != 0) {
char msg_err[BINLOG_ERROR_MSG_LEN + 1] = ""; char msg_err[BINLOG_ERROR_MSG_LEN + 1] = "";
@ -2017,11 +1952,9 @@ static int blr_check_binlog(ROUTER_INSTANCE *router) {
/* set last_safe_pos */ /* set last_safe_pos */
router->last_safe_pos = router->binlog_position; router->last_safe_pos = router->binlog_position;
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Error found in binlog file %s. Safe starting pos is %lu",
LOGFILE_ERROR,
"Error found in binlog file %s. Safe starting pos is %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
return 0; return 0;
} else { } else {

306
server/modules/routing/binlog/blr_file.c
View File

@ -65,7 +65,7 @@
static int blr_file_create(ROUTER_INSTANCE *router, char *file); static int blr_file_create(ROUTER_INSTANCE *router, char *file);
static void blr_file_append(ROUTER_INSTANCE *router, char *file); static void blr_file_append(ROUTER_INSTANCE *router, char *file);
static void blr_log_header(logfile_id_t file, char *msg, uint8_t *ptr); static void blr_log_header(int priority, char *msg, uint8_t *ptr);
void blr_cache_read_master_data(ROUTER_INSTANCE *router); void blr_cache_read_master_data(ROUTER_INSTANCE *router);
int blr_file_get_next_binlogname(ROUTER_INSTANCE *router); int blr_file_get_next_binlogname(ROUTER_INSTANCE *router);
int blr_file_new_binlog(ROUTER_INSTANCE *router, char *file); int blr_file_new_binlog(ROUTER_INSTANCE *router, char *file);
@ -120,9 +120,8 @@ struct dirent *dp;
} }
if (access(router->binlogdir, R_OK) == -1) if (access(router->binlogdir, R_OK) == -1)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Unable to read the binlog directory %s.",
"%s: Unable to read the binlog directory %s.", router->service->name, router->binlogdir);
router->service->name, router->binlogdir)));
return 0; return 0;
} }
@ -131,10 +130,9 @@ struct dirent *dp;
if ((dirp = opendir(path)) == NULL) if ((dirp = opendir(path)) == NULL)
{ {
char err_msg[BLRM_STRERROR_R_MSG_SIZE]; char err_msg[BLRM_STRERROR_R_MSG_SIZE];
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Unable to read the binlog directory %s, %s.",
"%s: Unable to read the binlog directory %s, %s.",
router->service->name, router->binlogdir, router->service->name, router->binlogdir,
strerror_r(errno, err_msg, sizeof(err_msg))))); strerror_r(errno, err_msg, sizeof(err_msg)));
return 0; return 0;
} }
while ((dp = readdir(dirp)) != NULL) while ((dp = readdir(dirp)) != NULL)
@ -232,9 +230,8 @@ int fd;
{ {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Failed to create binlog file %s, %s.",
"%s: Failed to create binlog file %s, %s.", router->service->name, path, strerror_r(errno, err_msg, sizeof(err_msg)));
router->service->name, path, strerror_r(errno, err_msg, sizeof(err_msg)))));
return 0; return 0;
} }
fsync(fd); fsync(fd);
@ -264,9 +261,8 @@ int fd;
if ((fd = open(path, O_RDWR|O_APPEND, 0666)) == -1) if ((fd = open(path, O_RDWR|O_APPEND, 0666)) == -1)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Failed to open binlog file %s for append.",
"Failed to open binlog file %s for append.", path);
path)));
return; return;
} }
fsync(fd); fsync(fd);
@ -280,9 +276,8 @@ int fd;
} else { } else {
/* If for any reason the file's length is between 1 and 3 bytes /* If for any reason the file's length is between 1 and 3 bytes
* then report an error. */ * then report an error. */
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: binlog file %s has an invalid length %lu.",
"%s: binlog file %s has an invalid length %lu.", router->service->name, path, router->current_pos);
router->service->name, path, router->current_pos)));
close(fd); close(fd);
spinlock_release(&router->binlog_lock); spinlock_release(&router->binlog_lock);
return; return;
@ -309,12 +304,11 @@ int n;
hdr->next_pos - hdr->event_size)) != hdr->event_size) hdr->next_pos - hdr->event_size)) != hdr->event_size)
{ {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Failed to write binlog record at %d of %s, %s. "
"%s: Failed to write binlog record at %d of %s, %s. "
"Truncating to previous record.", "Truncating to previous record.",
router->service->name, hdr->next_pos - hdr->event_size, router->service->name, hdr->next_pos - hdr->event_size,
router->binlog_name, router->binlog_name,
strerror_r(errno, err_msg, sizeof(err_msg))))); strerror_r(errno, err_msg, sizeof(err_msg)));
/* Remove any partual event that was written */ /* Remove any partual event that was written */
ftruncate(router->binlog_fd, hdr->next_pos - hdr->event_size); ftruncate(router->binlog_fd, hdr->next_pos - hdr->event_size);
return 0; return 0;
@ -378,8 +372,7 @@ BLFILE *file;
if ((file->fd = open(path, O_RDONLY, 0666)) == -1) if ((file->fd = open(path, O_RDONLY, 0666)) == -1)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Failed to open binlog file %s", path);
"Failed to open binlog file %s", path)));
free(file); free(file);
spinlock_release(&router->fileslock); spinlock_release(&router->fileslock);
return NULL; return NULL;
@ -458,9 +451,8 @@ struct stat statb;
switch (n) switch (n)
{ {
case 0: case 0:
LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, MXS_DEBUG("Reached end of binlog file '%s' at %lu.",
"Reached end of binlog file '%s' at %lu.", file->binlogname, pos);
file->binlogname, pos)));
/* set ok indicator */ /* set ok indicator */
hdr->ok = SLAVE_POS_READ_OK; hdr->ok = SLAVE_POS_READ_OK;
@ -514,21 +506,19 @@ struct stat statb;
if (hdr->next_pos < pos && hdr->event_type != ROTATE_EVENT) if (hdr->next_pos < pos && hdr->event_type != ROTATE_EVENT)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Next position in header appears to be incorrect "
"Next position in header appears to be incorrect "
"rereading event header at pos %lu in file %s, " "rereading event header at pos %lu in file %s, "
"file size is %lu. Master will write %lu in %s next.", "file size is %lu. Master will write %lu in %s next.",
pos, file->binlogname, filelen, router->binlog_position, pos, file->binlogname, filelen, router->binlog_position,
router->binlog_name))); router->binlog_name);
if ((n = pread(file->fd, hdbuf, BINLOG_EVENT_HDR_LEN, pos)) != BINLOG_EVENT_HDR_LEN) if ((n = pread(file->fd, hdbuf, BINLOG_EVENT_HDR_LEN, pos)) != BINLOG_EVENT_HDR_LEN)
{ {
switch (n) switch (n)
{ {
case 0: case 0:
LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, MXS_DEBUG("Reached end of binlog file at %lu.",
"Reached end of binlog file at %lu.", pos);
pos)));
/* set ok indicator */ /* set ok indicator */
hdr->ok = SLAVE_POS_READ_OK; hdr->ok = SLAVE_POS_READ_OK;
@ -570,9 +560,8 @@ struct stat statb;
} }
else else
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Next position corrected by "
"Next position corrected by " "rereading");
"rereading")));
} }
} }
if ((result = gwbuf_alloc(hdr->event_size)) == NULL) if ((result = gwbuf_alloc(hdr->event_size)) == NULL)
@ -608,7 +597,7 @@ struct stat statb;
"current file size is %lu, event at %lu in binlog file '%s'", "current file size is %lu, event at %lu in binlog file '%s'",
filelen, pos, file->binlogname); filelen, pos, file->binlogname);
} }
blr_log_header(LOGFILE_ERROR, "Possible malformed event header", hdbuf); blr_log_header(LOG_ERR, "Possible malformed event header", hdbuf);
} }
gwbuf_free(result); gwbuf_free(result);
@ -667,12 +656,12 @@ blr_close_binlog(ROUTER_INSTANCE *router, BLFILE *file)
/** /**
* Log the event header of binlog event * Log the event header of binlog event
* *
* @param file The log file into which to write the entry * @param priority The syslog priority of the message (LOG_ERR, LOG_WARNING, etc.)
* @param msg A message strign to preceed the header with * @param msg A message strign to preceed the header with
* @param ptr The event header raw data * @param ptr The event header raw data
*/ */
static void static void
blr_log_header(logfile_id_t file, char *msg, uint8_t *ptr) blr_log_header(int priority, char *msg, uint8_t *ptr)
{ {
char buf[400], *bufp; char buf[400], *bufp;
int i; int i;
@ -681,8 +670,7 @@ int i;
bufp += sprintf(bufp, "%s: ", msg); bufp += sprintf(bufp, "%s: ", msg);
for (i = 0; i < BINLOG_EVENT_HDR_LEN; i++) for (i = 0; i < BINLOG_EVENT_HDR_LEN; i++)
bufp += sprintf(bufp, "0x%02x ", ptr[i]); bufp += sprintf(bufp, "0x%02x ", ptr[i]);
skygw_log_write_flush(file, "%s", buf); MXS_LOG_MESSAGE(priority, "%s", buf);
} }
/** /**
@ -852,9 +840,8 @@ int fde_seen = 0;
memset(&fde_event, '\0', sizeof(fde_event)); memset(&fde_event, '\0', sizeof(fde_event));
if (router->binlog_fd == -1) { if (router->binlog_fd == -1) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Current binlog file %s is not open",
"ERROR: Current binlog file %s is not open", router->binlog_name);
router->binlog_name)));
return 1; return 1;
} }
@ -872,10 +859,9 @@ int fde_seen = 0;
switch (n) switch (n)
{ {
case 0: case 0:
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG("End of binlog file [%s] at %llu.",
"End of binlog file [%s] at %llu.",
router->binlog_name, router->binlog_name,
pos))); pos);
if (n_transactions) if (n_transactions)
average_events = (double)((double)total_events / (double)n_transactions) * (1.0); average_events = (double)((double)total_events / (double)n_transactions) * (1.0);
if (n_transactions) if (n_transactions)
@ -901,24 +887,25 @@ int fde_seen = 0;
blr_format_event_size(&average_bytes, average_label); blr_format_event_size(&average_bytes, average_label);
blr_format_event_size(&format_max_bytes, max_label); blr_format_event_size(&format_max_bytes, max_label);
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Transaction Summary for binlog '%s'\n"
"Transaction Summary for binlog '%s'\n"
"\t\t\tDescription %17s%17s%17s\n\t\t\t" "\t\t\tDescription %17s%17s%17s\n\t\t\t"
"No. of Transactions %16lu\n\t\t\t" "No. of Transactions %16lu\n\t\t\t"
"No. of Events %16lu %16.1f %16lu\n\t\t\t" "No. of Events %16lu %16.1f %16lu\n\t\t\t"
"No. of Bytes %16.1f%s%16.1f%s%16.1f%s", router->binlog_name, "No. of Bytes %16.1f%s%16.1f%s%16.1f%s",
router->binlog_name,
"Total", "Average", "Max", "Total", "Average", "Max",
n_transactions, total_events, n_transactions, total_events,
average_events, max_events, average_events, max_events,
format_total_bytes, total_label, average_bytes, average_label, format_max_bytes, max_label))); format_total_bytes, total_label,
average_bytes, average_label,
format_max_bytes, max_label);
} }
if (pending_transaction) { if (pending_transaction) {
LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, MXS_WARNING("Binlog file %s contains a previous Opened "
"Warning : Binlog file %s contains a previous Opened Transaction" "Transaction @ %llu. This pos is safe for slaves",
" @ %llu. This pos is safe for slaves",
router->binlog_name, router->binlog_name,
last_known_commit))); last_known_commit);
} }
@ -927,24 +914,21 @@ int fde_seen = 0;
{ {
char err_msg[BLRM_STRERROR_R_MSG_SIZE+1] = ""; char err_msg[BLRM_STRERROR_R_MSG_SIZE+1] = "";
strerror_r(errno, err_msg, BLRM_STRERROR_R_MSG_SIZE); strerror_r(errno, err_msg, BLRM_STRERROR_R_MSG_SIZE);
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Failed to read binlog file %s at position %llu"
"ERROR: Failed to read binlog file %s at position %llu"
" (%s).", router->binlog_name, " (%s).", router->binlog_name,
pos, err_msg))); pos, err_msg);
if (errno == EBADF) if (errno == EBADF)
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Bad file descriptor in read binlog for file %s"
"ERROR: Bad file descriptor in read binlog for file %s"
", descriptor %d.", ", descriptor %d.",
router->binlog_name, router->binlog_fd))); router->binlog_name, router->binlog_fd);
break; break;
} }
default: default:
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Short read when reading the header. "
"ERROR: Short read when reading the header. "
"Expected 19 bytes but got %d bytes. " "Expected 19 bytes but got %d bytes. "
"Binlog file is %s, position %llu", "Binlog file is %s, position %llu",
n, router->binlog_name, pos))); n, router->binlog_name, pos);
break; break;
} }
@ -960,10 +944,9 @@ int fde_seen = 0;
router->pending_transaction = 1; router->pending_transaction = 1;
pending_transaction = 0; pending_transaction = 0;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("pending transaction has been found. "
"Warning : pending transaction has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
return 0; return 0;
} else { } else {
@ -973,16 +956,14 @@ int fde_seen = 0;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1010,21 +991,19 @@ int fde_seen = 0;
if (router->mariadb10_compat) { if (router->mariadb10_compat) {
if (hdr.event_type > MAX_EVENT_TYPE_MARIADB10) { if (hdr.event_type > MAX_EVENT_TYPE_MARIADB10) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Invalid MariaDB 10 event type 0x%x. "
"Invalid MariaDB 10 event type 0x%x. "
"Binlog file is %s, position %llu", "Binlog file is %s, position %llu",
hdr.event_type, hdr.event_type,
router->binlog_name, pos))); router->binlog_name, pos);
event_error = 1; event_error = 1;
} }
} else { } else {
if (hdr.event_type > MAX_EVENT_TYPE) { if (hdr.event_type > MAX_EVENT_TYPE) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Invalid event type 0x%x. "
"Invalid event type 0x%x. "
"Binlog file is %s, position %llu", "Binlog file is %s, position %llu",
hdr.event_type, hdr.event_type,
router->binlog_name, pos))); router->binlog_name, pos);
event_error = 1; event_error = 1;
} }
@ -1036,19 +1015,17 @@ int fde_seen = 0;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found in %s. "
"warning : an error has been found in %s. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_name, router->binlog_name,
router->binlog_position, router->binlog_position,
router->current_pos))); router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1058,25 +1035,22 @@ int fde_seen = 0;
if (hdr.event_size <= 0) if (hdr.event_size <= 0)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Event size error: "
"Event size error: "
"size %d at %llu.", "size %d at %llu.",
hdr.event_size, pos))); hdr.event_size, pos);
router->binlog_position = last_known_commit; router->binlog_position = last_known_commit;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1087,26 +1061,23 @@ int fde_seen = 0;
/* Allocate a GWBUF for the event */ /* Allocate a GWBUF for the event */
if ((result = gwbuf_alloc(hdr.event_size)) == NULL) if ((result = gwbuf_alloc(hdr.event_size)) == NULL)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Failed to allocate memory for binlog entry, "
"ERROR: Failed to allocate memory for binlog entry, "
"size %d at %llu.", "size %d at %llu.",
hdr.event_size, pos))); hdr.event_size, pos);
router->binlog_position = last_known_commit; router->binlog_position = last_known_commit;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1125,25 +1096,23 @@ int fde_seen = 0;
{ {
char err_msg[BLRM_STRERROR_R_MSG_SIZE+1] = ""; char err_msg[BLRM_STRERROR_R_MSG_SIZE+1] = "";
strerror_r(errno, err_msg, BLRM_STRERROR_R_MSG_SIZE); strerror_r(errno, err_msg, BLRM_STRERROR_R_MSG_SIZE);
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Error reading the event at %llu in %s. "
"Error reading the event at %llu in %s. "
"%s, expected %d bytes.", "%s, expected %d bytes.",
pos, router->binlog_name, pos, router->binlog_name,
err_msg, hdr.event_size - BINLOG_EVENT_HDR_LEN))); err_msg, hdr.event_size - BINLOG_EVENT_HDR_LEN);
} }
else else
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Short read when reading the event at %llu in %s. "
"Short read when reading the event at %llu in %s. "
"Expected %d bytes got %d bytes.", "Expected %d bytes got %d bytes.",
pos, router->binlog_name, hdr.event_size - BINLOG_EVENT_HDR_LEN, n))); pos, router->binlog_name,
hdr.event_size - BINLOG_EVENT_HDR_LEN, n);
if (filelen > 0 && filelen - pos < hdr.event_size) if (filelen > 0 && filelen - pos < hdr.event_size)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Binlog event is close to the end of the binlog file %s, "
"Binlog event is close to the end of the binlog file %s, "
" size is %lu.", " size is %lu.",
router->binlog_name, filelen))); router->binlog_name, filelen);
} }
} }
@ -1153,16 +1122,14 @@ int fde_seen = 0;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1209,9 +1176,8 @@ int fde_seen = 0;
} }
if(debug) if(debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG("- Format Description event FDE @ %llu, size %lu, time %lu (%s)",
"- Format Description event FDE @ %llu, size %lu, time %lu (%s)", pos, (unsigned long)hdr.event_size, fde_event.event_time, buf_t);
pos, (unsigned long)hdr.event_size, fde_event.event_time, buf_t)));
event_header_length = ptr[2 + 50 + 4]; event_header_length = ptr[2 + 50 + 4];
event_header_ntypes = hdr.event_size - event_header_length - (2 + 50 + 4 + 1); event_header_ntypes = hdr.event_size - event_header_length - (2 + 50 + 4 + 1);
@ -1232,14 +1198,12 @@ int fde_seen = 0;
n_events = hdr.event_size - event_header_length - (2 + 50 + 4 + 1); n_events = hdr.event_size - event_header_length - (2 + 50 + 4 + 1);
if(debug) { if(debug) {
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG(" FDE ServerVersion [%50s]", ptr + 2);
" FDE ServerVersion [%50s]", ptr + 2)));
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG(" FDE Header EventLength %i"
" FDE Header EventLength %i"
", N. of supported MySQL/MariaDB events %i", ", N. of supported MySQL/MariaDB events %i",
event_header_length, event_header_length,
(n_events - event_header_ntypes)))); (n_events - event_header_ntypes));
} }
if (event_header_ntypes < n_events) { if (event_header_ntypes < n_events) {
@ -1247,10 +1211,10 @@ int fde_seen = 0;
check_alg = checksum[0]; check_alg = checksum[0];
if(debug) if(debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG(" FDE Checksum alg desc %i, alg type %s",
" FDE Checksum alg desc %i, alg type %s",
check_alg, check_alg,
check_alg == 1 ? "BINLOG_CHECKSUM_ALG_CRC32" : "NONE or UNDEF"))); check_alg == 1 ?
"BINLOG_CHECKSUM_ALG_CRC32" : "NONE or UNDEF");
if (check_alg == 1) { if (check_alg == 1) {
found_chksum = 1; found_chksum = 1;
} else { } else {
@ -1283,9 +1247,8 @@ int fde_seen = 0;
file[slen] = 0; file[slen] = 0;
if(debug) if(debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG("- Rotate event @ %llu, next file is [%s] @ %lu",
"- Rotate event @ %llu, next file is [%s] @ %lu", pos, file, new_pos);
pos, file, new_pos)));
} }
/* If MariaDB 10 compatibility: /* If MariaDB 10 compatibility:
@ -1305,11 +1268,11 @@ int fde_seen = 0;
if (flags == 0) { if (flags == 0) {
if (pending_transaction > 0) { if (pending_transaction > 0) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Transaction cannot be @ pos %llu: "
"ERROR: Transaction cannot be @ pos %llu: "
"Another MariaDB 10 transaction (GTID %u-%u-%lu)" "Another MariaDB 10 transaction (GTID %u-%u-%lu)"
" was opened at %llu", " was opened at %llu",
pos, domainid, hdr.serverid, n_sequence, last_known_commit))); pos, domainid, hdr.serverid,
n_sequence, last_known_commit);
gwbuf_free(result); gwbuf_free(result);
@ -1321,10 +1284,9 @@ int fde_seen = 0;
event_bytes = 0; event_bytes = 0;
if (debug) if (debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG("> MariaDB 10 Transaction (GTID %u-%u-%lu)"
"> MariaDB 10 Transaction (GTID %u-%u-%lu)"
" starts @ pos %llu", " starts @ pos %llu",
domainid, hdr.serverid, n_sequence, pos))); domainid, hdr.serverid, n_sequence, pos);
} }
} }
} }
@ -1350,10 +1312,9 @@ int fde_seen = 0;
/* A transaction starts with this event */ /* A transaction starts with this event */
if (strncmp(statement_sql, "BEGIN", 5) == 0) { if (strncmp(statement_sql, "BEGIN", 5) == 0) {
if (pending_transaction > 0) { if (pending_transaction > 0) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Transaction cannot be @ pos %llu: "
"ERROR: Transaction cannot be @ pos %llu: "
"Another transaction was opened at %llu", "Another transaction was opened at %llu",
pos, last_known_commit))); pos, last_known_commit);
free(statement_sql); free(statement_sql);
gwbuf_free(result); gwbuf_free(result);
@ -1366,8 +1327,7 @@ int fde_seen = 0;
event_bytes = 0; event_bytes = 0;
if (debug) if (debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG("> Transaction starts @ pos %llu", pos);
"> Transaction starts @ pos %llu", pos)));
} }
} }
@ -1377,8 +1337,8 @@ int fde_seen = 0;
pending_transaction = 3; pending_transaction = 3;
if (debug) if (debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG(" Transaction @ pos %llu, closing @ %llu",
" Transaction @ pos %llu, closing @ %llu", last_known_commit, pos))); last_known_commit, pos);
} }
} }
free(statement_sql); free(statement_sql);
@ -1391,15 +1351,15 @@ int fde_seen = 0;
if (pending_transaction > 0) { if (pending_transaction > 0) {
pending_transaction = 2; pending_transaction = 2;
if (debug) if (debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG(" Transaction XID @ pos %llu, closing @ %llu",
" Transaction XID @ pos %llu, closing @ %llu", last_known_commit, pos))); last_known_commit, pos);
} }
} }
if (pending_transaction > 1) { if (pending_transaction > 1) {
if (debug) if (debug)
LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, MXS_DEBUG("< Transaction @ pos %llu, is now closed @ %llu. %lu events seen",
"< Transaction @ pos %llu, is now closed @ %llu. %lu events seen", last_known_commit, pos, transaction_events))); last_known_commit, pos, transaction_events);
pending_transaction = 0; pending_transaction = 0;
last_known_commit = pos; last_known_commit = pos;
@ -1415,27 +1375,24 @@ int fde_seen = 0;
/* pos and next_pos sanity checks */ /* pos and next_pos sanity checks */
if (hdr.next_pos > 0 && hdr.next_pos < pos) { if (hdr.next_pos > 0 && hdr.next_pos < pos) {
LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, MXS_INFO("Binlog %s: next pos %u < pos %llu, truncating to %llu",
"Binlog %s: next pos %u < pos %llu, truncating to %llu",
router->binlog_name, router->binlog_name,
hdr.next_pos, hdr.next_pos,
pos, pos,
pos))); pos);
router->binlog_position = last_known_commit; router->binlog_position = last_known_commit;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1444,29 +1401,26 @@ int fde_seen = 0;
} }
if (hdr.next_pos > 0 && hdr.next_pos != (pos + hdr.event_size)) { if (hdr.next_pos > 0 && hdr.next_pos != (pos + hdr.event_size)) {
LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, MXS_INFO("Binlog %s: next pos %u != (pos %llu + event_size %u), truncating to %llu",
"Binlog %s: next pos %u != (pos %llu + event_size %u), truncating to %llu",
router->binlog_name, router->binlog_name,
hdr.next_pos, hdr.next_pos,
pos, pos,
hdr.event_size, hdr.event_size,
pos))); pos);
router->binlog_position = last_known_commit; router->binlog_position = last_known_commit;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
if (fix) { if (fix) {
if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Binlog file %s has been truncated at %lu",
"Binlog file %s has been truncated at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position))); router->binlog_position);
fsync(router->binlog_fd); fsync(router->binlog_fd);
} }
} }
@ -1488,8 +1442,8 @@ int fde_seen = 0;
pos = hdr.next_pos; pos = hdr.next_pos;
} else { } else {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Current event type %d @ %llu has nex pos = %u : exiting",
"Current event type %d @ %llu has nex pos = %u : exiting", hdr.event_type, pos, hdr.next_pos))); hdr.event_type, pos, hdr.next_pos);
break; break;
} }
@ -1497,20 +1451,18 @@ int fde_seen = 0;
} }
if (pending_transaction) { if (pending_transaction) {
LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, MXS_INFO("Binlog %s contains an Open Transaction, truncating to %llu",
"Binlog %s contains an Open Transaction, truncating to %llu",
router->binlog_name, router->binlog_name,
last_known_commit))); last_known_commit);
router->binlog_position = last_known_commit; router->binlog_position = last_known_commit;
router->current_safe_event = last_known_commit; router->current_safe_event = last_known_commit;
router->current_pos = pos; router->current_pos = pos;
router->pending_transaction = 1; router->pending_transaction = 1;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_WARNING("an error has been found. "
"warning : an error has been found. "
"Setting safe pos to %lu, current pos %lu", "Setting safe pos to %lu, current pos %lu",
router->binlog_position, router->current_pos))); router->binlog_position, router->current_pos);
return 0; return 0;
} else { } else {
@ -1707,10 +1659,9 @@ char *event_desc;
event_desc = blr_get_event_description(router, first_event.event_type); event_desc = blr_get_event_description(router, first_event.event_type);
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("%lu @ %llu, %s, (%s), First EventTime",
"%lu @ %llu, %s, (%s), First EventTime",
first_event.event_time, first_event.event_pos, first_event.event_time, first_event.event_pos,
event_desc != NULL ? event_desc : "unknown", buf_t))); event_desc != NULL ? event_desc : "unknown", buf_t);
/* Last Event */ /* Last Event */
localtime_r(&last_event.event_time, &tm_t); localtime_r(&last_event.event_time, &tm_t);
@ -1722,9 +1673,8 @@ char *event_desc;
event_desc = blr_get_event_description(router, last_event.event_type); event_desc = blr_get_event_description(router, last_event.event_type);
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("%lu @ %llu, %s, (%s), Last EventTime",
"%lu @ %llu, %s, (%s), Last EventTime",
last_event.event_time, last_event.event_pos, last_event.event_time, last_event.event_pos,
event_desc != NULL ? event_desc : "unknown", buf_t))); event_desc != NULL ? event_desc : "unknown", buf_t);
} }

254
server/modules/routing/binlog/blr_master.c
View File

@ -87,7 +87,7 @@ static int blr_rotate_event(ROUTER_INSTANCE *router, uint8_t *pkt, REP_HEADER *
void blr_distribute_binlog_record(ROUTER_INSTANCE *router, REP_HEADER *hdr, uint8_t *ptr); void blr_distribute_binlog_record(ROUTER_INSTANCE *router, REP_HEADER *hdr, uint8_t *ptr);
static void *CreateMySQLAuthData(char *username, char *password, char *database); static void *CreateMySQLAuthData(char *username, char *password, char *database);
void blr_extract_header(uint8_t *pkt, REP_HEADER *hdr); void blr_extract_header(uint8_t *pkt, REP_HEADER *hdr);
static void blr_log_packet(logfile_id_t file, char *msg, uint8_t *ptr, int len); static void blr_log_packet(int priority, char *msg, uint8_t *ptr, int len);
void blr_master_close(ROUTER_INSTANCE *); void blr_master_close(ROUTER_INSTANCE *);
char *blr_extract_column(GWBUF *buf, int col); char *blr_extract_column(GWBUF *buf, int col);
void blr_cache_response(ROUTER_INSTANCE *router, char *response, GWBUF *buf); void blr_cache_response(ROUTER_INSTANCE *router, char *response, GWBUF *buf);
@ -119,13 +119,11 @@ DCB *client;
if (router->master_state != BLRM_UNCONNECTED) if (router->master_state != BLRM_UNCONNECTED)
{ {
if (router->master_state != BLRM_SLAVE_STOPPED) { if (router->master_state != BLRM_SLAVE_STOPPED) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("%s: Master Connect: Unexpected master state %s\n",
"%s: Master Connect: Unexpected master state %s\n", router->service->name, blrm_states[router->master_state]);
router->service->name, blrm_states[router->master_state])));
} else { } else {
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("%s: Master Connect: binlog state is %s\n",
"%s: Master Connect: binlog state is %s\n", router->service->name, blrm_states[router->master_state]);
router->service->name, blrm_states[router->master_state])));
} }
spinlock_release(&router->lock); spinlock_release(&router->lock);
return; return;
@ -142,8 +140,7 @@ DCB *client;
spinlock_release(&router->lock); spinlock_release(&router->lock);
if ((client = dcb_alloc(DCB_ROLE_INTERNAL)) == NULL) if ((client = dcb_alloc(DCB_ROLE_INTERNAL)) == NULL)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Binlog router: failed to create DCB for dummy client");
"Binlog router: failed to create DCB for dummy client")));
return; return;
} }
router->client = client; router->client = client;
@ -151,8 +148,7 @@ DCB *client;
client->data = CreateMySQLAuthData(router->user, router->password, ""); client->data = CreateMySQLAuthData(router->user, router->password, "");
if ((router->session = session_alloc(router->service, client)) == NULL) if ((router->session = session_alloc(router->service, client)) == NULL)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Binlog router: failed to create session for connection to master");
"Binlog router: failed to create session for connection to master")));
return; return;
} }
client->session = router->session; client->session = router->session;
@ -169,17 +165,15 @@ DCB *client;
} }
if (router->retry_backoff > BLR_MAX_BACKOFF) if (router->retry_backoff > BLR_MAX_BACKOFF)
router->retry_backoff = BLR_MAX_BACKOFF; router->retry_backoff = BLR_MAX_BACKOFF;
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Binlog router: failed to connect to master server '%s'",
"Binlog router: failed to connect to master server '%s'", router->service->dbref->server->unique_name);
router->service->dbref->server->unique_name)));
return; return;
} }
router->master->remote = strdup(router->service->dbref->server->name); router->master->remote = strdup(router->service->dbref->server->name);
LOGIF(LM,(skygw_log_write( MXS_NOTICE("%s: attempting to connect to master server %s:%d, binlog %s, pos %lu",
LOGFILE_MESSAGE, router->service->name, router->service->dbref->server->name,
"%s: attempting to connect to master server %s:%d, binlog %s, pos %lu", router->service->dbref->server->port, router->binlog_name, router->current_pos);
router->service->name, router->service->dbref->server->name, router->service->dbref->server->port, router->binlog_name, router->current_pos)));
router->connect_time = time(0); router->connect_time = time(0);
@ -339,10 +333,8 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = "";
spinlock_release(&router->lock); spinlock_release(&router->lock);
if (router->master_state < 0 || router->master_state > BLRM_MAXSTATE) if (router->master_state < 0 || router->master_state > BLRM_MAXSTATE)
{ {
LOGIF(LE, (skygw_log_write( MXS_ERROR("Invalid master state machine state (%d) for binlog router.",
LOGFILE_ERROR, router->master_state);
"Invalid master state machine state (%d) for binlog router.",
router->master_state)));
gwbuf_consume(buf, gwbuf_length(buf)); gwbuf_consume(buf, gwbuf_length(buf));
spinlock_acquire(&router->lock); spinlock_acquire(&router->lock);
@ -351,12 +343,9 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = "";
router->active_logs = 0; router->active_logs = 0;
spinlock_release(&router->lock); spinlock_release(&router->lock);
atomic_add(&router->handling_threads, -1); atomic_add(&router->handling_threads, -1);
LOGIF(LE, (skygw_log_write( MXS_ERROR("%s: Pending reconnect in state %s.",
LOGFILE_ERROR,
"%s: Pending reconnect in state %s.",
router->service->name, router->service->name,
blrm_states[router->master_state] blrm_states[router->master_state]);
)));
blr_restart_master(router); blr_restart_master(router);
return; return;
} }
@ -374,10 +363,8 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = "";
* continue. The error is saved and replayed to slaves if * continue. The error is saved and replayed to slaves if
* they also request the GTID mode. * they also request the GTID mode.
*/ */
LOGIF(LE, (skygw_log_write( MXS_ERROR("%s: Master server does not support GTID Mode.",
LOGFILE_ERROR, router->service->name);
"%s: Master server does not support GTID Mode.",
router->service->name)));
} }
else if (router->master_state != BLRM_BINLOGDUMP && MYSQL_RESPONSE_ERR(buf)) else if (router->master_state != BLRM_BINLOGDUMP && MYSQL_RESPONSE_ERR(buf))
{ {
@ -395,14 +382,11 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = "";
/* NULL terminated error string */ /* NULL terminated error string */
*(msg_err+msg_len)='\0'; *(msg_err+msg_len)='\0';
LOGIF(LE, (skygw_log_write( MXS_ERROR("%s: Received error: %lu, '%s' from master during '%s' phase "
LOGFILE_ERROR,
"%s: Received error: %lu, '%s' from master during '%s' phase "
"of the master state machine.", "of the master state machine.",
router->service->name, router->service->name,
mysql_errno, msg_err, mysql_errno, msg_err,
blrm_states[router->master_state] blrm_states[router->master_state]);
)));
gwbuf_consume(buf, gwbuf_length(buf)); gwbuf_consume(buf, gwbuf_length(buf));
spinlock_acquire(&router->lock); spinlock_acquire(&router->lock);
@ -643,14 +627,12 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = "";
buf = blr_make_binlog_dump(router); buf = blr_make_binlog_dump(router);
router->master_state = BLRM_BINLOGDUMP; router->master_state = BLRM_BINLOGDUMP;
router->master->func.write(router->master, buf); router->master->func.write(router->master, buf);
LOGIF(LM,(skygw_log_write( MXS_NOTICE("%s: Request binlog records from %s at "
LOGFILE_MESSAGE,
"%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->service->name, router->binlog_name,
router->current_pos, router->current_pos,
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port))); router->service->dbref->server->port);
/* Log binlog router identity */ /* Log binlog router identity */
blr_log_identity(router); blr_log_identity(router);
@ -867,12 +849,10 @@ int n_bufs = -1, pn_bufs = -1;
if ((msg = malloc(len)) == NULL) if ((msg = malloc(len)) == NULL)
{ {
LOGIF(LE,(skygw_log_write( MXS_ERROR("Insufficient memory to buffer event "
LOGFILE_ERROR,
"Insufficient memory to buffer event "
"of %d bytes. Binlog %s @ %lu.", "of %d bytes. Binlog %s @ %lu.",
len, router->binlog_name, len, router->binlog_name,
router->current_pos))); router->current_pos);
break; break;
} }
@ -891,13 +871,11 @@ int n_bufs = -1, pn_bufs = -1;
} }
if (remainder) if (remainder)
{ {
LOGIF(LE,(skygw_log_write( MXS_ERROR("Expected entire message in buffer "
LOGFILE_ERROR,
"Expected entire message in buffer "
"chain, but failed to create complete " "chain, but failed to create complete "
"message as expected. %s @ %lu", "message as expected. %s @ %lu",
router->binlog_name, router->binlog_name,
router->current_pos))); router->current_pos);
free(msg); free(msg);
msg = NULL; msg = NULL;
break; break;
@ -914,11 +892,9 @@ int n_bufs = -1, pn_bufs = -1;
* until we receive the next buffer. * until we receive the next buffer.
*/ */
router->stats.n_residuals++; router->stats.n_residuals++;
LOGIF(LD,(skygw_log_write( MXS_DEBUG("Residual data left after %lu records. %s @ %lu",
LOGFILE_DEBUG,
"Residual data left after %lu records. %s @ %lu",
router->stats.n_binlogs, router->stats.n_binlogs,
router->binlog_name, router->current_pos))); router->binlog_name, router->current_pos);
break; break;
} }
else else
@ -949,10 +925,7 @@ int n_bufs = -1, pn_bufs = -1;
{ {
msg = "error"; msg = "error";
} }
LOGIF(LM,(skygw_log_write( MXS_NOTICE("Non-event message (%s) from master.", msg);
LOGFILE_MESSAGE,
"Non-event message (%s) from master.",
msg)));
} }
else else
{ {
@ -964,9 +937,7 @@ int n_bufs = -1, pn_bufs = -1;
/* Sanity check */ /* Sanity check */
if (hdr.ok == 0 && hdr.event_size != len - 5) if (hdr.ok == 0 && hdr.event_size != len - 5)
{ {
LOGIF(LE,(skygw_log_write( MXS_ERROR("Packet length is %d, but event size is %d, "
LOGFILE_ERROR,
"Packet length is %d, but event size is %d, "
"binlog file %s position %lu " "binlog file %s position %lu "
"reslen is %d and preslen is %d, " "reslen is %d and preslen is %d, "
"length of previous event %d. %s", "length of previous event %d. %s",
@ -975,14 +946,13 @@ int n_bufs = -1, pn_bufs = -1;
router->current_pos, router->current_pos,
reslen, preslen, prev_length, reslen, preslen, prev_length,
(prev_length == -1 ? (prev_length == -1 ?
(no_residual ? "No residual data from previous call" : "Residual data from previous call") : "") (no_residual ? "No residual data from previous call" :
))); "Residual data from previous call") : ""));
blr_log_packet(LOGFILE_ERROR, "Packet:", ptr, len);
LOGIF(LE,(skygw_log_write( blr_log_packet(LOG_ERR, "Packet:", ptr, len);
LOGFILE_ERROR, MXS_ERROR("This event (0x%x) was contained in %d GWBUFs, "
"This event (0x%x) was contained in %d GWBUFs, "
"the previous events was contained in %d GWBUFs", "the previous events was contained in %d GWBUFs",
router->lastEventReceived, n_bufs, pn_bufs))); router->lastEventReceived, n_bufs, pn_bufs);
if (msg) if (msg)
{ {
free(msg); free(msg);
@ -1030,14 +1000,13 @@ int n_bufs = -1, pn_bufs = -1;
free(msg); free(msg);
msg = NULL; msg = NULL;
} }
LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Checksum error in event "
"%s: Checksum error in event "
"from master, " "from master, "
"binlog %s @ %lu. " "binlog %s @ %lu. "
"Closing master connection.", "Closing master connection.",
router->service->name, router->service->name,
router->binlog_name, router->binlog_name,
router->current_pos))); router->current_pos);
blr_master_close(router); blr_master_close(router);
blr_master_delayed_connect(router); blr_master_delayed_connect(router);
return; return;
@ -1088,14 +1057,14 @@ int n_bufs = -1, pn_bufs = -1;
if (flags == 0) { if (flags == 0) {
if (router->pending_transaction > 0) { if (router->pending_transaction > 0) {
LOGIF(LE,(skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("A MariaDB 10 transaction "
"Error: a MariaDB 10 transaction "
"is already open " "is already open "
"@ %lu (GTID %u-%u-%lu) and " "@ %lu (GTID %u-%u-%lu) and "
"a new one starts @ %lu", "a new one starts @ %lu",
router->binlog_position, router->binlog_position,
domainid, hdr.serverid, n_sequence, domainid, hdr.serverid,
router->current_pos))); n_sequence,
router->current_pos);
// An action should be taken here // An action should be taken here
} }
@ -1127,11 +1096,10 @@ int n_bufs = -1, pn_bufs = -1;
if (strncmp(statement_sql, "BEGIN", 5) == 0) { if (strncmp(statement_sql, "BEGIN", 5) == 0) {
if (router->pending_transaction > 0) { if (router->pending_transaction > 0) {
LOGIF(LE,(skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("A transaction is already open "
"Error: a transaction is already open "
"@ %lu and a new one starts @ %lu", "@ %lu and a new one starts @ %lu",
router->binlog_position, router->binlog_position,
router->current_pos))); router->current_pos);
// An action should be taken here // An action should be taken here
} }
@ -1175,11 +1143,10 @@ int n_bufs = -1, pn_bufs = -1;
if (hdr.event_type == FORMAT_DESCRIPTION_EVENT && hdr.next_pos == 0) if (hdr.event_type == FORMAT_DESCRIPTION_EVENT && hdr.next_pos == 0)
{ {
// Fake format description message // Fake format description message
LOGIF(LD,(skygw_log_write(LOGFILE_DEBUG, MXS_DEBUG("Replication fake event. "
"Replication fake event. "
"Binlog %s @ %lu.", "Binlog %s @ %lu.",
router->binlog_name, router->binlog_name,
router->current_pos))); router->current_pos);
router->stats.n_fakeevents++; router->stats.n_fakeevents++;
if (hdr.event_type == FORMAT_DESCRIPTION_EVENT) if (hdr.event_type == FORMAT_DESCRIPTION_EVENT)
@ -1202,13 +1169,12 @@ int n_bufs = -1, pn_bufs = -1;
} }
else else
{ {
LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Received a format description "
"%s: Received a format description "
"event that MaxScale was unable to " "event that MaxScale was unable to "
"record. Event length is %d.", "record. Event length is %d.",
router->service->name, router->service->name,
hdr.event_size))); hdr.event_size);
blr_log_packet(LOGFILE_ERROR, blr_log_packet(LOG_ERR,
"Format Description Event:", ptr, len); "Format Description Event:", ptr, len);
} }
} }
@ -1220,12 +1186,10 @@ int n_bufs = -1, pn_bufs = -1;
#ifdef SHOW_EVENTS #ifdef SHOW_EVENTS
printf("Replication heartbeat\n"); printf("Replication heartbeat\n");
#endif #endif
LOGIF(LD,(skygw_log_write( MXS_DEBUG("Replication heartbeat. "
LOGFILE_DEBUG,
"Replication heartbeat. "
"Binlog %s @ %lu.", "Binlog %s @ %lu.",
router->binlog_name, router->binlog_name,
router->current_pos))); router->current_pos);
router->stats.n_heartbeats++; router->stats.n_heartbeats++;
@ -1347,23 +1311,23 @@ int n_bufs = -1, pn_bufs = -1;
/* No event has been sent */ /* No event has been sent */
if (pos == router->binlog_position) { if (pos == router->binlog_position) {
LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, MXS_ERROR("No events distributed to slaves for a pending "
"No events distributed to slaves for a pending transaction in %s at %lu." "transaction in %s at %lu. "
"Last event from master at %lu", "Last event from master at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position, router->binlog_position,
router->current_pos))); router->current_pos);
strncpy(err_message, "No transaction events sent", BINLOG_ERROR_MSG_LEN); strncpy(err_message, "No transaction events sent", BINLOG_ERROR_MSG_LEN);
} else { } else {
/* Some events have been sent */ /* Some events have been sent */
LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Some events were not distributed to slaves for a "
"Some events were not distributed to slaves for a pending transaction " "pending transaction in %s at %lu. Last distributed "
"in %s at %lu. Last distributed even at %llu, last event from master at %lu", "even at %llu, last event from master at %lu",
router->binlog_name, router->binlog_name,
router->binlog_position, router->binlog_position,
pos, pos,
router->current_pos))); router->current_pos);
strncpy(err_message, "Incomplete transaction events sent", BINLOG_ERROR_MSG_LEN); strncpy(err_message, "Incomplete transaction events sent", BINLOG_ERROR_MSG_LEN);
} }
@ -1386,16 +1350,14 @@ int n_bufs = -1, pn_bufs = -1;
else else
{ {
router->stats.n_artificial++; router->stats.n_artificial++;
LOGIF(LD,(skygw_log_write( MXS_DEBUG("Artificial event not written "
LOGFILE_DEBUG,
"Artificial event not written "
"to disk or distributed. " "to disk or distributed. "
"Type 0x%x, Length %d, Binlog " "Type 0x%x, Length %d, Binlog "
"%s @ %lu.", "%s @ %lu.",
hdr.event_type, hdr.event_type,
hdr.event_size, hdr.event_size,
router->binlog_name, router->binlog_name,
router->current_pos))); router->current_pos);
ptr += 5; ptr += 5;
if (hdr.event_type == ROTATE_EVENT) if (hdr.event_type == ROTATE_EVENT)
{ {
@ -1445,10 +1407,9 @@ int n_bufs = -1, pn_bufs = -1;
spinlock_release(&router->lock); spinlock_release(&router->lock);
LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Error packet in binlog stream.%s @ %lu.",
"Error packet in binlog stream.%s @ %lu.",
router->binlog_name, router->binlog_name,
router->current_pos))); router->current_pos);
router->stats.n_binlog_errors++; router->stats.n_binlog_errors++;
} }
@ -1572,9 +1533,7 @@ MYSQL_session *auth_info;
if (username == NULL || password == NULL) if (username == NULL || password == NULL)
{ {
LOGIF(LE,(skygw_log_write( MXS_ERROR("You must specify both username and password for the binlog router.\n");
LOGFILE_ERROR,
"You must specify both username and password for the binlog router.\n")));
return NULL; return NULL;
} }
@ -1690,12 +1649,11 @@ int action;
* happen. Force the slave to catchup mode in order to * happen. Force the slave to catchup mode in order to
* try to resolve the issue. * try to resolve the issue.
*/ */
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Slave %d is ahead of expected position %s@%lu. "
"Slave %d is ahead of expected position %s@%lu. "
"Expected position %d", "Expected position %d",
slave->serverid, slave->binlogfile, slave->serverid, slave->binlogfile,
(unsigned long)slave->binlog_pos, (unsigned long)slave->binlog_pos,
hdr->next_pos - hdr->event_size))); hdr->next_pos - hdr->event_size);
} }
/* /*
@ -1792,13 +1750,13 @@ int action;
/** /**
* Write a raw event (the first 40 bytes at most) to a log file * Write a raw event (the first 40 bytes at most) to a log file
* *
* @param file The logfile to write to * @param priority The syslog priority of the message (LOG_ERR, LOG_WARNING, etc.)
* @param msg A textual message to write before the packet * @param msg A textual message to write before the packet
* @param ptr Pointer to the message buffer * @param ptr Pointer to the message buffer
* @param len Length of message packet * @param len Length of message packet
*/ */
static void static void
blr_log_packet(logfile_id_t file, char *msg, uint8_t *ptr, int len) blr_log_packet(int priority, char *msg, uint8_t *ptr, int len)
{ {
char buf[400] = ""; char buf[400] = "";
char *bufp; char *bufp;
@ -1809,10 +1767,9 @@ int i;
for (i = 0; i < len && i < 40; i++) for (i = 0; i < len && i < 40; i++)
bufp += sprintf(bufp, "0x%02x ", ptr[i]); bufp += sprintf(bufp, "0x%02x ", ptr[i]);
if (i < len) if (i < len)
skygw_log_write_flush(file, "%s...", buf); MXS_LOG_MESSAGE(priority, "%s...", buf);
else else
skygw_log_write_flush(file, "%s", buf); MXS_LOG_MESSAGE(priority, "%s", buf);
} }
/** /**
@ -1924,10 +1881,9 @@ int event_limit;
/* error */ /* error */
if (pos > end_pos) if (pos > end_pos)
{ {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Reading saved events, the specified pos %llu "
"Error: Reading saved events, the specified pos %llu "
"is ahead of current pos %lu for file %s", "is ahead of current pos %lu for file %s",
pos, router->current_pos, router->binlog_name))); pos, router->current_pos, router->binlog_name);
return NULL; return NULL;
} }
@ -1937,31 +1893,27 @@ int event_limit;
switch (n) switch (n)
{ {
case 0: case 0:
LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, MXS_DEBUG("Reading saved events: reached end of binlog file at %llu.", pos);
"Reading saved events: reached end of binlog file at %llu.", pos)));
break; break;
case -1: case -1:
{ {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: failed to read binlog "
"Error: Reading saved events: failed to read binlog "
"file %s at position %llu" "file %s at position %llu"
" (%s).", router->binlog_name, " (%s).", router->binlog_name,
pos, strerror_r(errno, err_msg, sizeof(err_msg))))); pos, strerror_r(errno, err_msg, sizeof(err_msg)));
if (errno == EBADF) if (errno == EBADF)
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: bad file descriptor for file %s"
"Error: Reading saved events: bad file descriptor for file %s"
", descriptor %d.", ", descriptor %d.",
router->binlog_name, router->binlog_fd))); router->binlog_name, router->binlog_fd);
break; break;
} }
default: default:
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: short read when reading the header. "
"Error: Reading saved events: short read when reading the header. "
"Expected 19 bytes but got %d bytes. " "Expected 19 bytes but got %d bytes. "
"Binlog file is %s, position %llu", "Binlog file is %s, position %llu",
n, router->binlog_name, pos))); n, router->binlog_name, pos);
break; break;
} }
@ -1979,20 +1931,18 @@ int event_limit;
if (hdr->event_type > event_limit) if (hdr->event_type > event_limit)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: invalid event type 0x%x. "
"Error: Reading saved events: invalid event type 0x%x. "
"Binlog file is %s, position %llu", "Binlog file is %s, position %llu",
hdr->event_type, hdr->event_type,
router->binlog_name, pos))); router->binlog_name, pos);
return NULL; return NULL;
} }
if ((result = gwbuf_alloc(hdr->event_size)) == NULL) if ((result = gwbuf_alloc(hdr->event_size)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: failed to allocate memory for binlog entry, "
"Error: Reading saved events: failed to allocate memory for binlog entry, "
"size %d at %llu.", "size %d at %llu.",
hdr->event_size, pos))); hdr->event_size, pos);
return NULL; return NULL;
} }
@ -2006,24 +1956,21 @@ int event_limit;
if (n == -1) if (n == -1)
{ {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: the event at %llu in %s. "
"Error: Reading saved events: the event at %llu in %s. "
"%s, expected %d bytes.", "%s, expected %d bytes.",
pos, router->binlog_name, pos, router->binlog_name,
strerror_r(errno, err_msg, sizeof(err_msg)), hdr->event_size - 19))); strerror_r(errno, err_msg, sizeof(err_msg)), hdr->event_size - 19);
} else { } else {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: short read when reading "
"Error: Reading saved events: short read when reading "
"the event at %llu in %s. " "the event at %llu in %s. "
"Expected %d bytes got %d bytes.", "Expected %d bytes got %d bytes.",
pos, router->binlog_name, hdr->event_size - 19, n))); pos, router->binlog_name, hdr->event_size - 19, n);
if (end_pos - pos < hdr->event_size) if (end_pos - pos < hdr->event_size)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Reading saved events: binlog event "
"Error: Reading saved events: binlog event "
"is close to the end of the binlog file, " "is close to the end of the binlog file, "
"current file size is %llu.", end_pos))); "current file size is %llu.", end_pos);
} }
} }
@ -2154,14 +2101,15 @@ char *event_desc = NULL;
if (router->master_state == BLRM_BINLOGDUMP && router->lastEventReceived > 0) { if (router->master_state == BLRM_BINLOGDUMP && router->lastEventReceived > 0) {
if ((t_now - router->stats.lastReply) > (router->heartbeat + BLR_NET_LATENCY_WAIT_TIME)) { if ((t_now - router->stats.lastReply) > (router->heartbeat + BLR_NET_LATENCY_WAIT_TIME)) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("No event received from master %s:%d in heartbeat period (%lu seconds), "
"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.", "last event (%s %d) received %lu seconds ago. Assuming connection is dead "
"and reconnecting.",
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port, router->service->dbref->server->port,
router->heartbeat, router->heartbeat,
event_desc != NULL ? event_desc : "unknown", event_desc != NULL ? event_desc : "unknown",
router->lastEventReceived, router->lastEventReceived,
t_now - router->stats.lastReply))); t_now - router->stats.lastReply);
return 0; return 0;
} }
@ -2201,33 +2149,27 @@ static void blr_log_identity(ROUTER_INSTANCE *router) {
} }
/* Seen by the master */ /* Seen by the master */
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: identity seen by the master: "
LOGFILE_MESSAGE,
"%s: identity seen by the master: "
"server_id: %d, uuid: %s", "server_id: %d, uuid: %s",
router->service->name, router->service->name,
router->serverid, (router->uuid == NULL ? "not available" : router->uuid)))); router->serverid, (router->uuid == NULL ? "not available" : router->uuid));
/* Seen by the slaves */ /* Seen by the slaves */
/* MariaDB 5.5 and MariaDB don't have the MASTER_UUID var */ /* MariaDB 5.5 and MariaDB don't have the MASTER_UUID var */
if (master_uuid == NULL) { if (master_uuid == NULL) {
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: identity seen by the slaves: "
LOGFILE_MESSAGE,
"%s: identity seen by the slaves: "
"server_id: %d, hostname: %s, MySQL version: %s", "server_id: %d, hostname: %s, MySQL version: %s",
router->service->name, router->service->name,
router->masterid, (master_hostname == NULL ? "not available" : master_hostname), router->masterid, (master_hostname == NULL ? "not available" : master_hostname),
(master_version == NULL ? "not available" : master_version)))); (master_version == NULL ? "not available" : master_version));
} else { } else {
LOGIF(LM, (skygw_log_write_flush( MXS_NOTICE("%s: identity seen by the slaves: "
LOGFILE_MESSAGE,
"%s: identity seen by the slaves: "
"server_id: %d, uuid: %s, hostname: %s, MySQL version: %s", "server_id: %d, uuid: %s, hostname: %s, MySQL version: %s",
router->service->name, router->service->name,
router->masterid, master_uuid, router->masterid, master_uuid,
(master_hostname == NULL ? "not available" : master_hostname), (master_hostname == NULL ? "not available" : master_hostname),
(master_version == NULL ? "not available" : master_version)))); (master_version == NULL ? "not available" : master_version));
} }
} }

323
server/modules/routing/binlog/blr_slave.c
View File

@ -176,9 +176,8 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue)
{ {
if (slave->state < 0 || slave->state > BLRS_MAXSTATE) if (slave->state < 0 || slave->state > BLRS_MAXSTATE)
{ {
LOGIF(LE, (skygw_log_write( MXS_ERROR("Invalid slave state machine state (%d) for binlog router.",
LOGFILE_ERROR, "Invalid slave state machine state (%d) for binlog router.", slave->state);
slave->state)));
gwbuf_consume(queue, gwbuf_length(queue)); gwbuf_consume(queue, gwbuf_length(queue));
return 0; return 0;
} }
@ -196,11 +195,9 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue)
blr_slave_send_error_packet(slave, blr_slave_send_error_packet(slave,
"Binlog router is not yet configured for replication", (unsigned int) 1597, NULL); "Binlog router is not yet configured for replication", (unsigned int) 1597, NULL);
LOGIF(LE, (skygw_log_write( MXS_ERROR("%s: Slave %s: Binlog router is not yet configured for replication",
LOGFILE_ERROR,
"%s: Slave %s: Binlog router is not yet configured for replication",
router->service->name, router->service->name,
slave->dcb->remote))); slave->dcb->remote);
dcb_close(slave->dcb); dcb_close(slave->dcb);
return 1; return 1;
} }
@ -215,11 +212,9 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue)
blr_send_custom_error(slave->dcb, 1, 0, blr_send_custom_error(slave->dcb, 1, 0,
"MariaDB 10 Slave is required for Slave registration", "42000", 1064); "MariaDB 10 Slave is required for Slave registration", "42000", 1064);
LOGIF(LE, (skygw_log_write( MXS_ERROR("%s: Slave %s: a MariaDB 10 Slave is required for Slave registration",
LOGFILE_ERROR,
"%s: Slave %s: a MariaDB 10 Slave is required for Slave registration",
router->service->name, router->service->name,
slave->dcb->remote))); slave->dcb->remote);
dcb_close(slave->dcb); dcb_close(slave->dcb);
return 1; return 1;
@ -252,18 +247,15 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue)
return blr_ping(router, slave, queue); return blr_ping(router, slave, queue);
break; break;
case COM_QUIT: case COM_QUIT:
LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, MXS_DEBUG("COM_QUIT received from slave with server_id %d",
"COM_QUIT received from slave with server_id %d", slave->serverid);
slave->serverid)));
break; break;
default: default:
blr_send_custom_error(slave->dcb, 1, 0, blr_send_custom_error(slave->dcb, 1, 0,
"You have an error in your SQL syntax; Check the syntax the MaxScale binlog router accepts.", "You have an error in your SQL syntax; Check the syntax the MaxScale binlog router accepts.",
"42000", 1064); "42000", 1064);
LOGIF(LE, (skygw_log_write( MXS_ERROR("Unexpected MySQL Command (%d) received from slave",
LOGFILE_ERROR, MYSQL_COMMAND(queue));
"Unexpected MySQL Command (%d) received from slave",
MYSQL_COMMAND(queue))));
break; break;
} }
return 0; return 0;
@ -355,13 +347,11 @@ extern char *strcasestr();
} }
} }
LOGIF(LT, (skygw_log_write( MXS_INFO("Execute statement (truncated, it contains password)"
LOGFILE_TRACE, "Execute statement (truncated, it contains password)" " from the slave '%s'", new_text);
" from the slave '%s'", new_text)));
free(new_text); free(new_text);
} else { } else {
LOGIF(LT, (skygw_log_write( MXS_INFO("Execute statement from the slave '%s'", query_text);
LOGFILE_TRACE, "Execute statement from the slave '%s'", query_text)));
} }
/* /*
@ -375,15 +365,14 @@ extern char *strcasestr();
if ((word = strtok_r(query_text, sep, &brkb)) == NULL) if ((word = strtok_r(query_text, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete query.", MXS_ERROR("%s: Incomplete query.", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "SELECT") == 0) else if (strcasecmp(word, "SELECT") == 0)
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete select query.", MXS_ERROR("%s: Incomplete select query.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "UNIX_TIMESTAMP()") == 0) else if (strcasecmp(word, "UNIX_TIMESTAMP()") == 0)
{ {
@ -485,8 +474,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete show query.", MXS_ERROR("%s: Incomplete show query.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "WARNINGS") == 0) else if (strcasecmp(word, "WARNINGS") == 0)
{ {
@ -502,9 +491,8 @@ extern char *strcasestr();
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected VARIABLES in SHOW GLOBAL",
"%s: Expected VARIABLES in SHOW GLOBAL", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "VARIABLES") == 0) else if (strcasecmp(word, "VARIABLES") == 0)
{ {
@ -519,9 +507,8 @@ extern char *strcasestr();
return 1; return 1;
} else } else
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected LIKE clause in SHOW GLOBAL VARIABLES.",
"%s: Expected LIKE clause in SHOW GLOBAL VARIABLES.", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "STATUS") == 0) else if (strcasecmp(word, "STATUS") == 0)
{ {
@ -536,9 +523,8 @@ extern char *strcasestr();
return 1; return 1;
} else } else
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected LIKE clause in SHOW GLOBAL STATUS.",
"%s: Expected LIKE clause in SHOW GLOBAL STATUS.", router->service->name);
router->service->name)));
} }
} }
else if (strcasecmp(word, "VARIABLES") == 0) else if (strcasecmp(word, "VARIABLES") == 0)
@ -560,17 +546,15 @@ extern char *strcasestr();
return 1; return 1;
} else } else
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected LIKE clause in SHOW VARIABLES.",
"%s: Expected LIKE clause in SHOW VARIABLES.", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "MASTER") == 0) else if (strcasecmp(word, "MASTER") == 0)
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected SHOW MASTER STATUS command",
"%s: Expected SHOW MASTER STATUS command", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "STATUS") == 0) else if (strcasecmp(word, "STATUS") == 0)
{ {
@ -588,9 +572,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected SHOW SLAVE STATUS command",
"%s: Expected SHOW SLAVE STATUS command", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "STATUS") == 0) else if (strcasecmp(word, "STATUS") == 0)
{ {
@ -624,17 +607,16 @@ extern char *strcasestr();
return 1; return 1;
} else } else
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected LIKE clause in SHOW STATUS.",
"%s: Expected LIKE clause in SHOW STATUS.", router->service->name);
router->service->name)));
} }
} }
else if (strcasecmp(query_text, "SET") == 0) else if (strcasecmp(query_text, "SET") == 0)
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete set command.", MXS_ERROR("%s: Incomplete set command.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "@master_heartbeat_period") == 0) else if (strcasecmp(word, "@master_heartbeat_period") == 0)
{ {
@ -694,8 +676,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Truncated SET NAMES command.", MXS_ERROR("%s: Truncated SET NAMES command.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "latin1") == 0) else if (strcasecmp(word, "latin1") == 0)
{ {
@ -713,8 +695,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete RESET command.", MXS_ERROR("%s: Incomplete RESET command.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "SLAVE") == 0) else if (strcasecmp(word, "SLAVE") == 0)
{ {
@ -731,7 +713,7 @@ extern char *strcasestr();
if (!current_master) { if (!current_master) {
snprintf(error_string, BINLOG_ERROR_MSG_LEN, "error allocating memory for blr_master_get_config"); snprintf(error_string, BINLOG_ERROR_MSG_LEN, "error allocating memory for blr_master_get_config");
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error_string))); MXS_ERROR("%s: %s", router->service->name, error_string);
blr_slave_send_error_packet(slave, error_string, (unsigned int)1201, NULL); blr_slave_send_error_packet(slave, error_string, (unsigned int)1201, NULL);
return 1; return 1;
@ -740,13 +722,15 @@ extern char *strcasestr();
/* get current data */ /* get current data */
blr_master_get_config(router, current_master); blr_master_get_config(router, current_master);
LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, "%s: 'RESET SLAVE executed'. Previous state MASTER_HOST='%s', MASTER_PORT=%i, MASTER_LOG_FILE='%s', MASTER_LOG_POS=%lu, MASTER_USER='%s'", MXS_NOTICE("%s: 'RESET SLAVE executed'. Previous state MASTER_HOST='%s', "
"MASTER_PORT=%i, MASTER_LOG_FILE='%s', MASTER_LOG_POS=%lu, "
"MASTER_USER='%s'",
router->service->name, router->service->name,
current_master->host, current_master->host,
current_master->port, current_master->port,
current_master->logfile, current_master->logfile,
current_master->pos, current_master->pos,
current_master->user))); current_master->user);
/* remove master.ini */ /* remove master.ini */
strncpy(path, router->binlogdir, PATH_MAX); strncpy(path, router->binlogdir, PATH_MAX);
@ -759,7 +743,7 @@ extern char *strcasestr();
if (removed_cfg == -1) { if (removed_cfg == -1) {
char err_msg[STRERROR_BUFLEN]; char err_msg[STRERROR_BUFLEN];
snprintf(error_string, BINLOG_ERROR_MSG_LEN, "Error removing %s, %s, errno %u", path, strerror_r(errno, err_msg, sizeof(err_msg)), errno); snprintf(error_string, BINLOG_ERROR_MSG_LEN, "Error removing %s, %s, errno %u", path, strerror_r(errno, err_msg, sizeof(err_msg)), errno);
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error_string))); MXS_ERROR("%s: %s", router->service->name, error_string);
} }
spinlock_acquire(&router->lock); spinlock_acquire(&router->lock);
@ -790,8 +774,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete START command.", MXS_ERROR("%s: Incomplete START command.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "SLAVE") == 0) else if (strcasecmp(word, "SLAVE") == 0)
{ {
@ -804,8 +788,7 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete STOP command.", MXS_ERROR("%s: Incomplete STOP command.", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "SLAVE") == 0) else if (strcasecmp(word, "SLAVE") == 0)
{ {
@ -818,8 +801,7 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete CHANGE command.", MXS_ERROR("%s: Incomplete CHANGE command.", router->service->name);
router->service->name)));
} }
else if (strcasecmp(word, "MASTER") == 0) else if (strcasecmp(word, "MASTER") == 0)
{ {
@ -840,7 +822,7 @@ extern char *strcasestr();
if (!current_master) { if (!current_master) {
free(query_text); free(query_text);
strcpy(error_string, "Error allocating memory for blr_master_get_config"); strcpy(error_string, "Error allocating memory for blr_master_get_config");
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error_string))); MXS_ERROR("%s: %s", router->service->name, error_string);
blr_slave_send_error_packet(slave, error_string, (unsigned int)1201, NULL); blr_slave_send_error_packet(slave, error_string, (unsigned int)1201, NULL);
@ -876,8 +858,8 @@ extern char *strcasestr();
spinlock_release(&router->lock); spinlock_release(&router->lock);
snprintf(error_string, BINLOG_ERROR_MSG_LEN, "Error writing into %s/master.ini: %s", router->binlogdir, error); snprintf(error_string, BINLOG_ERROR_MSG_LEN, "Error writing into %s/master.ini: %s", router->binlogdir, error);
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: %s", MXS_ERROR("%s: %s",
router->service->name, error_string))); router->service->name, error_string);
blr_slave_send_error_packet(slave, error_string, (unsigned int)1201, NULL); blr_slave_send_error_packet(slave, error_string, (unsigned int)1201, NULL);
@ -923,8 +905,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete DISCONNECT command.", MXS_ERROR("%s: Incomplete DISCONNECT command.",
router->service->name))); router->service->name);
} }
else if (strcasecmp(word, "ALL") == 0) else if (strcasecmp(word, "ALL") == 0)
{ {
@ -935,9 +917,8 @@ extern char *strcasestr();
{ {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) if ((word = strtok_r(NULL, sep, &brkb)) == NULL)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Expected DISCONNECT SERVER $server_id",
"%s: Expected DISCONNECT SERVER $server_id", router->service->name);
router->service->name)));
} else { } else {
int serverid = atoi(word); int serverid = atoi(word);
free(query_text); free(query_text);
@ -949,8 +930,7 @@ extern char *strcasestr();
free(query_text); free(query_text);
query_text = strndup(qtext, query_len); query_text = strndup(qtext, query_len);
LOGIF(LE, (skygw_log_write( MXS_ERROR("Unexpected query from '%s'@'%s': %s", slave->dcb->user, slave->dcb->remote, query_text);
LOGFILE_ERROR, "Unexpected query from '%s'@'%s': %s", slave->dcb->user, slave->dcb->remote, query_text)));
free(query_text); free(query_text);
blr_slave_send_error(router, slave, "You have an error in your SQL syntax; Check the syntax the MaxScale binlog router accepts."); blr_slave_send_error(router, slave, "You have an error in your SQL syntax; Check the syntax the MaxScale binlog router accepts.");
return 1; return 1;
@ -984,8 +964,7 @@ GWBUF *clone;
} }
else else
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Failed to clone server response to send to slave.");
"Failed to clone server response to send to slave.")));
return 0; return 0;
} }
} }
@ -1713,20 +1692,16 @@ uint32_t chksum;
binlognamelen = len - 11; binlognamelen = len - 11;
if (binlognamelen > BINLOG_FNAMELEN) if (binlognamelen > BINLOG_FNAMELEN)
{ {
LOGIF(LE, (skygw_log_write( MXS_ERROR("blr_slave_binlog_dump truncating binlog filename "
LOGFILE_ERROR,
"blr_slave_binlog_dump truncating binlog filename "
"from %d to %d", "from %d to %d",
binlognamelen, BINLOG_FNAMELEN))); binlognamelen, BINLOG_FNAMELEN);
binlognamelen = BINLOG_FNAMELEN; binlognamelen = BINLOG_FNAMELEN;
} }
ptr += 4; // Skip length and sequence number ptr += 4; // Skip length and sequence number
if (*ptr++ != COM_BINLOG_DUMP) if (*ptr++ != COM_BINLOG_DUMP)
{ {
LOGIF(LE, (skygw_log_write( MXS_ERROR("blr_slave_binlog_dump expected a COM_BINLOG_DUMP but received %d",
LOGFILE_ERROR, *(ptr-1));
"blr_slave_binlog_dump expected a COM_BINLOG_DUMP but received %d",
*(ptr-1))));
return 0; return 0;
} }
@ -1737,12 +1712,10 @@ uint32_t chksum;
strncpy(slave->binlogfile, (char *)ptr, binlognamelen); strncpy(slave->binlogfile, (char *)ptr, binlognamelen);
slave->binlogfile[binlognamelen] = 0; slave->binlogfile[binlognamelen] = 0;
LOGIF(LD, (skygw_log_write( MXS_DEBUG("%s: COM_BINLOG_DUMP: binlog name '%s', length %d, "
LOGFILE_DEBUG,
"%s: COM_BINLOG_DUMP: binlog name '%s', length %d, "
"from position %lu.", router->service->name, "from position %lu.", router->service->name,
slave->binlogfile, binlognamelen, slave->binlogfile, binlognamelen,
(unsigned long)slave->binlog_pos))); (unsigned long)slave->binlog_pos);
slave->seqno = 1; slave->seqno = 1;
@ -1808,12 +1781,10 @@ uint32_t chksum;
slave->state = BLRS_DUMPING; slave->state = BLRS_DUMPING;
LOGIF(LM, (skygw_log_write( MXS_NOTICE("%s: Slave %s, server id %d requested binlog file %s from position %lu",
LOGFILE_MESSAGE,
"%s: Slave %s, server id %d requested binlog file %s from position %lu",
router->service->name, slave->dcb->remote, router->service->name, slave->dcb->remote,
slave->serverid, slave->serverid,
slave->binlogfile, (unsigned long)slave->binlog_pos))); slave->binlogfile, (unsigned long)slave->binlog_pos);
if (slave->binlog_pos != router->binlog_position || if (slave->binlog_pos != router->binlog_position ||
strcmp(slave->binlogfile, router->binlog_name) != 0) strcmp(slave->binlogfile, router->binlog_name) != 0)
@ -1949,11 +1920,10 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
poll_fake_write_event(slave->dcb); poll_fake_write_event(slave->dcb);
return rval; return rval;
} }
LOGIF(LE, (skygw_log_write( MXS_ERROR("Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup "
LOGFILE_ERROR, "failed to open binlog file",
"Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup failed to open binlog file",
slave->dcb->remote, slave->port, slave->serverid, slave->dcb->remote, slave->port, slave->serverid,
slave->binlogfile))); slave->binlogfile);
slave->cstate &= ~CS_BUSY; slave->cstate &= ~CS_BUSY;
slave->state = BLRS_ERRORED; slave->state = BLRS_ERRORED;
@ -1987,9 +1957,8 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
unsigned long beat1 = hkheartbeat; unsigned long beat1 = hkheartbeat;
blr_close_binlog(router, slave->file); blr_close_binlog(router, slave->file);
if (hkheartbeat - beat1 > 1) if (hkheartbeat - beat1 > 1)
LOGIF(LE, (skygw_log_write( MXS_ERROR("blr_close_binlog took %lu maxscale beats",
LOGFILE_ERROR, "blr_close_binlog took %lu maxscale beats", hkheartbeat - beat1);
hkheartbeat - beat1)));
blr_slave_rotate(router, slave, GWBUF_DATA(record)); blr_slave_rotate(router, slave, GWBUF_DATA(record));
beat1 = hkheartbeat; beat1 = hkheartbeat;
if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL) if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL)
@ -2005,13 +1974,12 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
poll_fake_write_event(slave->dcb); poll_fake_write_event(slave->dcb);
return rval; return rval;
} }
LOGIF(LE, (skygw_log_write( MXS_ERROR("Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup "
LOGFILE_ERROR, "failed to open binlog file in rotate event",
"Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup failed to open binlog file in rotate event",
slave->dcb->remote, slave->dcb->remote,
slave->port, slave->port,
slave->serverid, slave->serverid,
slave->binlogfile))); slave->binlogfile);
slave->state = BLRS_ERRORED; slave->state = BLRS_ERRORED;
@ -2024,9 +1992,8 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
break; break;
} }
if (hkheartbeat - beat1 > 1) if (hkheartbeat - beat1 > 1)
LOGIF(LE, (skygw_log_write( MXS_ERROR("blr_open_binlog took %lu beats",
LOGFILE_ERROR, "blr_open_binlog took %lu beats", hkheartbeat - beat1);
hkheartbeat - beat1)));
} }
slave->stats.n_bytes += gwbuf_length(head); slave->stats.n_bytes += gwbuf_length(head);
written = slave->dcb->func.write(slave->dcb, head); written = slave->dcb->func.write(slave->dcb, head);
@ -2046,14 +2013,13 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
slave->stats.n_failed_read++; slave->stats.n_failed_read++;
if (hdr.ok == SLAVE_POS_READ_ERR) { if (hdr.ok == SLAVE_POS_READ_ERR) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s Slave %s:%i, server-id %d, binlog '%s', %s",
"%s Slave %s:%i, server-id %d, binlog '%s', %s",
router->service->name, router->service->name,
slave->dcb->remote, slave->dcb->remote,
slave->port, slave->port,
slave->serverid, slave->serverid,
slave->binlogfile, slave->binlogfile,
read_errmsg))); read_errmsg);
spinlock_acquire(&slave->catch_lock); spinlock_acquire(&slave->catch_lock);
@ -2075,14 +2041,13 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
ROUTER_OBJECT *router_obj= router->service->router; ROUTER_OBJECT *router_obj= router->service->router;
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Slave %s:%i, server-id %d, binlog '%s', %s",
"%s: Slave %s:%i, server-id %d, binlog '%s', %s",
router->service->name, router->service->name,
slave->dcb->remote, slave->dcb->remote,
slave->port, slave->port,
slave->serverid, slave->serverid,
slave->binlogfile, slave->binlogfile,
read_errmsg))); read_errmsg);
/* /*
* Close the slave session and socket * Close the slave session and socket
@ -2142,23 +2107,21 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
slave->stats.n_caughtup++; slave->stats.n_caughtup++;
if (slave->stats.n_caughtup == 1) if (slave->stats.n_caughtup == 1)
{ {
LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, MXS_NOTICE("%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.",
"%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.",
router->service->name, router->service->name,
slave->dcb->remote, slave->dcb->remote,
slave->port, slave->port,
slave->serverid, slave->serverid,
slave->binlogfile, (unsigned long)slave->binlog_pos))); slave->binlogfile, (unsigned long)slave->binlog_pos);
} }
else if ((slave->stats.n_caughtup % 50) == 0) else if ((slave->stats.n_caughtup % 50) == 0)
{ {
LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, MXS_NOTICE("%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.",
"%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.",
router->service->name, router->service->name,
slave->dcb->remote, slave->dcb->remote,
slave->port, slave->port,
slave->serverid, slave->serverid,
slave->binlogfile, (unsigned long)slave->binlog_pos))); slave->binlogfile, (unsigned long)slave->binlog_pos);
} }
} }
} }
@ -2178,13 +2141,12 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1];
* but the new binlog file has not yet been created. Therefore * but the new binlog file has not yet been created. Therefore
* we ignore these issues during the rotate processing. * we ignore these issues during the rotate processing.
*/ */
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Slave reached end of file for binlog file %s at %lu "
"Slave reached end of file for binlog file %s at %lu "
"which is not the file currently being downloaded. " "which is not the file currently being downloaded. "
"Master binlog is %s, %lu. This may be caused by a " "Master binlog is %s, %lu. This may be caused by a "
"previous failure of the master.", "previous failure of the master.",
slave->binlogfile, (unsigned long)slave->binlog_pos, slave->binlogfile, (unsigned long)slave->binlog_pos,
router->binlog_name, router->binlog_position))); router->binlog_name, router->binlog_position);
if (blr_slave_fake_rotate(router, slave)) if (blr_slave_fake_rotate(router, slave))
{ {
spinlock_acquire(&slave->catch_lock); spinlock_acquire(&slave->catch_lock);
@ -2246,9 +2208,8 @@ ROUTER_INSTANCE *router = slave->router;
} }
else else
{ {
LOGIF(LD, (skygw_log_write( MXS_DEBUG("Ignored callback due to slave state %s",
LOGFILE_DEBUG, "Ignored callback due to slave state %s", blrs_states[slave->state]);
blrs_states[slave->state])));
} }
} }
@ -2385,13 +2346,12 @@ char err_msg[BINLOG_ERROR_MSG_LEN+1];
if ((record = blr_read_binlog(router, file, 4, &hdr, err_msg)) == NULL) if ((record = blr_read_binlog(router, file, 4, &hdr, err_msg)) == NULL)
{ {
if (hdr.ok != SLAVE_POS_READ_OK) { if (hdr.ok != SLAVE_POS_READ_OK) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Slave %s:%i, server-id %d, binlog '%s', blr_read_binlog failure: %s",
"Slave %s:%i, server-id %d, binlog '%s', blr_read_binlog failure: %s",
slave->dcb->remote, slave->dcb->remote,
slave->port, slave->port,
slave->serverid, slave->serverid,
slave->binlogfile, slave->binlogfile,
err_msg))); err_msg);
} }
blr_close_binlog(router, file); blr_close_binlog(router, file);
@ -2610,12 +2570,12 @@ blr_slave_disconnect_server(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, int se
{ {
/* server_id found */ /* server_id found */
server_found = 1; server_found = 1;
LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, "%s: Slave %s, server id %d, disconnected by %s@%s", MXS_NOTICE("%s: Slave %s, server id %d, disconnected by %s@%s",
router->service->name, router->service->name,
sptr->dcb->remote, sptr->dcb->remote,
server_id, server_id,
slave->dcb->user, slave->dcb->user,
slave->dcb->remote))); slave->dcb->remote);
/* send server_id with disconnect state to client */ /* send server_id with disconnect state to client */
n = blr_slave_send_disconnected_server(router, slave, server_id, 1); n = blr_slave_send_disconnected_server(router, slave, server_id, 1);
@ -2640,9 +2600,9 @@ blr_slave_disconnect_server(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, int se
} }
if (n == 0) { if (n == 0) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Error: gwbuf memory allocation in " MXS_ERROR("gwbuf memory allocation in "
"DISCONNECT SERVER server_id [%d]", "DISCONNECT SERVER server_id [%d]",
sptr->serverid))); sptr->serverid);
blr_slave_send_error(router, slave, "Memory allocation error for DISCONNECT SERVER"); blr_slave_send_error(router, slave, "Memory allocation error for DISCONNECT SERVER");
} }
@ -2690,9 +2650,9 @@ blr_slave_disconnect_all(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave)
len = 5 + strlen(server_id) + strlen(state) + 1; len = 5 + strlen(server_id) + strlen(state) + 1;
if ((pkt = gwbuf_alloc(len)) == NULL) { if ((pkt = gwbuf_alloc(len)) == NULL) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Error: gwbuf memory allocation in " MXS_ERROR("gwbuf memory allocation in "
"DISCONNECT ALL for [%s], server_id [%d]", "DISCONNECT ALL for [%s], server_id [%d]",
sptr->dcb->remote, sptr->serverid))); sptr->dcb->remote, sptr->serverid);
spinlock_release(&router->lock); spinlock_release(&router->lock);
@ -2701,9 +2661,9 @@ blr_slave_disconnect_all(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave)
return 1; return 1;
} }
LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, "%s: Slave %s, server id %d, disconnected by %s@%s", MXS_NOTICE("%s: Slave %s, server id %d, disconnected by %s@%s",
router->service->name, router->service->name,
sptr->dcb->remote, sptr->serverid, slave->dcb->user, slave->dcb->remote))); sptr->dcb->remote, sptr->serverid, slave->dcb->user, slave->dcb->remote);
ptr = GWBUF_DATA(pkt); ptr = GWBUF_DATA(pkt);
encode_value(ptr, len - 4, 24); // Add length of data packet encode_value(ptr, len - 4, 24); // Add length of data packet
@ -2870,15 +2830,14 @@ blr_stop_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave)
spinlock_release(&router->lock); spinlock_release(&router->lock);
LOGIF(LM, (skygw_log_write( MXS_NOTICE("%s: STOP SLAVE executed by %s@%s. Disconnecting from master %s:%d, "
LOGFILE_MESSAGE, "read up to log %s, pos %lu, transaction safe pos %lu",
"%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, router->service->name,
slave->dcb->user, slave->dcb->user,
slave->dcb->remote, slave->dcb->remote,
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port, router->service->dbref->server->port,
router->binlog_name, router->current_pos, router->binlog_position))); router->binlog_name, router->current_pos, router->binlog_position);
if (router->trx_safe && router->pending_transaction) { if (router->trx_safe && router->pending_transaction) {
char message[BINLOG_ERROR_MSG_LEN+1] = ""; char message[BINLOG_ERROR_MSG_LEN+1] = "";
@ -2943,16 +2902,14 @@ blr_start_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave)
truncate(file, router->last_safe_pos); truncate(file, router->last_safe_pos);
/* Log it */ /* Log it */
LOGIF(LE, (skygw_log_write( MXS_WARNING("A transaction is still opened at pos %lu"
LOGFILE_ERROR,
"Warning: a transaction is still opened at pos %lu"
" File %s will be truncated. " " File %s will be truncated. "
"Next binlog file is %s at pos %d, " "Next binlog file is %s at pos %d, "
"START SLAVE is required again.", "START SLAVE is required again.",
router->last_safe_pos, router->last_safe_pos,
router->prevbinlog, router->prevbinlog,
router->binlog_name, router->binlog_name,
4))); 4);
spinlock_acquire(&router->lock); spinlock_acquire(&router->lock);
@ -2983,16 +2940,15 @@ blr_start_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave)
blr_start_master(router); blr_start_master(router);
LOGIF(LM, (skygw_log_write( MXS_NOTICE("%s: START SLAVE executed by %s@%s. Trying connection to master %s:%d, "
LOGFILE_MESSAGE, "binlog %s, pos %lu, transaction safe pos %lu",
"%s: START SLAVE executed by %s@%s. Trying connection to master %s:%d, binlog %s, pos %lu, transaction safe pos %lu",
router->service->name, router->service->name,
slave->dcb->user, slave->dcb->user,
slave->dcb->remote, slave->dcb->remote,
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port, router->service->dbref->server->port,
router->binlog_name, router->binlog_name,
router->current_pos, router->binlog_position))); router->current_pos, router->binlog_position);
/* File path for router cached authentication data */ /* File path for router cached authentication data */
strcpy(path, router->binlogdir); strcpy(path, router->binlogdir);
@ -3005,10 +2961,8 @@ blr_start_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave)
if (loaded < 0) if (loaded < 0)
{ {
LOGIF(LE, (skygw_log_write_flush( MXS_ERROR("Unable to load users for service %s",
LOGFILE_ERROR, router->service->name);
"Error : Unable to load users for service %s",
router->service->name)));
} else { } else {
/* update cached data */ /* update cached data */
if (loaded > 0) if (loaded > 0)
@ -3096,7 +3050,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
if ((cmd_string = strdup(cmd_ptr + 2)) == NULL) { if ((cmd_string = strdup(cmd_ptr + 2)) == NULL) {
strncpy(error, "error allocating memory for statement parsing", BINLOG_ERROR_MSG_LEN); strncpy(error, "error allocating memory for statement parsing", BINLOG_ERROR_MSG_LEN);
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error))); MXS_ERROR("%s: %s", router->service->name, error);
return -1; return -1;
} }
@ -3109,7 +3063,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
free(cmd_string); free(cmd_string);
if (parse_ret) { if (parse_ret) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s CHANGE MASTER TO parse error: %s", router->service->name, error))); MXS_ERROR("%s CHANGE MASTER TO parse error: %s", router->service->name, error);
blr_master_free_parsed_options(&change_master); blr_master_free_parsed_options(&change_master);
@ -3121,7 +3075,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
if (!current_master) { if (!current_master) {
strncpy(error, "error allocating memory for blr_master_get_config", BINLOG_ERROR_MSG_LEN); strncpy(error, "error allocating memory for blr_master_get_config", BINLOG_ERROR_MSG_LEN);
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error))); MXS_ERROR("%s: %s", router->service->name, error);
blr_master_free_parsed_options(&change_master); blr_master_free_parsed_options(&change_master);
@ -3170,7 +3124,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
strcpy(error, "Router is not configured for master connection, MASTER_LOG_FILE is required"); strcpy(error, "Router is not configured for master connection, MASTER_LOG_FILE is required");
} }
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error))); MXS_ERROR("%s: %s", router->service->name, error);
/* restore previous master_host and master_port */ /* restore previous master_host and master_port */
blr_master_restore_config(router, current_master); blr_master_restore_config(router, current_master);
@ -3191,7 +3145,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
/* if errors returned */ /* if errors returned */
if (strlen(error)) { if (strlen(error)) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error))); MXS_ERROR("%s: %s", router->service->name, error);
/* restore previous master_host and master_port */ /* restore previous master_host and master_port */
blr_master_restore_config(router, current_master); blr_master_restore_config(router, current_master);
@ -3242,7 +3196,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
/* return an error or set new binlog name at pos 4 */ /* return an error or set new binlog name at pos 4 */
if (return_error) { if (return_error) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error))); MXS_ERROR("%s: %s", router->service->name, error);
/* restore previous master_host and master_port */ /* restore previous master_host and master_port */
blr_master_restore_config(router, current_master); blr_master_restore_config(router, current_master);
@ -3269,9 +3223,9 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
close(router->binlog_fd); close(router->binlog_fd);
router->binlog_fd = -1; router->binlog_fd = -1;
LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_LOG_FILE is [%s]", MXS_INFO("%s: New MASTER_LOG_FILE is [%s]",
router->service->name, router->service->name,
router->binlog_name))); router->binlog_name);
} }
} else { } else {
/** /**
@ -3305,7 +3259,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
/* log error and return */ /* log error and return */
if (return_error) { if (return_error) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "%s: %s", router->service->name, error))); MXS_ERROR("%s: %s", router->service->name, error);
/* restore previous master_host and master_port */ /* restore previous master_host and master_port */
blr_master_restore_config(router, current_master); blr_master_restore_config(router, current_master);
@ -3329,27 +3283,31 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error
memset(router->binlog_name, '\0', sizeof(router->binlog_name)); memset(router->binlog_name, '\0', sizeof(router->binlog_name));
strncpy(router->binlog_name, master_logfile, BINLOG_FNAMELEN); strncpy(router->binlog_name, master_logfile, BINLOG_FNAMELEN);
LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_LOG_FILE is [%s]", MXS_INFO("%s: New MASTER_LOG_FILE is [%s]",
router->service->name, router->service->name,
router->binlog_name))); router->binlog_name);
} }
LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_LOG_POS is [%lu]", MXS_INFO("%s: New MASTER_LOG_POS is [%lu]",
router->service->name, router->service->name,
router->current_pos))); router->current_pos);
} }
} }
/* Log config changes (without passwords) */ /* Log config changes (without passwords) */
LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, "%s: 'CHANGE MASTER TO executed'. Previous state MASTER_HOST='%s', MASTER_PORT=%i, MASTER_LOG_FILE='%s', MASTER_LOG_POS=%lu, MASTER_USER='%s'. New state is MASTER_HOST='%s', MASTER_PORT=%i, MASTER_LOG_FILE='%s', MASTER_LOG_POS=%lu, MASTER_USER='%s'", MXS_NOTICE("%s: 'CHANGE MASTER TO executed'. Previous state "
"MASTER_HOST='%s', MASTER_PORT=%i, MASTER_LOG_FILE='%s', "
"MASTER_LOG_POS=%lu, MASTER_USER='%s'. New state is MASTER_HOST='%s', "
"MASTER_PORT=%i, MASTER_LOG_FILE='%s', MASTER_LOG_POS=%lu, MASTER_USER='%s'",
router->service->name, router->service->name,
current_master->host,current_master->port, current_master->logfile, current_master->pos, current_master->user, current_master->host, current_master->port, current_master->logfile,
current_master->pos, current_master->user,
router->service->dbref->server->name, router->service->dbref->server->name,
router->service->dbref->server->port, router->service->dbref->server->port,
router->binlog_name, router->binlog_name,
router->current_pos, router->current_pos,
router->user))); router->user);
blr_master_free_config(current_master); blr_master_free_config(current_master);
@ -3389,9 +3347,9 @@ blr_set_master_hostname(ROUTER_INSTANCE *router, char *hostname) {
server_update_address(router->service->dbref->server, ptr); server_update_address(router->service->dbref->server, ptr);
LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_HOST is [%s]", MXS_INFO("%s: New MASTER_HOST is [%s]",
router->service->name, router->service->name,
router->service->dbref->server->name))); router->service->dbref->server->name);
return 1; return 1;
} }
@ -3418,9 +3376,9 @@ blr_set_master_port(ROUTER_INSTANCE *router, char *port) {
if (new_port) { if (new_port) {
server_update_port(router->service->dbref->server, new_port); server_update_port(router->service->dbref->server, new_port);
LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_PORT is [%i]", MXS_INFO("%s: New MASTER_PORT is [%i]",
router->service->name, router->service->name,
router->service->dbref->server->port))); router->service->dbref->server->port);
return 1; return 1;
} }
@ -3654,9 +3612,9 @@ blr_set_master_user(ROUTER_INSTANCE *router, char *user) {
} }
router->user = strdup(ptr); router->user = strdup(ptr);
LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_USER is [%s]", MXS_INFO("%s: New MASTER_USER is [%s]",
router->service->name, router->service->name,
router->user))); router->user);
return 1; return 1;
} }
@ -4088,9 +4046,8 @@ char *sep = " ,=";
return -1; return -1;
} else if (strcasecmp(word, "LIKE") == 0) { } else if (strcasecmp(word, "LIKE") == 0) {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Missing LIKE clause in SHOW [GLOBAL] VARIABLES.",
"%s: Missing LIKE clause in SHOW [GLOBAL] VARIABLES.", router->service->name);
router->service->name)));
return -1; return -1;
} else if (strcasecmp(word, "'SERVER_ID'") == 0) { } else if (strcasecmp(word, "'SERVER_ID'") == 0) {
if (router->set_master_server_id) { if (router->set_master_server_id) {
@ -4265,9 +4222,8 @@ char *sep = " ,=";
return -1; return -1;
} else if (strcasecmp(word, "LIKE") == 0) { } else if (strcasecmp(word, "LIKE") == 0) {
if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("%s: Missing LIKE clause in SHOW [GLOBAL] STATUS.",
"%s: Missing LIKE clause in SHOW [GLOBAL] STATUS.", router->service->name);
router->service->name)));
return -1; return -1;
} else if (strcasecmp(word, "'Uptime'") == 0) { } else if (strcasecmp(word, "'Uptime'") == 0) {
char uptime[41]=""; char uptime[41]="";
@ -4444,11 +4400,10 @@ time_t t_now = time(0);
/* skip servers with state = 0 */ /* skip servers with state = 0 */
if ( (sptr->state == BLRS_DUMPING) && (sptr->heartbeat > 0) && ((t_now + 1 - sptr->lastReply) >= sptr->heartbeat) ) if ( (sptr->state == BLRS_DUMPING) && (sptr->heartbeat > 0) && ((t_now + 1 - sptr->lastReply) >= sptr->heartbeat) )
{ {
LOGIF(LM, (skygw_log_write( MXS_NOTICE("Sending Heartbeat to slave server-id %d in State %d, cstate %d. "
LOGFILE_MESSAGE, "Sending Heartbeat to slave server-id %d in State %d, cstate %d. "
"Heartbeat interval is %d, last event time is %lu", "Heartbeat interval is %d, last event time is %lu",
sptr->serverid, sptr->state, sptr->cstate, sptr->heartbeat, sptr->serverid, sptr->state, sptr->cstate, sptr->heartbeat,
(unsigned long)sptr->lastReply))); (unsigned long)sptr->lastReply);
blr_slave_send_heartbeat(router, sptr); blr_slave_send_heartbeat(router, sptr);

17
server/modules/routing/binlog/maxbinlogcheck.c
View File

@ -129,8 +129,7 @@ int main(int argc, char **argv) {
mxs_log_set_priority_enabled(LOG_DEBUG, debug_out); mxs_log_set_priority_enabled(LOG_DEBUG, debug_out);
if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) { if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) {
LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, MXS_ERROR("Memory allocation failed for ROUTER_INSTANCE");
"Error: Memory allocation failed for ROUTER_INSTANCE")));
mxs_log_flush_sync(); mxs_log_flush_sync();
mxs_log_finish(); mxs_log_finish();
@ -152,9 +151,8 @@ int main(int argc, char **argv) {
if (fd == -1) if (fd == -1)
{ {
LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, MXS_ERROR("Failed to open binlog file %s: %s",
"Failed to open binlog file %s: %s", path, strerror(errno));
path, strerror(errno))));
mxs_log_flush_sync(); mxs_log_flush_sync();
mxs_log_finish(); mxs_log_finish();
@ -175,14 +173,12 @@ int main(int argc, char **argv) {
else else
strncpy(inst->binlog_name, path, BINLOG_FNAMELEN); strncpy(inst->binlog_name, path, BINLOG_FNAMELEN);
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("maxbinlogcheck %s", binlog_check_version);
"maxbinlogcheck %s", binlog_check_version)));
if (fstat(inst->binlog_fd, &statb) == 0) if (fstat(inst->binlog_fd, &statb) == 0)
filelen = statb.st_size; filelen = statb.st_size;
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Checking %s (%s), size %lu bytes", path, inst->binlog_name, filelen);
"Checking %s (%s), size %lu bytes", path, inst->binlog_name, filelen)));
/* read binary log */ /* read binary log */
ret = blr_read_events_all_events(inst, fix_file, debug_out); ret = blr_read_events_all_events(inst, fix_file, debug_out);
@ -191,8 +187,7 @@ int main(int argc, char **argv) {
mxs_log_flush_sync(); mxs_log_flush_sync();
LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, MXS_NOTICE("Check retcode: %i, Binlog Pos = %lu", ret, inst->binlog_position);
"Check retcode: %i, Binlog Pos = %lu", ret, inst->binlog_position)));
mxs_log_flush_sync(); mxs_log_flush_sync();
mxs_log_finish(); mxs_log_finish();