diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index 475d4e4eb..6be4414ea 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -157,9 +157,7 @@ version() void ModuleInit() { - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, - "Initialise binlog router module %s.\n", version_str))); + MXS_NOTICE("Initialise binlog router module %s.\n", version_str); spinlock_init(&instlock); instances = NULL; } @@ -206,17 +204,16 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; if(service->credentials.name == NULL || service->credentials.authdata == NULL) { - skygw_log_write(LE,"%s: Error: Service is missing user credentials." - " Add the missing username or passwd parameter to the service.", - service->name); + MXS_ERROR("%s: Error: Service is missing user credentials." + " Add the missing username or passwd parameter to the service.", + service->name); return NULL; } if(options == NULL || options[0] == NULL) { - skygw_log_write(LE, - "%s: Error: No router options supplied for binlogrouter", - service->name); + MXS_ERROR("%s: Error: No router options supplied for binlogrouter", + service->name); return NULL; } @@ -227,11 +224,10 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; */ if (service->dbref != NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: Warning: backend database server is provided by master.ini file " - "for use with the binlog router." - " Server section is no longer required.", - service->name))); + MXS_WARNING("%s: backend database server is provided by master.ini file " + "for use with the binlog router." + " Server section is no longer required.", + service->name); server_free(service->dbref->server); free(service->dbref); @@ -239,9 +235,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; } if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: Error: failed to allocate memory for router instance.", - service->name))); + MXS_ERROR("%s: Error: failed to allocate memory for router instance.", + service->name); return NULL; } @@ -328,10 +323,9 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; { if ((value = strchr(options[i], '=')) == NULL) { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "Warning : Unsupported router " + MXS_WARNING("Unsupported router " "option %s for binlog router.", - options[i]))); + options[i]); } else { @@ -345,20 +339,16 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; { inst->serverid = atoi(value); if (strcmp(options[i], "server-id") == 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "WARNING: Configuration setting '%s' in router_options is deprecated" - " and will be removed in a later version of MaxScale. " - "Please use the new setting '%s' instead.", - "server-id", "server_id"))); + MXS_WARNING("Configuration setting '%s' in router_options is deprecated" + " and will be removed in a later version of MaxScale. " + "Please use the new setting '%s' instead.", + "server-id", "server_id"); } if (inst->serverid <= 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Error : Service %s, invalid server-id '%s'. " - "Please configure it with a unique positive integer value (1..2^32-1)", - service->name, value))); + MXS_ERROR("Service %s, invalid server-id '%s'. " + "Please configure it with a unique positive integer value (1..2^32-1)", + service->name, value); free(inst); return NULL; @@ -384,12 +374,10 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; inst->set_master_server_id = strdup(value); } if (strcmp(options[i], "master-id") == 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "WARNING: Configuration setting '%s' in router_options is deprecated" - " and will be removed in a later version of MaxScale. " - "Please use the new setting '%s' instead.", - "master-id", "master_id"))); + MXS_WARNING("Configuration setting '%s' in router_options is deprecated" + " and will be removed in a later version of MaxScale. " + "Please use the new setting '%s' instead.", + "master-id", "master_id"); } } 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); if (h_val <= 0 || (errno == ERANGE)) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Warning : invalid heartbeat period %s." - " Setting it to default value %ld.", - value, inst->heartbeat))); + MXS_WARNING("Invalid heartbeat period %s." + " Setting it to default value %ld.", + value, inst->heartbeat); } else { inst->heartbeat = h_val; } @@ -485,20 +471,17 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; } else { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "Warning : Unsupported router " - "option %s for binlog router.", - options[i]))); + MXS_WARNING("Unsupported router " + "option %s for binlog router.", + options[i]); } } } } else { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "%s: Error: No router options supplied for binlogrouter", - service->name))); + MXS_ERROR("%s: Error: No router options supplied for binlogrouter", + service->name); } if (inst->fileroot == NULL) @@ -520,18 +503,16 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; strcpy(inst->prevbinlog, ""); if ((inst->binlogdir == NULL) || (inst->binlogdir != NULL && !strlen(inst->binlogdir))) { - skygw_log_write_flush(LOGFILE_ERROR, - "Error : Service %s, binlog directory is not specified", - service->name); + MXS_ERROR("Service %s, binlog directory is not specified", + service->name); free(inst); return NULL; } if (inst->serverid <= 0) { - skygw_log_write_flush(LOGFILE_ERROR, - "Error : Service %s, server-id is not configured. " - "Please configure it with a unique positive integer value (1..2^32-1)", - service->name); + MXS_ERROR("Service %s, server-id is not configured. " + "Please configure it with a unique positive integer value (1..2^32-1)", + service->name); free(inst); return NULL; } @@ -545,12 +526,11 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; mkdir_rval = mkdir(inst->binlogdir, 0700); if (mkdir_rval == -1) { char err_msg[STRERROR_BUFLEN]; - skygw_log_write_flush(LOGFILE_ERROR, - "Error : Service %s, Failed to create binlog directory '%s': [%d] %s", - service->name, - inst->binlogdir, - errno, - strerror_r(errno, err_msg, sizeof(err_msg))); + MXS_ERROR("Service %s, Failed to create binlog directory '%s': [%d] %s", + service->name, + inst->binlogdir, + errno, + strerror_r(errno, err_msg, sizeof(err_msg))); free(inst); return NULL; @@ -561,9 +541,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; if (service->users == NULL) { service->users = (void *)mysql_users_alloc(); if (service->users == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: Error allocating dbusers in createInstance", - inst->service->name))); + MXS_ERROR("%s: Error allocating dbusers in createInstance", + inst->service->name); free(inst); return NULL; @@ -576,9 +555,8 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; SERVER *server; server = server_alloc("_none_", "MySQLBackend", (int)3306); if (server == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: Error for server_alloc in createInstance", - inst->service->name))); + MXS_ERROR("%s: Error for server_alloc in createInstance", + inst->service->name); if (service->users) { users_free(service->users); service->users = NULL; @@ -605,11 +583,10 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; rc = ini_parse(filename, blr_handler_config, inst); - LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, - "%s: %s parse result is %d", - inst->service->name, - filename, - rc))); + MXS_INFO("%s: %s parse result is %d", + inst->service->name, + filename, + rc); /* * retcode: @@ -618,17 +595,15 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; if (rc != 0) { if (rc == -1) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: master.ini file not found in %s." - " Master registration cannot be started." - " Configure with CHANGE MASTER TO ...", - inst->service->name, inst->binlogdir))); + MXS_ERROR("%s: master.ini file not found in %s." + " Master registration cannot be started." + " Configure with CHANGE MASTER TO ...", + inst->service->name, inst->binlogdir); } else { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: master.ini file with errors in %s." - " Master registration cannot be started." - " Fix errors in it or configure with CHANGE MASTER TO ...", - inst->service->name, inst->binlogdir))); + MXS_ERROR("%s: master.ini file with errors in %s." + " Master registration cannot be started." + " Fix errors in it or configure with CHANGE MASTER TO ...", + inst->service->name, inst->binlogdir); } /* 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) */ if (blr_file_init(inst) == 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "%s: Service not started due to lack of binlog directory %s", - service->name, - inst->binlogdir))); + MXS_ERROR("%s: Service not started due to lack of binlog directory %s", + service->name, + inst->binlogdir); if (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*/ if (inst->trx_safe) { - LOGIF(LT, (skygw_log_write_flush( - LOGFILE_TRACE, - "%s: Service has transaction safety option set to ON", - service->name))); + MXS_INFO("%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) { /* Check current binlog */ - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, "Validating binlog file '%s' ...", - inst->binlog_name))); + MXS_NOTICE("Validating binlog file '%s' ...", + inst->binlog_name); if (inst->trx_safe && !blr_check_binlog(inst)) { /* Don't start replication, just return */ @@ -717,15 +687,11 @@ char task_name[BLRM_TASK_NAME_LEN+1] = ""; } if (!inst->trx_safe) { - LOGIF(LT, (skygw_log_write_flush( - LOGFILE_TRACE, - "Current binlog file is %s, current pos is %lu\n", - inst->binlog_name, inst->binlog_position))); + MXS_INFO("Current binlog file is %s, current pos is %lu\n", + inst->binlog_name, inst->binlog_position); } else { - LOGIF(LT, (skygw_log_write_flush( - LOGFILE_TRACE, - "Current binlog file is %s, safe pos %lu, current pos is %lu\n", - inst->binlog_name, inst->binlog_position, inst->current_pos))); + MXS_INFO("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 */ @@ -752,20 +718,16 @@ newSession(ROUTER *instance, SESSION *session) ROUTER_INSTANCE *inst = (ROUTER_INSTANCE *)instance; ROUTER_SLAVE *slave; - LOGIF(LD, (skygw_log_write_flush( - LOGFILE_DEBUG, - "binlog router: %lu [newSession] new router session with " - "session %p, and inst %p.", - pthread_self(), - session, - inst))); + MXS_DEBUG("binlog router: %lu [newSession] new router session with " + "session %p, and inst %p.", + pthread_self(), + session, + inst); if ((slave = (ROUTER_SLAVE *)calloc(1, sizeof(ROUTER_SLAVE))) == NULL) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Insufficient memory to create new slave session for binlog router"))); + MXS_ERROR("Insufficient memory to create new slave session for binlog router"); return NULL; } @@ -849,14 +811,12 @@ int prev_val; } spinlock_release(&router->lock); - LOGIF(LD, (skygw_log_write_flush( - LOGFILE_DEBUG, - "%lu [freeSession] Unlinked router_client_session %p from " - "router %p. Connections : %d. ", - pthread_self(), - slave, - router, - prev_val-1))); + MXS_DEBUG("%lu [freeSession] Unlinked router_client_session %p from " + "router %p. Connections : %d. ", + pthread_self(), + slave, + router, + prev_val-1); if (slave->hostname) free(slave->hostname); @@ -886,16 +846,12 @@ ROUTER_SLAVE *slave = (ROUTER_SLAVE *)router_session; /* * We must be closing the master session. */ - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: Master %s disconnected after %ld seconds. " - "%lu events read,", - router->service->name, router->service->dbref->server->name, - time(0) - router->connect_time, router->stats.n_binlogs_ses))); - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Binlog router close session with master server %s", - router->service->dbref->server->unique_name))); + MXS_NOTICE("%s: Master %s disconnected after %ld seconds. " + "%lu events read,", + router->service->name, router->service->dbref->server->name, + time(0) - router->connect_time, router->stats.n_binlogs_ses); + MXS_ERROR("Binlog router close session with master server %s", + router->service->dbref->server->unique_name); blr_master_reconnect(router); return; } @@ -910,27 +866,24 @@ ROUTER_SLAVE *slave = (ROUTER_SLAVE *)router_session; atomic_add(&router->stats.n_registered, -1); if (slave->state > 0) { - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: Slave %s, server id %d, disconnected after %ld seconds. " - "%d SQL commands, %d events sent (%lu bytes), binlog '%s', last position %lu", - router->service->name, slave->dcb->remote, - slave->serverid, - time(0) - slave->connect_time, - slave->stats.n_queries, - slave->stats.n_events, - slave->stats.n_bytes, - slave->binlogfile, - (unsigned long)slave->binlog_pos))); + MXS_NOTICE("%s: Slave %s, server id %d, disconnected after %ld seconds. " + "%d SQL commands, %d events sent (%lu bytes), binlog '%s', " + "last position %lu", + router->service->name, slave->dcb->remote, + slave->serverid, + time(0) - slave->connect_time, + slave->stats.n_queries, + slave->stats.n_events, + slave->stats.n_bytes, + slave->binlogfile, + (unsigned long)slave->binlog_pos); } else { - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: Slave %s, server id %d, disconnected after %ld seconds. " - "%d SQL commands", - router->service->name, slave->dcb->remote, - slave->serverid, - time(0) - slave->connect_time, - slave->stats.n_queries))); + MXS_NOTICE("%s: Slave %s, server id %d, disconnected after %ld seconds. " + "%d SQL commands", + router->service->name, slave->dcb->remote, + slave->serverid, + time(0) - slave->connect_time, + slave->stats.n_queries); } /* @@ -1440,33 +1393,29 @@ unsigned long mysql_errno; free(router->m_errmsg); router->m_errmsg = strdup(errmsg); - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, "%s: Master connection error %lu '%s' in state '%s', " - "%sattempting reconnect to master %s:%d", - router->service->name, mysql_errno, errmsg, - blrm_states[router->master_state], msg, - router->service->dbref->server->name, - router->service->dbref->server->port))); + MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', " + "%sattempting reconnect to master %s:%d", + router->service->name, mysql_errno, errmsg, + blrm_states[router->master_state], msg, + router->service->dbref->server->name, + router->service->dbref->server->port); } else { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, "%s: Master connection error %lu '%s' in state '%s', " - "%sattempting reconnect to master %s:%d", - router->service->name, router->m_errno, router->m_errmsg, - blrm_states[router->master_state], msg, - router->service->dbref->server->name, - router->service->dbref->server->port))); + MXS_ERROR("%s: Master connection error %lu '%s' in state '%s', " + "%sattempting reconnect to master %s:%d", + router->service->name, router->m_errno, router->m_errmsg, + blrm_states[router->master_state], msg, + router->service->dbref->server->name, + router->service->dbref->server->port); } if (errmsg) free(errmsg); *succp = true; dcb_close(backend_dcb); - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: Master %s disconnected after %ld seconds. " - "%lu events read.", - router->service->name, router->service->dbref->server->name, - time(0) - router->connect_time, router->stats.n_binlogs_ses))); + MXS_NOTICE("%s: Master %s disconnected after %ld seconds. " + "%lu events read.", + router->service->name, router->service->dbref->server->name, + time(0) - router->connect_time, router->stats.n_binlogs_ses); blr_master_reconnect(router); } @@ -1734,10 +1683,10 @@ SERVICE *service; { return blr_handle_config_item(name, value, inst); } else { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Error : master.ini has an invalid section [%s], it should be [binlog_configuration]. Service %s", - section, - service->name))); + MXS_ERROR("master.ini has an invalid section [%s], it should be [binlog_configuration]. " + "Service %s", + section, + service->name); return 0; } @@ -1796,9 +1745,8 @@ char *service_user = NULL; char *service_passwd = NULL; if (serviceGetUser(service, &service_user, &service_passwd) == 0) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "failed to get service user details for service %s", - service->name))); + MXS_ERROR("failed to get service user details for service %s", + service->name); return 1; } @@ -1806,10 +1754,9 @@ char *service_passwd = NULL; dpwd = decryptPassword(service->credentials.authdata); if (!dpwd) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "decrypt password failed for service user %s, service %s", - service_user, - service->name))); + MXS_ERROR("decrypt password failed for service user %s, service %s", + service_user, + service->name); return 1; } @@ -1817,9 +1764,8 @@ char *service_passwd = NULL; newpasswd = create_hex_sha1_sha1_passwd(dpwd); if (!newpasswd) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "create hex_sha1_sha1_password failed for service user %s", - service_user))); + MXS_ERROR("create hex_sha1_sha1_password failed for service user %s", + service_user); free(dpwd); return 1; @@ -1859,10 +1805,8 @@ SERVICE *service; if (loaded < 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Error : Unable to load users for service %s", - service->name))); + MXS_ERROR("Unable to load users for service %s", + service->name); /* Try loading authentication data from file cache */ @@ -1870,29 +1814,23 @@ SERVICE *service; if (loaded != -1) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Service %s, Using cached credential information file %s.", - service->name, - path))); + MXS_ERROR("Service %s, Using cached credential information file %s.", + service->name, + path); } else { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Error: Service %s, Unable to read cache credential information from %s." - " No database user added to service users table.", - service->name, - path))); + MXS_ERROR("Service %s, Unable to read cache credential information from %s." + " No database user added to service users table.", + service->name, + path); } } else { /* don't update cache if no user was loaded */ if (loaded == 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Service %s: failed to load any user " - "information. Authentication will " - "probably fail as a result.", - service->name))); + MXS_ERROR("Service %s: failed to load any user " + "information. Authentication will " + "probably fail as a result.", + service->name); } else { /* update cached data */ blr_save_dbusers(router); @@ -1936,12 +1874,11 @@ int mkdir_rval = 0; if (mkdir_rval == -1) { char err_msg[STRERROR_BUFLEN]; - skygw_log_write(LOGFILE_ERROR, - "Error : Service %s, Failed to create directory '%s': [%d] %s", - service->name, - path, - errno, - strerror_r(errno, err_msg, sizeof(err_msg))); + MXS_ERROR("Service %s, Failed to create directory '%s': [%d] %s", + service->name, + path, + errno, + strerror_r(errno, err_msg, sizeof(err_msg))); return -1; } @@ -1999,9 +1936,7 @@ static int blr_check_binlog(ROUTER_INSTANCE *router) { n = blr_read_events_all_events(router, 0, 0); - LOGIF(LD, (skygw_log_write_flush( - LOGFILE_DEBUG, - "blr_read_events_all_events() ret = %i\n", n))); + MXS_DEBUG("blr_read_events_all_events() ret = %i\n", n); if (n != 0) { char msg_err[BINLOG_ERROR_MSG_LEN + 1] = ""; @@ -2017,11 +1952,9 @@ static int blr_check_binlog(ROUTER_INSTANCE *router) { /* set last_safe_pos */ router->last_safe_pos = router->binlog_position; - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Error found in binlog file %s. Safe starting pos is %lu", - router->binlog_name, - router->binlog_position))); + MXS_ERROR("Error found in binlog file %s. Safe starting pos is %lu", + router->binlog_name, + router->binlog_position); return 0; } else { diff --git a/server/modules/routing/binlog/blr_file.c b/server/modules/routing/binlog/blr_file.c index dc1683b9c..9a6e49f7a 100644 --- a/server/modules/routing/binlog/blr_file.c +++ b/server/modules/routing/binlog/blr_file.c @@ -65,7 +65,7 @@ static int blr_file_create(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); int blr_file_get_next_binlogname(ROUTER_INSTANCE *router); int blr_file_new_binlog(ROUTER_INSTANCE *router, char *file); @@ -120,9 +120,8 @@ struct dirent *dp; } if (access(router->binlogdir, R_OK) == -1) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Unable to read the binlog directory %s.", - router->service->name, router->binlogdir))); + MXS_ERROR("%s: Unable to read the binlog directory %s.", + router->service->name, router->binlogdir); return 0; } @@ -131,10 +130,9 @@ struct dirent *dp; if ((dirp = opendir(path)) == NULL) { char err_msg[BLRM_STRERROR_R_MSG_SIZE]; - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Unable to read the binlog directory %s, %s.", - router->service->name, router->binlogdir, - strerror_r(errno, err_msg, sizeof(err_msg))))); + MXS_ERROR("%s: Unable to read the binlog directory %s, %s.", + router->service->name, router->binlogdir, + strerror_r(errno, err_msg, sizeof(err_msg))); return 0; } while ((dp = readdir(dirp)) != NULL) @@ -232,9 +230,8 @@ int fd; { char err_msg[STRERROR_BUFLEN]; - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Failed to create binlog file %s, %s.", - router->service->name, path, strerror_r(errno, err_msg, sizeof(err_msg))))); + MXS_ERROR("%s: Failed to create binlog file %s, %s.", + router->service->name, path, strerror_r(errno, err_msg, sizeof(err_msg))); return 0; } fsync(fd); @@ -264,9 +261,8 @@ int fd; if ((fd = open(path, O_RDWR|O_APPEND, 0666)) == -1) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to open binlog file %s for append.", - path))); + MXS_ERROR("Failed to open binlog file %s for append.", + path); return; } fsync(fd); @@ -280,9 +276,8 @@ int fd; } else { /* If for any reason the file's length is between 1 and 3 bytes * then report an error. */ - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: binlog file %s has an invalid length %lu.", - router->service->name, path, router->current_pos))); + MXS_ERROR("%s: binlog file %s has an invalid length %lu.", + router->service->name, path, router->current_pos); close(fd); spinlock_release(&router->binlog_lock); return; @@ -309,12 +304,11 @@ int n; hdr->next_pos - hdr->event_size)) != hdr->event_size) { char err_msg[STRERROR_BUFLEN]; - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Failed to write binlog record at %d of %s, %s. " - "Truncating to previous record.", - router->service->name, hdr->next_pos - hdr->event_size, - router->binlog_name, - strerror_r(errno, err_msg, sizeof(err_msg))))); + MXS_ERROR("%s: Failed to write binlog record at %d of %s, %s. " + "Truncating to previous record.", + router->service->name, hdr->next_pos - hdr->event_size, + router->binlog_name, + strerror_r(errno, err_msg, sizeof(err_msg))); /* Remove any partual event that was written */ ftruncate(router->binlog_fd, hdr->next_pos - hdr->event_size); return 0; @@ -378,8 +372,7 @@ BLFILE *file; if ((file->fd = open(path, O_RDONLY, 0666)) == -1) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to open binlog file %s", path))); + MXS_ERROR("Failed to open binlog file %s", path); free(file); spinlock_release(&router->fileslock); return NULL; @@ -458,9 +451,8 @@ struct stat statb; switch (n) { case 0: - LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, - "Reached end of binlog file '%s' at %lu.", - file->binlogname, pos))); + MXS_DEBUG("Reached end of binlog file '%s' at %lu.", + file->binlogname, pos); /* set ok indicator */ hdr->ok = SLAVE_POS_READ_OK; @@ -514,21 +506,19 @@ struct stat statb; if (hdr->next_pos < pos && hdr->event_type != ROTATE_EVENT) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Next position in header appears to be incorrect " - "rereading event header at pos %lu in file %s, " - "file size is %lu. Master will write %lu in %s next.", - pos, file->binlogname, filelen, router->binlog_position, - router->binlog_name))); + MXS_ERROR("Next position in header appears to be incorrect " + "rereading event header at pos %lu in file %s, " + "file size is %lu. Master will write %lu in %s next.", + pos, file->binlogname, filelen, router->binlog_position, + router->binlog_name); if ((n = pread(file->fd, hdbuf, BINLOG_EVENT_HDR_LEN, pos)) != BINLOG_EVENT_HDR_LEN) { switch (n) { case 0: - LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, - "Reached end of binlog file at %lu.", - pos))); + MXS_DEBUG("Reached end of binlog file at %lu.", + pos); /* set ok indicator */ hdr->ok = SLAVE_POS_READ_OK; @@ -570,9 +560,8 @@ struct stat statb; } else { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Next position corrected by " - "rereading"))); + MXS_ERROR("Next position corrected by " + "rereading"); } } 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'", 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); @@ -667,12 +656,12 @@ blr_close_binlog(ROUTER_INSTANCE *router, BLFILE *file) /** * Log the event header of binlog event * - * @param file The log file into which to write the entry - * @param msg A message strign to preceed the header with - * @param ptr The event header raw data + * @param priority The syslog priority of the message (LOG_ERR, LOG_WARNING, etc.) + * @param msg A message strign to preceed the header with + * @param ptr The event header raw data */ 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; int i; @@ -681,8 +670,7 @@ int i; bufp += sprintf(bufp, "%s: ", msg); for (i = 0; i < BINLOG_EVENT_HDR_LEN; 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)); if (router->binlog_fd == -1) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Current binlog file %s is not open", - router->binlog_name))); + MXS_ERROR("Current binlog file %s is not open", + router->binlog_name); return 1; } @@ -872,10 +859,9 @@ int fde_seen = 0; switch (n) { case 0: - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "End of binlog file [%s] at %llu.", - router->binlog_name, - pos))); + MXS_DEBUG("End of binlog file [%s] at %llu.", + router->binlog_name, + pos); if (n_transactions) average_events = (double)((double)total_events / (double)n_transactions) * (1.0); if (n_transactions) @@ -901,24 +887,25 @@ int fde_seen = 0; blr_format_event_size(&average_bytes, average_label); blr_format_event_size(&format_max_bytes, max_label); - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Transaction Summary for binlog '%s'\n" - "\t\t\tDescription %17s%17s%17s\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 Bytes %16.1f%s%16.1f%s%16.1f%s", router->binlog_name, - "Total", "Average", "Max", - n_transactions, total_events, - average_events, max_events, - format_total_bytes, total_label, average_bytes, average_label, format_max_bytes, max_label))); + MXS_NOTICE("Transaction Summary for binlog '%s'\n" + "\t\t\tDescription %17s%17s%17s\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 Bytes %16.1f%s%16.1f%s%16.1f%s", + router->binlog_name, + "Total", "Average", "Max", + n_transactions, total_events, + average_events, max_events, + format_total_bytes, total_label, + average_bytes, average_label, + format_max_bytes, max_label); } if (pending_transaction) { - LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, - "Warning : Binlog file %s contains a previous Opened Transaction" - " @ %llu. This pos is safe for slaves", - router->binlog_name, - last_known_commit))); + MXS_WARNING("Binlog file %s contains a previous Opened " + "Transaction @ %llu. This pos is safe for slaves", + router->binlog_name, + last_known_commit); } @@ -927,24 +914,21 @@ int fde_seen = 0; { char err_msg[BLRM_STRERROR_R_MSG_SIZE+1] = ""; strerror_r(errno, err_msg, BLRM_STRERROR_R_MSG_SIZE); - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Failed to read binlog file %s at position %llu" - " (%s).", router->binlog_name, - pos, err_msg))); + MXS_ERROR("Failed to read binlog file %s at position %llu" + " (%s).", router->binlog_name, + pos, err_msg); if (errno == EBADF) - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Bad file descriptor in read binlog for file %s" - ", descriptor %d.", - router->binlog_name, router->binlog_fd))); + MXS_ERROR("Bad file descriptor in read binlog for file %s" + ", descriptor %d.", + router->binlog_name, router->binlog_fd); break; } default: - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Short read when reading the header. " - "Expected 19 bytes but got %d bytes. " - "Binlog file is %s, position %llu", - n, router->binlog_name, pos))); + MXS_ERROR("Short read when reading the header. " + "Expected 19 bytes but got %d bytes. " + "Binlog file is %s, position %llu", + n, router->binlog_name, pos); break; } @@ -960,10 +944,9 @@ int fde_seen = 0; router->pending_transaction = 1; pending_transaction = 0; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Warning : pending transaction has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("pending transaction has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); return 0; } else { @@ -973,16 +956,14 @@ int fde_seen = 0; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1010,21 +991,19 @@ int fde_seen = 0; if (router->mariadb10_compat) { if (hdr.event_type > MAX_EVENT_TYPE_MARIADB10) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Invalid MariaDB 10 event type 0x%x. " - "Binlog file is %s, position %llu", - hdr.event_type, - router->binlog_name, pos))); + MXS_ERROR("Invalid MariaDB 10 event type 0x%x. " + "Binlog file is %s, position %llu", + hdr.event_type, + router->binlog_name, pos); event_error = 1; } } else { if (hdr.event_type > MAX_EVENT_TYPE) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Invalid event type 0x%x. " - "Binlog file is %s, position %llu", - hdr.event_type, - router->binlog_name, pos))); + MXS_ERROR("Invalid event type 0x%x. " + "Binlog file is %s, position %llu", + hdr.event_type, + router->binlog_name, pos); event_error = 1; } @@ -1036,19 +1015,17 @@ int fde_seen = 0; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found in %s. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_name, - router->binlog_position, - router->current_pos))); + MXS_WARNING("an error has been found in %s. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_name, + router->binlog_position, + router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1058,25 +1035,22 @@ int fde_seen = 0; if (hdr.event_size <= 0) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Event size error: " - "size %d at %llu.", - hdr.event_size, pos))); + MXS_ERROR("Event size error: " + "size %d at %llu.", + hdr.event_size, pos); router->binlog_position = last_known_commit; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1087,26 +1061,23 @@ int fde_seen = 0; /* Allocate a GWBUF for the event */ if ((result = gwbuf_alloc(hdr.event_size)) == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Failed to allocate memory for binlog entry, " - "size %d at %llu.", - hdr.event_size, pos))); + MXS_ERROR("Failed to allocate memory for binlog entry, " + "size %d at %llu.", + hdr.event_size, pos); router->binlog_position = last_known_commit; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1125,25 +1096,23 @@ int fde_seen = 0; { char err_msg[BLRM_STRERROR_R_MSG_SIZE+1] = ""; strerror_r(errno, err_msg, BLRM_STRERROR_R_MSG_SIZE); - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Error reading the event at %llu in %s. " - "%s, expected %d bytes.", - pos, router->binlog_name, - err_msg, hdr.event_size - BINLOG_EVENT_HDR_LEN))); + MXS_ERROR("Error reading the event at %llu in %s. " + "%s, expected %d bytes.", + pos, router->binlog_name, + err_msg, hdr.event_size - BINLOG_EVENT_HDR_LEN); } else { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Short read when reading the event at %llu in %s. " - "Expected %d bytes got %d bytes.", - pos, router->binlog_name, hdr.event_size - BINLOG_EVENT_HDR_LEN, n))); + MXS_ERROR("Short read when reading the event at %llu in %s. " + "Expected %d bytes got %d bytes.", + pos, router->binlog_name, + hdr.event_size - BINLOG_EVENT_HDR_LEN, n); if (filelen > 0 && filelen - pos < hdr.event_size) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog event is close to the end of the binlog file %s, " - " size is %lu.", - router->binlog_name, filelen))); + MXS_ERROR("Binlog event is close to the end of the binlog file %s, " + " size is %lu.", + router->binlog_name, filelen); } } @@ -1153,16 +1122,14 @@ int fde_seen = 0; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1209,9 +1176,8 @@ int fde_seen = 0; } if(debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "- Format Description event FDE @ %llu, size %lu, time %lu (%s)", - pos, (unsigned long)hdr.event_size, fde_event.event_time, buf_t))); + MXS_DEBUG("- Format Description event FDE @ %llu, size %lu, time %lu (%s)", + pos, (unsigned long)hdr.event_size, fde_event.event_time, buf_t); event_header_length = ptr[2 + 50 + 4]; 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); if(debug) { - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - " FDE ServerVersion [%50s]", ptr + 2))); + MXS_DEBUG(" FDE ServerVersion [%50s]", ptr + 2); - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - " FDE Header EventLength %i" - ", N. of supported MySQL/MariaDB events %i", - event_header_length, - (n_events - event_header_ntypes)))); + MXS_DEBUG(" FDE Header EventLength %i" + ", N. of supported MySQL/MariaDB events %i", + event_header_length, + (n_events - event_header_ntypes)); } if (event_header_ntypes < n_events) { @@ -1247,10 +1211,10 @@ int fde_seen = 0; check_alg = checksum[0]; if(debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - " FDE Checksum alg desc %i, alg type %s", - check_alg, - check_alg == 1 ? "BINLOG_CHECKSUM_ALG_CRC32" : "NONE or UNDEF"))); + MXS_DEBUG(" FDE Checksum alg desc %i, alg type %s", + check_alg, + check_alg == 1 ? + "BINLOG_CHECKSUM_ALG_CRC32" : "NONE or UNDEF"); if (check_alg == 1) { found_chksum = 1; } else { @@ -1283,9 +1247,8 @@ int fde_seen = 0; file[slen] = 0; if(debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "- Rotate event @ %llu, next file is [%s] @ %lu", - pos, file, new_pos))); + MXS_DEBUG("- Rotate event @ %llu, next file is [%s] @ %lu", + pos, file, new_pos); } /* If MariaDB 10 compatibility: @@ -1305,11 +1268,11 @@ int fde_seen = 0; if (flags == 0) { if (pending_transaction > 0) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Transaction cannot be @ pos %llu: " - "Another MariaDB 10 transaction (GTID %u-%u-%lu)" - " was opened at %llu", - pos, domainid, hdr.serverid, n_sequence, last_known_commit))); + MXS_ERROR("Transaction cannot be @ pos %llu: " + "Another MariaDB 10 transaction (GTID %u-%u-%lu)" + " was opened at %llu", + pos, domainid, hdr.serverid, + n_sequence, last_known_commit); gwbuf_free(result); @@ -1321,10 +1284,9 @@ int fde_seen = 0; event_bytes = 0; if (debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "> MariaDB 10 Transaction (GTID %u-%u-%lu)" - " starts @ pos %llu", - domainid, hdr.serverid, n_sequence, pos))); + MXS_DEBUG("> MariaDB 10 Transaction (GTID %u-%u-%lu)" + " starts @ pos %llu", + domainid, hdr.serverid, n_sequence, pos); } } } @@ -1350,10 +1312,9 @@ int fde_seen = 0; /* A transaction starts with this event */ if (strncmp(statement_sql, "BEGIN", 5) == 0) { if (pending_transaction > 0) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: Transaction cannot be @ pos %llu: " - "Another transaction was opened at %llu", - pos, last_known_commit))); + MXS_ERROR("Transaction cannot be @ pos %llu: " + "Another transaction was opened at %llu", + pos, last_known_commit); free(statement_sql); gwbuf_free(result); @@ -1366,8 +1327,7 @@ int fde_seen = 0; event_bytes = 0; if (debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "> Transaction starts @ pos %llu", pos))); + MXS_DEBUG("> Transaction starts @ pos %llu", pos); } } @@ -1377,8 +1337,8 @@ int fde_seen = 0; pending_transaction = 3; if (debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - " Transaction @ pos %llu, closing @ %llu", last_known_commit, pos))); + MXS_DEBUG(" Transaction @ pos %llu, closing @ %llu", + last_known_commit, pos); } } free(statement_sql); @@ -1391,15 +1351,15 @@ int fde_seen = 0; if (pending_transaction > 0) { pending_transaction = 2; if (debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - " Transaction XID @ pos %llu, closing @ %llu", last_known_commit, pos))); + MXS_DEBUG(" Transaction XID @ pos %llu, closing @ %llu", + last_known_commit, pos); } } if (pending_transaction > 1) { if (debug) - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "< Transaction @ pos %llu, is now closed @ %llu. %lu events seen", last_known_commit, pos, transaction_events))); + MXS_DEBUG("< Transaction @ pos %llu, is now closed @ %llu. %lu events seen", + last_known_commit, pos, transaction_events); pending_transaction = 0; last_known_commit = pos; @@ -1415,27 +1375,24 @@ int fde_seen = 0; /* pos and next_pos sanity checks */ if (hdr.next_pos > 0 && hdr.next_pos < pos) { - LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, - "Binlog %s: next pos %u < pos %llu, truncating to %llu", - router->binlog_name, - hdr.next_pos, - pos, - pos))); + MXS_INFO("Binlog %s: next pos %u < pos %llu, truncating to %llu", + router->binlog_name, + hdr.next_pos, + pos, + pos); router->binlog_position = last_known_commit; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1444,29 +1401,26 @@ int fde_seen = 0; } if (hdr.next_pos > 0 && hdr.next_pos != (pos + hdr.event_size)) { - LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, - "Binlog %s: next pos %u != (pos %llu + event_size %u), truncating to %llu", - router->binlog_name, - hdr.next_pos, - pos, - hdr.event_size, - pos))); + MXS_INFO("Binlog %s: next pos %u != (pos %llu + event_size %u), truncating to %llu", + router->binlog_name, + hdr.next_pos, + pos, + hdr.event_size, + pos); router->binlog_position = last_known_commit; router->current_safe_event = last_known_commit; router->current_pos = pos; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); if (fix) { if (ftruncate(router->binlog_fd, router->binlog_position) == 0) { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Binlog file %s has been truncated at %lu", - router->binlog_name, - router->binlog_position))); + MXS_NOTICE("Binlog file %s has been truncated at %lu", + router->binlog_name, + router->binlog_position); fsync(router->binlog_fd); } } @@ -1488,8 +1442,8 @@ int fde_seen = 0; pos = hdr.next_pos; } else { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Current event type %d @ %llu has nex pos = %u : exiting", hdr.event_type, pos, hdr.next_pos))); + MXS_ERROR("Current event type %d @ %llu has nex pos = %u : exiting", + hdr.event_type, pos, hdr.next_pos); break; } @@ -1497,20 +1451,18 @@ int fde_seen = 0; } if (pending_transaction) { - LOGIF(LT, (skygw_log_write_flush(LOGFILE_TRACE, - "Binlog %s contains an Open Transaction, truncating to %llu", - router->binlog_name, - last_known_commit))); + MXS_INFO("Binlog %s contains an Open Transaction, truncating to %llu", + router->binlog_name, + last_known_commit); router->binlog_position = last_known_commit; router->current_safe_event = last_known_commit; router->current_pos = pos; router->pending_transaction = 1; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "warning : an error has been found. " - "Setting safe pos to %lu, current pos %lu", - router->binlog_position, router->current_pos))); + MXS_WARNING("an error has been found. " + "Setting safe pos to %lu, current pos %lu", + router->binlog_position, router->current_pos); return 0; } else { @@ -1707,10 +1659,9 @@ char *event_desc; event_desc = blr_get_event_description(router, first_event.event_type); - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "%lu @ %llu, %s, (%s), First EventTime", - first_event.event_time, first_event.event_pos, - event_desc != NULL ? event_desc : "unknown", buf_t))); + MXS_NOTICE("%lu @ %llu, %s, (%s), First EventTime", + first_event.event_time, first_event.event_pos, + event_desc != NULL ? event_desc : "unknown", buf_t); /* Last Event */ 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); - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "%lu @ %llu, %s, (%s), Last EventTime", - last_event.event_time, last_event.event_pos, - event_desc != NULL ? event_desc : "unknown", buf_t))); + MXS_NOTICE("%lu @ %llu, %s, (%s), Last EventTime", + last_event.event_time, last_event.event_pos, + event_desc != NULL ? event_desc : "unknown", buf_t); } diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index 7126b6a20..cb555dd30 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -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); static void *CreateMySQLAuthData(char *username, char *password, char *database); 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 *); char *blr_extract_column(GWBUF *buf, int col); 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_SLAVE_STOPPED) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "%s: Master Connect: Unexpected master state %s\n", - router->service->name, blrm_states[router->master_state]))); + MXS_ERROR("%s: Master Connect: Unexpected master state %s\n", + router->service->name, blrm_states[router->master_state]); } else { - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "%s: Master Connect: binlog state is %s\n", - router->service->name, blrm_states[router->master_state]))); + MXS_NOTICE("%s: Master Connect: binlog state is %s\n", + router->service->name, blrm_states[router->master_state]); } spinlock_release(&router->lock); return; @@ -142,8 +140,7 @@ DCB *client; spinlock_release(&router->lock); if ((client = dcb_alloc(DCB_ROLE_INTERNAL)) == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog router: failed to create DCB for dummy client"))); + MXS_ERROR("Binlog router: failed to create DCB for dummy client"); return; } router->client = client; @@ -151,8 +148,7 @@ DCB *client; client->data = CreateMySQLAuthData(router->user, router->password, ""); if ((router->session = session_alloc(router->service, client)) == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog router: failed to create session for connection to master"))); + MXS_ERROR("Binlog router: failed to create session for connection to master"); return; } client->session = router->session; @@ -169,17 +165,15 @@ DCB *client; } if (router->retry_backoff > BLR_MAX_BACKOFF) router->retry_backoff = BLR_MAX_BACKOFF; - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog router: failed to connect to master server '%s'", - router->service->dbref->server->unique_name))); + MXS_ERROR("Binlog router: failed to connect to master server '%s'", + router->service->dbref->server->unique_name); return; } router->master->remote = strdup(router->service->dbref->server->name); - LOGIF(LM,(skygw_log_write( - LOGFILE_MESSAGE, - "%s: attempting to connect to master server %s:%d, binlog %s, pos %lu", - router->service->name, router->service->dbref->server->name, router->service->dbref->server->port, router->binlog_name, router->current_pos))); + MXS_NOTICE("%s: attempting to connect to master server %s:%d, binlog %s, pos %lu", + router->service->name, router->service->dbref->server->name, + router->service->dbref->server->port, router->binlog_name, router->current_pos); router->connect_time = time(0); @@ -339,10 +333,8 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = ""; spinlock_release(&router->lock); if (router->master_state < 0 || router->master_state > BLRM_MAXSTATE) { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "Invalid master state machine state (%d) for binlog router.", - router->master_state))); + MXS_ERROR("Invalid master state machine state (%d) for binlog router.", + router->master_state); gwbuf_consume(buf, gwbuf_length(buf)); spinlock_acquire(&router->lock); @@ -351,12 +343,9 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = ""; router->active_logs = 0; spinlock_release(&router->lock); atomic_add(&router->handling_threads, -1); - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "%s: Pending reconnect in state %s.", - router->service->name, - blrm_states[router->master_state] - ))); + MXS_ERROR("%s: Pending reconnect in state %s.", + router->service->name, + blrm_states[router->master_state]); blr_restart_master(router); return; } @@ -374,10 +363,8 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = ""; * continue. The error is saved and replayed to slaves if * they also request the GTID mode. */ - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "%s: Master server does not support GTID Mode.", - router->service->name))); + MXS_ERROR("%s: Master server does not support GTID Mode.", + router->service->name); } 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 */ *(msg_err+msg_len)='\0'; - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "%s: Received error: %lu, '%s' from master during '%s' phase " - "of the master state machine.", - router->service->name, - mysql_errno, msg_err, - blrm_states[router->master_state] - ))); + MXS_ERROR("%s: Received error: %lu, '%s' from master during '%s' phase " + "of the master state machine.", + router->service->name, + mysql_errno, msg_err, + blrm_states[router->master_state]); gwbuf_consume(buf, gwbuf_length(buf)); spinlock_acquire(&router->lock); @@ -643,14 +627,12 @@ char task_name[BLRM_TASK_NAME_LEN + 1] = ""; buf = blr_make_binlog_dump(router); router->master_state = BLRM_BINLOGDUMP; router->master->func.write(router->master, buf); - LOGIF(LM,(skygw_log_write( - LOGFILE_MESSAGE, - "%s: Request binlog records from %s at " - "position %lu from master server %s:%d", - router->service->name, router->binlog_name, - router->current_pos, - router->service->dbref->server->name, - router->service->dbref->server->port))); + MXS_NOTICE("%s: Request binlog records from %s at " + "position %lu from master server %s:%d", + router->service->name, router->binlog_name, + router->current_pos, + router->service->dbref->server->name, + router->service->dbref->server->port); /* Log binlog router identity */ blr_log_identity(router); @@ -867,12 +849,10 @@ int n_bufs = -1, pn_bufs = -1; if ((msg = malloc(len)) == NULL) { - LOGIF(LE,(skygw_log_write( - LOGFILE_ERROR, - "Insufficient memory to buffer event " - "of %d bytes. Binlog %s @ %lu.", - len, router->binlog_name, - router->current_pos))); + MXS_ERROR("Insufficient memory to buffer event " + "of %d bytes. Binlog %s @ %lu.", + len, router->binlog_name, + router->current_pos); break; } @@ -891,13 +871,11 @@ int n_bufs = -1, pn_bufs = -1; } if (remainder) { - LOGIF(LE,(skygw_log_write( - LOGFILE_ERROR, - "Expected entire message in buffer " - "chain, but failed to create complete " - "message as expected. %s @ %lu", - router->binlog_name, - router->current_pos))); + MXS_ERROR("Expected entire message in buffer " + "chain, but failed to create complete " + "message as expected. %s @ %lu", + router->binlog_name, + router->current_pos); free(msg); msg = NULL; break; @@ -914,11 +892,9 @@ int n_bufs = -1, pn_bufs = -1; * until we receive the next buffer. */ router->stats.n_residuals++; - LOGIF(LD,(skygw_log_write( - LOGFILE_DEBUG, - "Residual data left after %lu records. %s @ %lu", - router->stats.n_binlogs, - router->binlog_name, router->current_pos))); + MXS_DEBUG("Residual data left after %lu records. %s @ %lu", + router->stats.n_binlogs, + router->binlog_name, router->current_pos); break; } else @@ -949,10 +925,7 @@ int n_bufs = -1, pn_bufs = -1; { msg = "error"; } - LOGIF(LM,(skygw_log_write( - LOGFILE_MESSAGE, - "Non-event message (%s) from master.", - msg))); + MXS_NOTICE("Non-event message (%s) from master.", msg); } else { @@ -964,25 +937,22 @@ int n_bufs = -1, pn_bufs = -1; /* Sanity check */ if (hdr.ok == 0 && hdr.event_size != len - 5) { - LOGIF(LE,(skygw_log_write( - LOGFILE_ERROR, - "Packet length is %d, but event size is %d, " - "binlog file %s position %lu " - "reslen is %d and preslen is %d, " - "length of previous event %d. %s", - len, hdr.event_size, - router->binlog_name, - router->current_pos, - reslen, preslen, prev_length, - (prev_length == -1 ? - (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( - LOGFILE_ERROR, - "This event (0x%x) was contained in %d GWBUFs, " - "the previous events was contained in %d GWBUFs", - router->lastEventReceived, n_bufs, pn_bufs))); + MXS_ERROR("Packet length is %d, but event size is %d, " + "binlog file %s position %lu " + "reslen is %d and preslen is %d, " + "length of previous event %d. %s", + len, hdr.event_size, + router->binlog_name, + router->current_pos, + reslen, preslen, prev_length, + (prev_length == -1 ? + (no_residual ? "No residual data from previous call" : + "Residual data from previous call") : "")); + + blr_log_packet(LOG_ERR, "Packet:", ptr, len); + MXS_ERROR("This event (0x%x) was contained in %d GWBUFs, " + "the previous events was contained in %d GWBUFs", + router->lastEventReceived, n_bufs, pn_bufs); if (msg) { free(msg); @@ -1030,14 +1000,13 @@ int n_bufs = -1, pn_bufs = -1; free(msg); msg = NULL; } - LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, - "%s: Checksum error in event " - "from master, " - "binlog %s @ %lu. " - "Closing master connection.", - router->service->name, - router->binlog_name, - router->current_pos))); + MXS_ERROR("%s: Checksum error in event " + "from master, " + "binlog %s @ %lu. " + "Closing master connection.", + router->service->name, + router->binlog_name, + router->current_pos); blr_master_close(router); blr_master_delayed_connect(router); return; @@ -1088,14 +1057,14 @@ int n_bufs = -1, pn_bufs = -1; if (flags == 0) { if (router->pending_transaction > 0) { - LOGIF(LE,(skygw_log_write_flush(LOGFILE_ERROR, - "Error: a MariaDB 10 transaction " - "is already open " - "@ %lu (GTID %u-%u-%lu) and " - "a new one starts @ %lu", - router->binlog_position, - domainid, hdr.serverid, n_sequence, - router->current_pos))); + MXS_ERROR("A MariaDB 10 transaction " + "is already open " + "@ %lu (GTID %u-%u-%lu) and " + "a new one starts @ %lu", + router->binlog_position, + domainid, hdr.serverid, + n_sequence, + router->current_pos); // 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 (router->pending_transaction > 0) { - LOGIF(LE,(skygw_log_write_flush(LOGFILE_ERROR, - "Error: a transaction is already open " - "@ %lu and a new one starts @ %lu", - router->binlog_position, - router->current_pos))); + MXS_ERROR("A transaction is already open " + "@ %lu and a new one starts @ %lu", + router->binlog_position, + router->current_pos); // 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) { // Fake format description message - LOGIF(LD,(skygw_log_write(LOGFILE_DEBUG, - "Replication fake event. " - "Binlog %s @ %lu.", - router->binlog_name, - router->current_pos))); + MXS_DEBUG("Replication fake event. " + "Binlog %s @ %lu.", + router->binlog_name, + router->current_pos); router->stats.n_fakeevents++; if (hdr.event_type == FORMAT_DESCRIPTION_EVENT) @@ -1202,13 +1169,12 @@ int n_bufs = -1, pn_bufs = -1; } else { - LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, - "%s: Received a format description " - "event that MaxScale was unable to " - "record. Event length is %d.", - router->service->name, - hdr.event_size))); - blr_log_packet(LOGFILE_ERROR, + MXS_ERROR("%s: Received a format description " + "event that MaxScale was unable to " + "record. Event length is %d.", + router->service->name, + hdr.event_size); + blr_log_packet(LOG_ERR, "Format Description Event:", ptr, len); } } @@ -1220,12 +1186,10 @@ int n_bufs = -1, pn_bufs = -1; #ifdef SHOW_EVENTS printf("Replication heartbeat\n"); #endif - LOGIF(LD,(skygw_log_write( - LOGFILE_DEBUG, - "Replication heartbeat. " - "Binlog %s @ %lu.", - router->binlog_name, - router->current_pos))); + MXS_DEBUG("Replication heartbeat. " + "Binlog %s @ %lu.", + router->binlog_name, + router->current_pos); router->stats.n_heartbeats++; @@ -1347,23 +1311,23 @@ int n_bufs = -1, pn_bufs = -1; /* No event has been sent */ if (pos == router->binlog_position) { - LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, - "No events distributed to slaves for a pending transaction in %s at %lu." - " Last event from master at %lu", - router->binlog_name, - router->binlog_position, - router->current_pos))); + MXS_ERROR("No events distributed to slaves for a pending " + "transaction in %s at %lu. " + "Last event from master at %lu", + router->binlog_name, + router->binlog_position, + router->current_pos); strncpy(err_message, "No transaction events sent", BINLOG_ERROR_MSG_LEN); } else { /* Some events have been sent */ - LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, - "Some events were not distributed to slaves for a pending transaction " - "in %s at %lu. Last distributed even at %llu, last event from master at %lu", - router->binlog_name, - router->binlog_position, - pos, - router->current_pos))); + MXS_ERROR("Some events were not distributed to slaves for a " + "pending transaction in %s at %lu. Last distributed " + "even at %llu, last event from master at %lu", + router->binlog_name, + router->binlog_position, + pos, + router->current_pos); strncpy(err_message, "Incomplete transaction events sent", BINLOG_ERROR_MSG_LEN); } @@ -1386,16 +1350,14 @@ int n_bufs = -1, pn_bufs = -1; else { router->stats.n_artificial++; - LOGIF(LD,(skygw_log_write( - LOGFILE_DEBUG, - "Artificial event not written " - "to disk or distributed. " - "Type 0x%x, Length %d, Binlog " - "%s @ %lu.", - hdr.event_type, - hdr.event_size, - router->binlog_name, - router->current_pos))); + MXS_DEBUG("Artificial event not written " + "to disk or distributed. " + "Type 0x%x, Length %d, Binlog " + "%s @ %lu.", + hdr.event_type, + hdr.event_size, + router->binlog_name, + router->current_pos); ptr += 5; if (hdr.event_type == ROTATE_EVENT) { @@ -1445,10 +1407,9 @@ int n_bufs = -1, pn_bufs = -1; spinlock_release(&router->lock); - LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, - "Error packet in binlog stream.%s @ %lu.", - router->binlog_name, - router->current_pos))); + MXS_ERROR("Error packet in binlog stream.%s @ %lu.", + router->binlog_name, + router->current_pos); router->stats.n_binlog_errors++; } @@ -1572,9 +1533,7 @@ MYSQL_session *auth_info; if (username == NULL || password == NULL) { - LOGIF(LE,(skygw_log_write( - LOGFILE_ERROR, - "You must specify both username and password for the binlog router.\n"))); + MXS_ERROR("You must specify both username and password for the binlog router.\n"); return NULL; } @@ -1690,12 +1649,11 @@ int action; * happen. Force the slave to catchup mode in order to * try to resolve the issue. */ - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Slave %d is ahead of expected position %s@%lu. " - "Expected position %d", - slave->serverid, slave->binlogfile, - (unsigned long)slave->binlog_pos, - hdr->next_pos - hdr->event_size))); + MXS_ERROR("Slave %d is ahead of expected position %s@%lu. " + "Expected position %d", + slave->serverid, slave->binlogfile, + (unsigned long)slave->binlog_pos, + 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 * - * @param file The logfile to write to - * @param msg A textual message to write before the packet - * @param ptr Pointer to the message buffer - * @param len Length of message packet + * @param priority The syslog priority of the message (LOG_ERR, LOG_WARNING, etc.) + * @param msg A textual message to write before the packet + * @param ptr Pointer to the message buffer + * @param len Length of message packet */ 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 *bufp; @@ -1809,10 +1767,9 @@ int i; for (i = 0; i < len && i < 40; i++) bufp += sprintf(bufp, "0x%02x ", ptr[i]); if (i < len) - skygw_log_write_flush(file, "%s...", buf); + MXS_LOG_MESSAGE(priority, "%s...", buf); else - skygw_log_write_flush(file, "%s", buf); - + MXS_LOG_MESSAGE(priority, "%s", buf); } /** @@ -1924,10 +1881,9 @@ int event_limit; /* error */ if (pos > end_pos) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Error: Reading saved events, the specified pos %llu " - "is ahead of current pos %lu for file %s", - pos, router->current_pos, router->binlog_name))); + MXS_ERROR("Reading saved events, the specified pos %llu " + "is ahead of current pos %lu for file %s", + pos, router->current_pos, router->binlog_name); return NULL; } @@ -1937,31 +1893,27 @@ int event_limit; switch (n) { case 0: - LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, - "Reading saved events: reached end of binlog file at %llu.", pos))); + MXS_DEBUG("Reading saved events: reached end of binlog file at %llu.", pos); break; case -1: { char err_msg[STRERROR_BUFLEN]; - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: failed to read binlog " - "file %s at position %llu" - " (%s).", router->binlog_name, - pos, strerror_r(errno, err_msg, sizeof(err_msg))))); + MXS_ERROR("Reading saved events: failed to read binlog " + "file %s at position %llu" + " (%s).", router->binlog_name, + pos, strerror_r(errno, err_msg, sizeof(err_msg))); if (errno == EBADF) - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: bad file descriptor for file %s" - ", descriptor %d.", - router->binlog_name, router->binlog_fd))); + MXS_ERROR("Reading saved events: bad file descriptor for file %s" + ", descriptor %d.", + router->binlog_name, router->binlog_fd); break; } default: - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: short read when reading the header. " - "Expected 19 bytes but got %d bytes. " - "Binlog file is %s, position %llu", - n, router->binlog_name, pos))); + MXS_ERROR("Reading saved events: short read when reading the header. " + "Expected 19 bytes but got %d bytes. " + "Binlog file is %s, position %llu", + n, router->binlog_name, pos); break; } @@ -1979,20 +1931,18 @@ int event_limit; if (hdr->event_type > event_limit) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: invalid event type 0x%x. " - "Binlog file is %s, position %llu", - hdr->event_type, - router->binlog_name, pos))); + MXS_ERROR("Reading saved events: invalid event type 0x%x. " + "Binlog file is %s, position %llu", + hdr->event_type, + router->binlog_name, pos); return NULL; } if ((result = gwbuf_alloc(hdr->event_size)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: failed to allocate memory for binlog entry, " - "size %d at %llu.", - hdr->event_size, pos))); + MXS_ERROR("Reading saved events: failed to allocate memory for binlog entry, " + "size %d at %llu.", + hdr->event_size, pos); return NULL; } @@ -2006,24 +1956,21 @@ int event_limit; if (n == -1) { char err_msg[STRERROR_BUFLEN]; - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: the event at %llu in %s. " - "%s, expected %d bytes.", - pos, router->binlog_name, - strerror_r(errno, err_msg, sizeof(err_msg)), hdr->event_size - 19))); + MXS_ERROR("Reading saved events: the event at %llu in %s. " + "%s, expected %d bytes.", + pos, router->binlog_name, + strerror_r(errno, err_msg, sizeof(err_msg)), hdr->event_size - 19); } else { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: short read when reading " - "the event at %llu in %s. " - "Expected %d bytes got %d bytes.", - pos, router->binlog_name, hdr->event_size - 19, n))); + MXS_ERROR("Reading saved events: short read when reading " + "the event at %llu in %s. " + "Expected %d bytes got %d bytes.", + pos, router->binlog_name, hdr->event_size - 19, n); if (end_pos - pos < hdr->event_size) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Error: Reading saved events: binlog event " - "is close to the end of the binlog file, " - "current file size is %llu.", end_pos))); + MXS_ERROR("Reading saved events: binlog event " + "is close to the end of the binlog file, " + "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 ((t_now - router->stats.lastReply) > (router->heartbeat + BLR_NET_LATENCY_WAIT_TIME)) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "ERROR: No event received from master %s:%d in heartbeat period (%lu seconds), last event (%s %d) received %lu seconds ago. Assuming connection is dead and reconnecting.", - router->service->dbref->server->name, - router->service->dbref->server->port, - router->heartbeat, - event_desc != NULL ? event_desc : "unknown", - router->lastEventReceived, - t_now - router->stats.lastReply))); + MXS_ERROR("No event received from master %s:%d in heartbeat period (%lu seconds), " + "last event (%s %d) received %lu seconds ago. Assuming connection is dead " + "and reconnecting.", + router->service->dbref->server->name, + router->service->dbref->server->port, + router->heartbeat, + event_desc != NULL ? event_desc : "unknown", + router->lastEventReceived, + t_now - router->stats.lastReply); return 0; } @@ -2201,33 +2149,27 @@ static void blr_log_identity(ROUTER_INSTANCE *router) { } /* Seen by the master */ - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: identity seen by the master: " - "server_id: %d, uuid: %s", - router->service->name, - router->serverid, (router->uuid == NULL ? "not available" : router->uuid)))); + MXS_NOTICE("%s: identity seen by the master: " + "server_id: %d, uuid: %s", + router->service->name, + router->serverid, (router->uuid == NULL ? "not available" : router->uuid)); /* Seen by the slaves */ /* MariaDB 5.5 and MariaDB don't have the MASTER_UUID var */ if (master_uuid == NULL) { - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: identity seen by the slaves: " - "server_id: %d, hostname: %s, MySQL version: %s", - router->service->name, - router->masterid, (master_hostname == NULL ? "not available" : master_hostname), - (master_version == NULL ? "not available" : master_version)))); + MXS_NOTICE("%s: identity seen by the slaves: " + "server_id: %d, hostname: %s, MySQL version: %s", + router->service->name, + router->masterid, (master_hostname == NULL ? "not available" : master_hostname), + (master_version == NULL ? "not available" : master_version)); } else { - LOGIF(LM, (skygw_log_write_flush( - LOGFILE_MESSAGE, - "%s: identity seen by the slaves: " - "server_id: %d, uuid: %s, hostname: %s, MySQL version: %s", - router->service->name, - router->masterid, master_uuid, - (master_hostname == NULL ? "not available" : master_hostname), - (master_version == NULL ? "not available" : master_version)))); + MXS_NOTICE("%s: identity seen by the slaves: " + "server_id: %d, uuid: %s, hostname: %s, MySQL version: %s", + router->service->name, + router->masterid, master_uuid, + (master_hostname == NULL ? "not available" : master_hostname), + (master_version == NULL ? "not available" : master_version)); } } diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 0adbaef02..6cc941587 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -176,9 +176,8 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue) { if (slave->state < 0 || slave->state > BLRS_MAXSTATE) { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "Invalid slave state machine state (%d) for binlog router.", - slave->state))); + MXS_ERROR("Invalid slave state machine state (%d) for binlog router.", + slave->state); gwbuf_consume(queue, gwbuf_length(queue)); return 0; } @@ -196,11 +195,9 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue) blr_slave_send_error_packet(slave, "Binlog router is not yet configured for replication", (unsigned int) 1597, NULL); - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "%s: Slave %s: Binlog router is not yet configured for replication", - router->service->name, - slave->dcb->remote))); + MXS_ERROR("%s: Slave %s: Binlog router is not yet configured for replication", + router->service->name, + slave->dcb->remote); dcb_close(slave->dcb); 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, "MariaDB 10 Slave is required for Slave registration", "42000", 1064); - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "%s: Slave %s: a MariaDB 10 Slave is required for Slave registration", - router->service->name, - slave->dcb->remote))); + MXS_ERROR("%s: Slave %s: a MariaDB 10 Slave is required for Slave registration", + router->service->name, + slave->dcb->remote); dcb_close(slave->dcb); return 1; @@ -252,18 +247,15 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue) return blr_ping(router, slave, queue); break; case COM_QUIT: - LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, - "COM_QUIT received from slave with server_id %d", - slave->serverid))); + MXS_DEBUG("COM_QUIT received from slave with server_id %d", + slave->serverid); break; default: blr_send_custom_error(slave->dcb, 1, 0, "You have an error in your SQL syntax; Check the syntax the MaxScale binlog router accepts.", "42000", 1064); - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "Unexpected MySQL Command (%d) received from slave", - MYSQL_COMMAND(queue)))); + MXS_ERROR("Unexpected MySQL Command (%d) received from slave", + MYSQL_COMMAND(queue)); break; } return 0; @@ -355,13 +347,11 @@ extern char *strcasestr(); } } - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, "Execute statement (truncated, it contains password)" - " from the slave '%s'", new_text))); + MXS_INFO("Execute statement (truncated, it contains password)" + " from the slave '%s'", new_text); free(new_text); } else { - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, "Execute statement from the slave '%s'", query_text))); + MXS_INFO("Execute statement from the slave '%s'", query_text); } /* @@ -375,15 +365,14 @@ extern char *strcasestr(); if ((word = strtok_r(query_text, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete query.", - router->service->name))); + MXS_ERROR("%s: Incomplete query.", router->service->name); } else if (strcasecmp(word, "SELECT") == 0) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete select query.", - router->service->name))); + MXS_ERROR("%s: Incomplete select query.", + router->service->name); } else if (strcasecmp(word, "UNIX_TIMESTAMP()") == 0) { @@ -485,8 +474,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete show query.", - router->service->name))); + MXS_ERROR("%s: Incomplete show query.", + router->service->name); } else if (strcasecmp(word, "WARNINGS") == 0) { @@ -502,9 +491,8 @@ extern char *strcasestr(); if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected VARIABLES in SHOW GLOBAL", - router->service->name))); + MXS_ERROR("%s: Expected VARIABLES in SHOW GLOBAL", + router->service->name); } else if (strcasecmp(word, "VARIABLES") == 0) { @@ -519,9 +507,8 @@ extern char *strcasestr(); return 1; } else - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected LIKE clause in SHOW GLOBAL VARIABLES.", - router->service->name))); + MXS_ERROR("%s: Expected LIKE clause in SHOW GLOBAL VARIABLES.", + router->service->name); } else if (strcasecmp(word, "STATUS") == 0) { @@ -536,9 +523,8 @@ extern char *strcasestr(); return 1; } else - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected LIKE clause in SHOW GLOBAL STATUS.", - router->service->name))); + MXS_ERROR("%s: Expected LIKE clause in SHOW GLOBAL STATUS.", + router->service->name); } } else if (strcasecmp(word, "VARIABLES") == 0) @@ -560,17 +546,15 @@ extern char *strcasestr(); return 1; } else - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected LIKE clause in SHOW VARIABLES.", - router->service->name))); + MXS_ERROR("%s: Expected LIKE clause in SHOW VARIABLES.", + router->service->name); } else if (strcasecmp(word, "MASTER") == 0) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected SHOW MASTER STATUS command", - router->service->name))); + MXS_ERROR("%s: Expected SHOW MASTER STATUS command", + router->service->name); } else if (strcasecmp(word, "STATUS") == 0) { @@ -588,9 +572,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected SHOW SLAVE STATUS command", - router->service->name))); + MXS_ERROR("%s: Expected SHOW SLAVE STATUS command", + router->service->name); } else if (strcasecmp(word, "STATUS") == 0) { @@ -624,17 +607,16 @@ extern char *strcasestr(); return 1; } else - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected LIKE clause in SHOW STATUS.", - router->service->name))); + MXS_ERROR("%s: Expected LIKE clause in SHOW STATUS.", + router->service->name); } } else if (strcasecmp(query_text, "SET") == 0) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete set command.", - router->service->name))); + MXS_ERROR("%s: Incomplete set command.", + router->service->name); } else if (strcasecmp(word, "@master_heartbeat_period") == 0) { @@ -694,8 +676,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Truncated SET NAMES command.", - router->service->name))); + MXS_ERROR("%s: Truncated SET NAMES command.", + router->service->name); } else if (strcasecmp(word, "latin1") == 0) { @@ -713,8 +695,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete RESET command.", - router->service->name))); + MXS_ERROR("%s: Incomplete RESET command.", + router->service->name); } else if (strcasecmp(word, "SLAVE") == 0) { @@ -731,7 +713,7 @@ extern char *strcasestr(); if (!current_master) { 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); return 1; @@ -740,13 +722,15 @@ extern char *strcasestr(); /* get current data */ 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'", - router->service->name, - current_master->host, - current_master->port, - current_master->logfile, - current_master->pos, - current_master->user))); + 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, + current_master->host, + current_master->port, + current_master->logfile, + current_master->pos, + current_master->user); /* remove master.ini */ strncpy(path, router->binlogdir, PATH_MAX); @@ -759,7 +743,7 @@ extern char *strcasestr(); if (removed_cfg == -1) { 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); - 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); @@ -790,8 +774,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete START command.", - router->service->name))); + MXS_ERROR("%s: Incomplete START command.", + router->service->name); } else if (strcasecmp(word, "SLAVE") == 0) { @@ -804,8 +788,7 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete STOP command.", - router->service->name))); + MXS_ERROR("%s: Incomplete STOP command.", router->service->name); } else if (strcasecmp(word, "SLAVE") == 0) { @@ -818,8 +801,7 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete CHANGE command.", - router->service->name))); + MXS_ERROR("%s: Incomplete CHANGE command.", router->service->name); } else if (strcasecmp(word, "MASTER") == 0) { @@ -840,7 +822,7 @@ extern char *strcasestr(); if (!current_master) { free(query_text); 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); @@ -876,8 +858,8 @@ extern char *strcasestr(); spinlock_release(&router->lock); 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", - 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); @@ -923,8 +905,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "%s: Incomplete DISCONNECT command.", - router->service->name))); + MXS_ERROR("%s: Incomplete DISCONNECT command.", + router->service->name); } else if (strcasecmp(word, "ALL") == 0) { @@ -935,9 +917,8 @@ extern char *strcasestr(); { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Expected DISCONNECT SERVER $server_id", - router->service->name))); + MXS_ERROR("%s: Expected DISCONNECT SERVER $server_id", + router->service->name); } else { int serverid = atoi(word); free(query_text); @@ -949,8 +930,7 @@ extern char *strcasestr(); free(query_text); query_text = strndup(qtext, query_len); - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "Unexpected query from '%s'@'%s': %s", slave->dcb->user, slave->dcb->remote, query_text))); + MXS_ERROR("Unexpected query from '%s'@'%s': %s", slave->dcb->user, slave->dcb->remote, 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."); return 1; @@ -984,8 +964,7 @@ GWBUF *clone; } else { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to clone server response to send to slave."))); + MXS_ERROR("Failed to clone server response to send to slave."); return 0; } } @@ -1713,20 +1692,16 @@ uint32_t chksum; binlognamelen = len - 11; if (binlognamelen > BINLOG_FNAMELEN) { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "blr_slave_binlog_dump truncating binlog filename " - "from %d to %d", - binlognamelen, BINLOG_FNAMELEN))); + MXS_ERROR("blr_slave_binlog_dump truncating binlog filename " + "from %d to %d", + binlognamelen, BINLOG_FNAMELEN); binlognamelen = BINLOG_FNAMELEN; } ptr += 4; // Skip length and sequence number if (*ptr++ != COM_BINLOG_DUMP) { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "blr_slave_binlog_dump expected a COM_BINLOG_DUMP but received %d", - *(ptr-1)))); + MXS_ERROR("blr_slave_binlog_dump expected a COM_BINLOG_DUMP but received %d", + *(ptr-1)); return 0; } @@ -1737,12 +1712,10 @@ uint32_t chksum; strncpy(slave->binlogfile, (char *)ptr, binlognamelen); slave->binlogfile[binlognamelen] = 0; - LOGIF(LD, (skygw_log_write( - LOGFILE_DEBUG, - "%s: COM_BINLOG_DUMP: binlog name '%s', length %d, " - "from position %lu.", router->service->name, - slave->binlogfile, binlognamelen, - (unsigned long)slave->binlog_pos))); + MXS_DEBUG("%s: COM_BINLOG_DUMP: binlog name '%s', length %d, " + "from position %lu.", router->service->name, + slave->binlogfile, binlognamelen, + (unsigned long)slave->binlog_pos); slave->seqno = 1; @@ -1808,12 +1781,10 @@ uint32_t chksum; slave->state = BLRS_DUMPING; - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, - "%s: Slave %s, server id %d requested binlog file %s from position %lu", - router->service->name, slave->dcb->remote, - slave->serverid, - slave->binlogfile, (unsigned long)slave->binlog_pos))); + MXS_NOTICE("%s: Slave %s, server id %d requested binlog file %s from position %lu", + router->service->name, slave->dcb->remote, + slave->serverid, + slave->binlogfile, (unsigned long)slave->binlog_pos); if (slave->binlog_pos != router->binlog_position || 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); return rval; } - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup failed to open binlog file", - slave->dcb->remote, slave->port, slave->serverid, - slave->binlogfile))); + MXS_ERROR("Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup " + "failed to open binlog file", + slave->dcb->remote, slave->port, slave->serverid, + slave->binlogfile); slave->cstate &= ~CS_BUSY; slave->state = BLRS_ERRORED; @@ -1987,9 +1957,8 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1]; unsigned long beat1 = hkheartbeat; blr_close_binlog(router, slave->file); if (hkheartbeat - beat1 > 1) - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "blr_close_binlog took %lu maxscale beats", - hkheartbeat - beat1))); + MXS_ERROR("blr_close_binlog took %lu maxscale beats", + hkheartbeat - beat1); blr_slave_rotate(router, slave, GWBUF_DATA(record)); beat1 = hkheartbeat; 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); return rval; } - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup failed to open binlog file in rotate event", - slave->dcb->remote, - slave->port, - slave->serverid, - slave->binlogfile))); + MXS_ERROR("Slave %s:%i, server-id %d, binlog '%s': blr_slave_catchup " + "failed to open binlog file in rotate event", + slave->dcb->remote, + slave->port, + slave->serverid, + slave->binlogfile); slave->state = BLRS_ERRORED; @@ -2024,9 +1992,8 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1]; break; } if (hkheartbeat - beat1 > 1) - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "blr_open_binlog took %lu beats", - hkheartbeat - beat1))); + MXS_ERROR("blr_open_binlog took %lu beats", + hkheartbeat - beat1); } slave->stats.n_bytes += gwbuf_length(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++; if (hdr.ok == SLAVE_POS_READ_ERR) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s Slave %s:%i, server-id %d, binlog '%s', %s", - router->service->name, - slave->dcb->remote, - slave->port, - slave->serverid, - slave->binlogfile, - read_errmsg))); + MXS_ERROR("%s Slave %s:%i, server-id %d, binlog '%s', %s", + router->service->name, + slave->dcb->remote, + slave->port, + slave->serverid, + slave->binlogfile, + read_errmsg); spinlock_acquire(&slave->catch_lock); @@ -2075,14 +2041,13 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1]; ROUTER_OBJECT *router_obj= router->service->router; - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Slave %s:%i, server-id %d, binlog '%s', %s", - router->service->name, - slave->dcb->remote, - slave->port, - slave->serverid, - slave->binlogfile, - read_errmsg))); + MXS_ERROR("%s: Slave %s:%i, server-id %d, binlog '%s', %s", + router->service->name, + slave->dcb->remote, + slave->port, + slave->serverid, + slave->binlogfile, + read_errmsg); /* * Close the slave session and socket @@ -2142,23 +2107,21 @@ char read_errmsg[BINLOG_ERROR_MSG_LEN+1]; slave->stats.n_caughtup++; if (slave->stats.n_caughtup == 1) { - LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, - "%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.", - router->service->name, - slave->dcb->remote, - slave->port, - slave->serverid, - slave->binlogfile, (unsigned long)slave->binlog_pos))); + MXS_NOTICE("%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.", + router->service->name, + slave->dcb->remote, + slave->port, + slave->serverid, + slave->binlogfile, (unsigned long)slave->binlog_pos); } else if ((slave->stats.n_caughtup % 50) == 0) { - LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, - "%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.", - router->service->name, - slave->dcb->remote, - slave->port, - slave->serverid, - slave->binlogfile, (unsigned long)slave->binlog_pos))); + MXS_NOTICE("%s: Slave %s:%d, server-id %d is up to date '%s', position %lu.", + router->service->name, + slave->dcb->remote, + slave->port, + slave->serverid, + 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 * we ignore these issues during the rotate processing. */ - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Slave reached end of file for binlog file %s at %lu " - "which is not the file currently being downloaded. " - "Master binlog is %s, %lu. This may be caused by a " - "previous failure of the master.", - slave->binlogfile, (unsigned long)slave->binlog_pos, - router->binlog_name, router->binlog_position))); + MXS_ERROR("Slave reached end of file for binlog file %s at %lu " + "which is not the file currently being downloaded. " + "Master binlog is %s, %lu. This may be caused by a " + "previous failure of the master.", + slave->binlogfile, (unsigned long)slave->binlog_pos, + router->binlog_name, router->binlog_position); if (blr_slave_fake_rotate(router, slave)) { spinlock_acquire(&slave->catch_lock); @@ -2246,9 +2208,8 @@ ROUTER_INSTANCE *router = slave->router; } else { - LOGIF(LD, (skygw_log_write( - LOGFILE_DEBUG, "Ignored callback due to slave state %s", - blrs_states[slave->state]))); + MXS_DEBUG("Ignored callback due to slave state %s", + 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 (hdr.ok != SLAVE_POS_READ_OK) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Slave %s:%i, server-id %d, binlog '%s', blr_read_binlog failure: %s", - slave->dcb->remote, - slave->port, - slave->serverid, - slave->binlogfile, - err_msg))); + MXS_ERROR("Slave %s:%i, server-id %d, binlog '%s', blr_read_binlog failure: %s", + slave->dcb->remote, + slave->port, + slave->serverid, + slave->binlogfile, + err_msg); } 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_found = 1; - LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, "%s: Slave %s, server id %d, disconnected by %s@%s", - router->service->name, - sptr->dcb->remote, - server_id, - slave->dcb->user, - slave->dcb->remote))); + MXS_NOTICE("%s: Slave %s, server id %d, disconnected by %s@%s", + router->service->name, + sptr->dcb->remote, + server_id, + slave->dcb->user, + slave->dcb->remote); /* send server_id with disconnect state to client */ 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) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Error: gwbuf memory allocation in " - "DISCONNECT SERVER server_id [%d]", - sptr->serverid))); + MXS_ERROR("gwbuf memory allocation in " + "DISCONNECT SERVER server_id [%d]", + sptr->serverid); 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; if ((pkt = gwbuf_alloc(len)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Error: gwbuf memory allocation in " - "DISCONNECT ALL for [%s], server_id [%d]", - sptr->dcb->remote, sptr->serverid))); + MXS_ERROR("gwbuf memory allocation in " + "DISCONNECT ALL for [%s], server_id [%d]", + sptr->dcb->remote, sptr->serverid); spinlock_release(&router->lock); @@ -2701,9 +2661,9 @@ blr_slave_disconnect_all(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave) return 1; } - LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, "%s: Slave %s, server id %d, disconnected by %s@%s", - router->service->name, - sptr->dcb->remote, sptr->serverid, slave->dcb->user, slave->dcb->remote))); + MXS_NOTICE("%s: Slave %s, server id %d, disconnected by %s@%s", + router->service->name, + sptr->dcb->remote, sptr->serverid, slave->dcb->user, slave->dcb->remote); ptr = GWBUF_DATA(pkt); 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); - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, - "%s: STOP SLAVE executed by %s@%s. Disconnecting from master %s:%d, read up to log %s, pos %lu, transaction safe pos %lu", - router->service->name, - slave->dcb->user, - slave->dcb->remote, - router->service->dbref->server->name, - router->service->dbref->server->port, - router->binlog_name, router->current_pos, router->binlog_position))); + MXS_NOTICE("%s: STOP SLAVE executed by %s@%s. Disconnecting from master %s:%d, " + "read up to log %s, pos %lu, transaction safe pos %lu", + router->service->name, + slave->dcb->user, + slave->dcb->remote, + router->service->dbref->server->name, + router->service->dbref->server->port, + router->binlog_name, router->current_pos, router->binlog_position); if (router->trx_safe && router->pending_transaction) { 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); /* Log it */ - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "Warning: a transaction is still opened at pos %lu" - " File %s will be truncated. " - "Next binlog file is %s at pos %d, " - "START SLAVE is required again.", - router->last_safe_pos, - router->prevbinlog, - router->binlog_name, - 4))); + MXS_WARNING("A transaction is still opened at pos %lu" + " File %s will be truncated. " + "Next binlog file is %s at pos %d, " + "START SLAVE is required again.", + router->last_safe_pos, + router->prevbinlog, + router->binlog_name, + 4); spinlock_acquire(&router->lock); @@ -2983,16 +2940,15 @@ blr_start_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave) blr_start_master(router); - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, - "%s: START SLAVE executed by %s@%s. Trying connection to master %s:%d, binlog %s, pos %lu, transaction safe pos %lu", - router->service->name, - slave->dcb->user, - slave->dcb->remote, - router->service->dbref->server->name, - router->service->dbref->server->port, - router->binlog_name, - router->current_pos, router->binlog_position))); + MXS_NOTICE("%s: START SLAVE executed by %s@%s. Trying connection to master %s:%d, " + "binlog %s, pos %lu, transaction safe pos %lu", + router->service->name, + slave->dcb->user, + slave->dcb->remote, + router->service->dbref->server->name, + router->service->dbref->server->port, + router->binlog_name, + router->current_pos, router->binlog_position); /* File path for router cached authentication data */ strcpy(path, router->binlogdir); @@ -3005,10 +2961,8 @@ blr_start_slave(ROUTER_INSTANCE* router, ROUTER_SLAVE* slave) if (loaded < 0) { - LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, - "Error : Unable to load users for service %s", - router->service->name))); + MXS_ERROR("Unable to load users for service %s", + router->service->name); } else { /* update cached data */ 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) { 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; } @@ -3109,7 +3063,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error free(cmd_string); 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); @@ -3121,7 +3075,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error if (!current_master) { 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); @@ -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"); } - 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 */ 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 (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 */ 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 */ 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 */ 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); router->binlog_fd = -1; - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_LOG_FILE is [%s]", - router->service->name, - router->binlog_name))); + MXS_INFO("%s: New MASTER_LOG_FILE is [%s]", + router->service->name, + router->binlog_name); } } else { /** @@ -3305,7 +3259,7 @@ int blr_handle_change_master(ROUTER_INSTANCE* router, char *command, char *error /* log error and return */ 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 */ 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)); strncpy(router->binlog_name, master_logfile, BINLOG_FNAMELEN); - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_LOG_FILE is [%s]", - router->service->name, - router->binlog_name))); + MXS_INFO("%s: New MASTER_LOG_FILE is [%s]", + router->service->name, + router->binlog_name); } - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_LOG_POS is [%lu]", - router->service->name, - router->current_pos))); + MXS_INFO("%s: New MASTER_LOG_POS is [%lu]", + router->service->name, + router->current_pos); } } /* 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'", - router->service->name, - current_master->host,current_master->port, current_master->logfile, current_master->pos, current_master->user, - router->service->dbref->server->name, - router->service->dbref->server->port, - router->binlog_name, - router->current_pos, - router->user))); + 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, + current_master->host, current_master->port, current_master->logfile, + current_master->pos, current_master->user, + router->service->dbref->server->name, + router->service->dbref->server->port, + router->binlog_name, + router->current_pos, + router->user); 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); - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_HOST is [%s]", - router->service->name, - router->service->dbref->server->name))); + MXS_INFO("%s: New MASTER_HOST is [%s]", + router->service->name, + router->service->dbref->server->name); return 1; } @@ -3418,9 +3376,9 @@ blr_set_master_port(ROUTER_INSTANCE *router, char *port) { if (new_port) { server_update_port(router->service->dbref->server, new_port); - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_PORT is [%i]", - router->service->name, - router->service->dbref->server->port))); + MXS_INFO("%s: New MASTER_PORT is [%i]", + router->service->name, + router->service->dbref->server->port); return 1; } @@ -3654,9 +3612,9 @@ blr_set_master_user(ROUTER_INSTANCE *router, char *user) { } router->user = strdup(ptr); - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "%s: New MASTER_USER is [%s]", - router->service->name, - router->user))); + MXS_INFO("%s: New MASTER_USER is [%s]", + router->service->name, + router->user); return 1; } @@ -4088,9 +4046,8 @@ char *sep = " ,="; return -1; } else if (strcasecmp(word, "LIKE") == 0) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Missing LIKE clause in SHOW [GLOBAL] VARIABLES.", - router->service->name))); + MXS_ERROR("%s: Missing LIKE clause in SHOW [GLOBAL] VARIABLES.", + router->service->name); return -1; } else if (strcasecmp(word, "'SERVER_ID'") == 0) { if (router->set_master_server_id) { @@ -4265,9 +4222,8 @@ char *sep = " ,="; return -1; } else if (strcasecmp(word, "LIKE") == 0) { if ((word = strtok_r(NULL, sep, &brkb)) == NULL) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "%s: Missing LIKE clause in SHOW [GLOBAL] STATUS.", - router->service->name))); + MXS_ERROR("%s: Missing LIKE clause in SHOW [GLOBAL] STATUS.", + router->service->name); return -1; } else if (strcasecmp(word, "'Uptime'") == 0) { char uptime[41]=""; @@ -4444,11 +4400,10 @@ time_t t_now = time(0); /* skip servers with state = 0 */ if ( (sptr->state == BLRS_DUMPING) && (sptr->heartbeat > 0) && ((t_now + 1 - sptr->lastReply) >= sptr->heartbeat) ) { - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, "Sending Heartbeat to slave server-id %d in State %d, cstate %d. " - "Heartbeat interval is %d, last event time is %lu", - sptr->serverid, sptr->state, sptr->cstate, sptr->heartbeat, - (unsigned long)sptr->lastReply))); + MXS_NOTICE("Sending Heartbeat to slave server-id %d in State %d, cstate %d. " + "Heartbeat interval is %d, last event time is %lu", + sptr->serverid, sptr->state, sptr->cstate, sptr->heartbeat, + (unsigned long)sptr->lastReply); blr_slave_send_heartbeat(router, sptr); diff --git a/server/modules/routing/binlog/maxbinlogcheck.c b/server/modules/routing/binlog/maxbinlogcheck.c index 6706c0b65..f6d03ee13 100644 --- a/server/modules/routing/binlog/maxbinlogcheck.c +++ b/server/modules/routing/binlog/maxbinlogcheck.c @@ -129,8 +129,7 @@ int main(int argc, char **argv) { mxs_log_set_priority_enabled(LOG_DEBUG, debug_out); if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) { - LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Error: Memory allocation failed for ROUTER_INSTANCE"))); + MXS_ERROR("Memory allocation failed for ROUTER_INSTANCE"); mxs_log_flush_sync(); mxs_log_finish(); @@ -152,9 +151,8 @@ int main(int argc, char **argv) { if (fd == -1) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to open binlog file %s: %s", - path, strerror(errno)))); + MXS_ERROR("Failed to open binlog file %s: %s", + path, strerror(errno)); mxs_log_flush_sync(); mxs_log_finish(); @@ -175,14 +173,12 @@ int main(int argc, char **argv) { else strncpy(inst->binlog_name, path, BINLOG_FNAMELEN); - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "maxbinlogcheck %s", binlog_check_version))); + MXS_NOTICE("maxbinlogcheck %s", binlog_check_version); if (fstat(inst->binlog_fd, &statb) == 0) filelen = statb.st_size; - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Checking %s (%s), size %lu bytes", path, inst->binlog_name, filelen))); + MXS_NOTICE("Checking %s (%s), size %lu bytes", path, inst->binlog_name, filelen); /* read binary log */ 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(); - LOGIF(LM, (skygw_log_write_flush(LOGFILE_MESSAGE, - "Check retcode: %i, Binlog Pos = %lu", ret, inst->binlog_position))); + MXS_NOTICE("Check retcode: %i, Binlog Pos = %lu", ret, inst->binlog_position); mxs_log_flush_sync(); mxs_log_finish();