diff --git a/server/modules/routing/binlogrouter/blr.h b/server/modules/routing/binlogrouter/blr.h index 4f7da22b8..6b8f61be9 100644 --- a/server/modules/routing/binlogrouter/blr.h +++ b/server/modules/routing/binlogrouter/blr.h @@ -79,6 +79,10 @@ MXS_BEGIN_DECLS #define BINLOG_SYSTEM_DATA_CRYPTO_SCHEME 1 #define BINLOG_MAX_KEYFILE_LINE_LEN 130 +/* Event detail routine */ +#define BLR_REPORT_CHECKSUM_FORMAT "CRC32 0x" +#define BLR_REPORT_REP_HEADER 0x02 + /* Supported Encryption algorithms */ enum blr_aes_mode { diff --git a/server/modules/routing/binlogrouter/blr_file.c b/server/modules/routing/binlogrouter/blr_file.c index 0db36dbfd..e28a42db7 100644 --- a/server/modules/routing/binlogrouter/blr_file.c +++ b/server/modules/routing/binlogrouter/blr_file.c @@ -176,22 +176,24 @@ static GWBUF *blr_prepare_encrypted_event(ROUTER_INSTANCE *router, const uint8_t *nonce, int action); static GWBUF *blr_aes_crypt(ROUTER_INSTANCE *router, - uint8_t *event, - uint32_t event_size, - uint8_t *iv, - int action); + uint8_t *event, + uint32_t event_size, + uint8_t *iv, + int action); static int blr_aes_create_tail_for_cbc(uint8_t *output, - uint8_t *input, - uint32_t in_size, - uint8_t *iv, - uint8_t *key, - unsigned int key_len); + uint8_t *input, + uint32_t in_size, + uint8_t *iv, + uint8_t *key, + unsigned int key_len); static int blr_binlog_event_check(ROUTER_INSTANCE *router, unsigned long pos, REP_HEADER *hdr, char *binlogname, char *errmsg); +static void blr_report_checksum(REP_HEADER hdr, const uint8_t *buffer, char *output); + /** MaxScale generated events */ typedef enum { @@ -516,8 +518,7 @@ blr_write_binlog_record(ROUTER_INSTANCE *router, REP_HEADER *hdr, uint32_t size, * Fill the gap with a self generated ignorable event * Binlog file position is incremented by blr_write_special_event() */ - if (router->master_event_state == BLR_EVENT_DONE && - hdr->next_pos && (hdr->next_pos > (file_offset + size))) + if (hdr->next_pos && (hdr->next_pos > (file_offset + size))) { uint64_t hole_size = hdr->next_pos - file_offset - size; if (!blr_write_special_event(router, file_offset, hole_size, hdr, BLRM_IGNORABLE)) @@ -990,7 +991,10 @@ blr_read_binlog(ROUTER_INSTANCE *router, return NULL; } - /* Check whether we need to decrypt the current event */ + /** + * Check whether we need to decrypt the current event. + * Note: if event is before the first_enc_event_pos don't decrypt it + */ if (enc_ctx && pos >= enc_ctx->first_enc_event_pos) { GWBUF *decrypted_event; @@ -1484,20 +1488,23 @@ blr_read_events_all_events(ROUTER_INSTANCE *router, int fix, int debug) * Print the IV for the current encrypted event. */ - /* Get binlog file "nonce" and other data from router encryption_ctx */ - BINLOG_ENCRYPTION_CTX *enc_ctx = router->encryption_ctx; + if (debug & BLR_REPORT_REP_HEADER) + { + /* Get binlog file "nonce" and other data from router encryption_ctx */ + BINLOG_ENCRYPTION_CTX *enc_ctx = router->encryption_ctx; - /* Encryption IV is 12 bytes nonce + 4 bytes event position */ - memcpy(iv, enc_ctx->nonce, BLRM_NONCE_LENGTH); - gw_mysql_set_byte4(iv + BLRM_NONCE_LENGTH, (unsigned long)pos); + /* Encryption IV is 12 bytes nonce + 4 bytes event position */ + memcpy(iv, enc_ctx->nonce, BLRM_NONCE_LENGTH); + gw_mysql_set_byte4(iv + BLRM_NONCE_LENGTH, (unsigned long)pos); - /* Human readable version */ - gw_bin2hex(iv_hex, iv, BLRM_IV_LENGTH); + /* Human readable version */ + gw_bin2hex(iv_hex, iv, BLRM_IV_LENGTH); - MXS_DEBUG("** Encrypted Event @ %lu: the IV is %s, size is %lu, next pos is %lu\n", - (unsigned long)pos, - iv_hex, (unsigned long)event_size, - (unsigned long)(pos + event_size)); + MXS_DEBUG("** Encrypted Event @ %lu: the IV is %s, size is %lu, next pos is %lu\n", + (unsigned long)pos, + iv_hex, (unsigned long)event_size, + (unsigned long)(pos + event_size)); + } /* Set event size only in hdr struct, before decryption */ hdr.event_size = event_size; @@ -1682,7 +1689,6 @@ blr_read_events_all_events(ROUTER_INSTANCE *router, int fix, int debug) uint8_t *decrypt_ptr; unsigned long next_pos; char errmsg[BLRM_STRERROR_R_MSG_SIZE + 1] = ""; - char *event_desc; /** * Events are encrypted. @@ -1713,15 +1719,6 @@ blr_read_events_all_events(ROUTER_INSTANCE *router, int fix, int debug) hdr.next_pos = EXTRACT32(&decrypt_ptr[13]); hdr.flags = EXTRACT16(&decrypt_ptr[17]); - /* Get next pos from decrypted event header */ - next_pos = EXTRACT32(&decrypt_ptr[13]); - event_desc = blr_get_event_description(router, hdr.event_type); - - MXS_DEBUG("%8sEvent time %lu\n%39sEvent Type %u (%s)\n%39sServer Id %lu\n%39sNextPos %lu\n%39sFlags %u", - " ", (unsigned long)hdr.timestamp, " ", hdr.event_type, - event_desc ? event_desc : "NULL", " ", - (unsigned long)hdr.serverid, " ", next_pos, " ", hdr.flags); - /* Check event */ if (!blr_binlog_event_check(router, pos, @@ -1831,6 +1828,7 @@ blr_read_events_all_events(ROUTER_INSTANCE *router, int fix, int debug) } if (check_alg == 1) { + /* Set checksum found indicator */ found_chksum = 1; } else @@ -1839,6 +1837,21 @@ blr_read_events_all_events(ROUTER_INSTANCE *router, int fix, int debug) } } + if ((debug & BLR_REPORT_REP_HEADER)) + { + char *event_desc = blr_get_event_description(router, hdr.event_type); + MXS_DEBUG("%8s==== Event Header ====\n%39sEvent time %lu\n%39sEvent Type %u (%s)\n%39sServer Id %lu\n%39sNextPos %lu\n%39sFlags %u", + " ", " ", (unsigned long)hdr.timestamp, " ", hdr.event_type, + event_desc ? event_desc : "NULL", " ", + (unsigned long)hdr.serverid, " ", (unsigned long)hdr.next_pos, " ", hdr.flags); + if (found_chksum) + { + char hex_checksum[BINLOG_EVENT_CRC_SIZE * 2 + strlen(BLR_REPORT_CHECKSUM_FORMAT) + 1]; + blr_report_checksum(hdr, ptr, hex_checksum); + MXS_DEBUG("%8s%s", " ", hex_checksum); + } + } + /* Detect possible Start Encryption Event */ if (hdr.event_type == MARIADB10_START_ENCRYPTION_EVENT) { @@ -1871,33 +1884,11 @@ blr_read_events_all_events(ROUTER_INSTANCE *router, int fix, int debug) if (debug) { - char *cksum_format = ", CRC32 0x"; - char hex_checksum[BINLOG_EVENT_CRC_SIZE * 2 + strlen(cksum_format) + 1]; - uint8_t cksum_data[BINLOG_EVENT_CRC_SIZE]; - hex_checksum[0]='\0'; - /* Hex representation of nonce */ gw_bin2hex(nonce_hex, ste_event.nonce, BLRM_NONCE_LENGTH); - /* Hex representation of checksum */ - cksum_data[3] = *(ptr + hdr.event_size - 4 - BINLOG_EVENT_HDR_LEN); - cksum_data[2] = *(ptr + hdr.event_size - 3 - BINLOG_EVENT_HDR_LEN); - cksum_data[1] = *(ptr + hdr.event_size - 2 - BINLOG_EVENT_HDR_LEN); - cksum_data[0] = *(ptr + hdr.event_size - 1 - BINLOG_EVENT_HDR_LEN); - - if (found_chksum) - { - strcpy(hex_checksum, cksum_format); - gw_bin2hex(hex_checksum + strlen(cksum_format) , cksum_data, BINLOG_EVENT_CRC_SIZE); - for (char *p = hex_checksum + strlen(cksum_format) ; *p; ++p) - { - *p = tolower(*p); - } - } - - MXS_DEBUG("- START_ENCRYPTION event @ %llu, size %lu, next pos is @ %lu, flags %u%s", - pos, (unsigned long)hdr.event_size, (unsigned long)hdr.next_pos, hdr.flags, - hex_checksum); + MXS_DEBUG("- START_ENCRYPTION event @ %llu, size %lu, next pos is @ %lu, flags %u", + pos, (unsigned long)hdr.event_size, (unsigned long)hdr.next_pos, hdr.flags); MXS_DEBUG(" Encryption scheme: %u, key_version: %u," " nonce: %s\n", ste_event.binlog_crypto_scheme, @@ -2934,7 +2925,7 @@ static GWBUF *blr_prepare_encrypted_event(ROUTER_INSTANCE *router, gw_bin2hex(iv_hex, iv, BLRM_IV_LENGTH); gw_bin2hex(nonce_hex, nonce_ptr, BLRM_NONCE_LENGTH); - MXS_DEBUG("** Decrypting Event @ %lu: the IV is %s, size is %lu, next pos is %lu", + MXS_DEBUG("** Encryption/Decryption of Event @ %lu: the IV is %s, size is %lu, next pos is %lu", (unsigned long)pos, iv_hex, (unsigned long)size, (unsigned long)(pos + size)); @@ -3107,10 +3098,10 @@ static int blr_aes_create_tail_for_cbc(uint8_t *output, * * 1 ok, 0 err */ static int blr_binlog_event_check(ROUTER_INSTANCE *router, - unsigned long pos, - REP_HEADER *hdr, - char *binlogname, - char *errmsg) + unsigned long pos, + REP_HEADER *hdr, + char *binlogname, + char *errmsg) { /* event pos & size checks */ if (hdr->event_size == 0 || ((hdr->next_pos != (pos + hdr->event_size)) && @@ -3148,3 +3139,30 @@ static int blr_binlog_event_check(ROUTER_INSTANCE *router, /* check is OK */ return 1; } + +/** + * Fill a string buffer with HEX representation of CRC32 (4) bytes + * at the end of binlog event + * + * @param hdr The replication header struct + * @param buffer The buffer with binlog event + * @output The output buffer to fill, preallocated by the caller + */ +static void blr_report_checksum(REP_HEADER hdr, const uint8_t *buffer, char *output) +{ + uint8_t cksum_data[BINLOG_EVENT_CRC_SIZE]; + char *ptr = output + strlen(BLR_REPORT_CHECKSUM_FORMAT); + strcpy(output, BLR_REPORT_CHECKSUM_FORMAT); + + /* Hex representation of checksum */ + cksum_data[3] = *(buffer + hdr.event_size - 4 - BINLOG_EVENT_HDR_LEN); + cksum_data[2] = *(buffer + hdr.event_size - 3 - BINLOG_EVENT_HDR_LEN); + cksum_data[1] = *(buffer + hdr.event_size - 2 - BINLOG_EVENT_HDR_LEN); + cksum_data[0] = *(buffer + hdr.event_size - 1 - BINLOG_EVENT_HDR_LEN); + + gw_bin2hex(ptr, cksum_data, BINLOG_EVENT_CRC_SIZE); + for (char *p = ptr ; *p; ++p) + { + *p = tolower(*p); + } +} diff --git a/server/modules/routing/binlogrouter/blr_master.c b/server/modules/routing/binlogrouter/blr_master.c index 06c90ed56..6b8730ec0 100644 --- a/server/modules/routing/binlogrouter/blr_master.c +++ b/server/modules/routing/binlogrouter/blr_master.c @@ -1148,9 +1148,11 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) break; } - /** This is the first (and possibly last) packet of a replication + /** + * This is the first (and possibly last) packet of a replication * event. We store the header in case the event is large and - * it is transmitted over multiple network packets. */ + * it is transmitted over multiple network packets. + */ router->master_event_state = BLR_EVENT_STARTED; memcpy(&router->stored_header, &hdr, sizeof(hdr)); reset_errors(router, &hdr); @@ -1234,12 +1236,19 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) continue; } - /** We now have the complete event in one contiguous buffer */ + /** + * We now have the complete event in one contiguous buffer: + * router->master_event_state is BLR_EVENT_DONE + */ router->stored_event = gwbuf_make_contiguous(router->stored_event); + MXS_ABORT_IF_NULL(router->stored_event); + ptr = GWBUF_DATA(router->stored_event); - /** len is now the length of the complete event plus 4 bytes of network - * header and one OK byte. Semi-sync bytes are never stored. */ + /** + * len is now the length of the complete event plus 4 bytes of network + * header and one OK byte. Semi-sync bytes are never stored. + */ len = gwbuf_length(router->stored_event); /** @@ -1279,14 +1288,15 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) /** * Detect transactions in events * Only complete transactions should be sent to sleves - */ - - /* If MariaDB 10 compatibility: - * check for MARIADB10_GTID_EVENT with flags = 0 - * This marks the transaction starts instead of - * QUERY_EVENT with "BEGIN" */ - if (router->trx_safe && router->master_event_state == BLR_EVENT_DONE) + + /** + * If MariaDB 10 compatibility: + * check for MARIADB10_GTID_EVENT with flags = 0 + * This marks the transaction starts instead of + * QUERY_EVENT with "BEGIN" + */ + if (router->trx_safe) { if (router->mariadb10_compat) { @@ -1295,9 +1305,9 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) uint64_t n_sequence; uint32_t domainid; unsigned int flags; - n_sequence = extract_field(ptr + 4 + 20, 64); - domainid = extract_field(ptr + 4 + 20 + 8, 32); - flags = *(ptr + 4 + 20 + 8 + 4); + n_sequence = extract_field(ptr + MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN, 64); + domainid = extract_field(ptr + MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN + 8, 32); + flags = *(ptr + MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN + 8 + 4); if ((flags & (MARIADB_FL_DDL | MARIADB_FL_STANDALONE)) == 0) { @@ -1332,14 +1342,16 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) { char *statement_sql; int db_name_len, var_block_len, statement_len; - db_name_len = ptr[4 + 20 + 4 + 4]; - var_block_len = ptr[4 + 20 + 4 + 4 + 1 + 2]; + db_name_len = ptr[MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN + 4 + 4]; + var_block_len = ptr[MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN + 4 + 4 + 1 + 2]; - statement_len = len - (4 + 20 + 4 + 4 + 1 + 2 + 2 + var_block_len + 1 + db_name_len); + statement_len = len - (MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN + 4 + 4 + 1 + 2 + 2 \ + + var_block_len + 1 + db_name_len); statement_sql = MXS_CALLOC(1, statement_len + 1); MXS_ABORT_IF_NULL(statement_sql); memcpy(statement_sql, - (char *)ptr + 4 + 20 + 4 + 4 + 1 + 2 + 2 + var_block_len + 1 + db_name_len, + (char *)ptr + MYSQL_HEADER_LEN + 1 + BINLOG_EVENT_HDR_LEN + 4 + 4 + 1 + 2 + 2 \ + + var_block_len + 1 + db_name_len, statement_len); spinlock_acquire(&router->binlog_lock); @@ -1481,8 +1493,7 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) /* Handle semi-sync request from master */ if (router->master_semi_sync != MASTER_SEMISYNC_NOT_AVAILABLE && - semi_sync_send_ack == BLR_MASTER_SEMI_SYNC_ACK_REQ && - (router->master_event_state == BLR_EVENT_DONE)) + semi_sync_send_ack == BLR_MASTER_SEMI_SYNC_ACK_REQ) { MXS_DEBUG("%s: binlog record in file %s, pos %lu has " @@ -1560,7 +1571,7 @@ blr_handle_binlog_record(ROUTER_INSTANCE *router, GWBUF *pkt) hdr.event_size, router->binlog_name, router->current_pos); - ptr += 5; + ptr += MYSQL_HEADER_LEN + 1; if (hdr.event_type == ROTATE_EVENT) { spinlock_acquire(&router->binlog_lock); diff --git a/server/modules/routing/binlogrouter/blr_slave.c b/server/modules/routing/binlogrouter/blr_slave.c index bb535b4bd..c224969f5 100644 --- a/server/modules/routing/binlogrouter/blr_slave.c +++ b/server/modules/routing/binlogrouter/blr_slave.c @@ -2389,17 +2389,19 @@ blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large) { /* read it, set slave & file context */ uint8_t *record_ptr = GWBUF_DATA(record); - SLAVE_ENCRYPTION_CTX *new_encryption_ctx = MXS_CALLOC(1, sizeof(SLAVE_ENCRYPTION_CTX)); + SLAVE_ENCRYPTION_CTX *encryption_ctx = MXS_CALLOC(1, sizeof(SLAVE_ENCRYPTION_CTX)); + + MXS_ABORT_IF_NULL(encryption_ctx); record_ptr += BINLOG_EVENT_HDR_LEN; - new_encryption_ctx->binlog_crypto_scheme = record_ptr[0]; - memcpy(&new_encryption_ctx->binlog_key_version, record_ptr + 1, BLRM_KEY_VERSION_LENGTH); - memcpy(new_encryption_ctx->nonce, record_ptr + 1 + BLRM_KEY_VERSION_LENGTH, BLRM_NONCE_LENGTH); + encryption_ctx->binlog_crypto_scheme = record_ptr[0]; + memcpy(&encryption_ctx->binlog_key_version, record_ptr + 1, BLRM_KEY_VERSION_LENGTH); + memcpy(encryption_ctx->nonce, record_ptr + 1 + BLRM_KEY_VERSION_LENGTH, BLRM_NONCE_LENGTH); /* Save current first_enc_event_pos */ - new_encryption_ctx->first_enc_event_pos = hdr.next_pos; + encryption_ctx->first_enc_event_pos = hdr.next_pos; /* set the encryption ctx into slave */ - slave->encryption_ctx = new_encryption_ctx; + slave->encryption_ctx = encryption_ctx; MXS_INFO("Start Encryption event found while reading. Binlog %s is encrypted. First event at %lu", slave->binlogfile, @@ -5885,6 +5887,7 @@ blr_slave_read_ste(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, uint32_t fde_en if (hdr.event_type == MARIADB10_START_ENCRYPTION_EVENT) { uint8_t *record_ptr = GWBUF_DATA(record); + void *old_encryption_ctx = slave->encryption_ctx; SLAVE_ENCRYPTION_CTX *new_encryption_ctx = MXS_CALLOC(1, sizeof(SLAVE_ENCRYPTION_CTX)); if (!new_encryption_ctx) @@ -5900,16 +5903,22 @@ blr_slave_read_ste(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, uint32_t fde_en new_encryption_ctx->first_enc_event_pos = fde_end_pos + hdr.event_size; spinlock_acquire(&slave->catch_lock); - /* set the encryption ctx into slave */ - MXS_FREE(slave->encryption_ctx); + + /* Set the new encryption ctx into slave */ slave->encryption_ctx = new_encryption_ctx; - /* Set the slave postion after START_ENCRYPTION_EVENT */ - slave->binlog_pos = (unsigned long)fde_end_pos + hdr.event_size; + spinlock_release(&slave->catch_lock); + /* Free previous encryption ctx */ + MXS_FREE(old->encryption_ctx); + MXS_INFO("Start Encryption event found. Binlog %s is encrypted. First event at %lu", slave->binlogfile, (unsigned long)fde_end_pos + hdr.event_size); + /** + * Note: if the requested pos is equal to START_ENCRYPTION_EVENT pos + * the event will be skipped by blr_read_binlog() routine + */ return 1; } diff --git a/server/modules/routing/binlogrouter/maxbinlogcheck.c b/server/modules/routing/binlogrouter/maxbinlogcheck.c index e47929875..889847ffa 100644 --- a/server/modules/routing/binlogrouter/maxbinlogcheck.c +++ b/server/modules/routing/binlogrouter/maxbinlogcheck.c @@ -28,12 +28,13 @@ * Currently MariadDB 10 starting transactions * are detected checking GTID event * with flags = 0 - * 26/04/16 Massimiliano Pinto MariaDB 10.1 GTID flags are properly parsed - * 23/09/16 Massimiliano Pinto MariaDB 10.1 encrypted binlog compatible: + * 26/04/2016 Massimiliano Pinto MariaDB 10.1 GTID flags are properly parsed + * 23/09/2016 Massimiliano Pinto MariaDB 10.1 encrypted binlog compatible: * the output shows the START_ENCRYPTION_EVENT and follows * binlog positions without dectypting events. - * 25/11/16 Massimiliano Pinto MariaDB 10.1 encrypted files can be checked + * 25/11/2016 Massimiliano Pinto MariaDB 10.1 encrypted files can be checked * with Key and Algo options + * 06/12/2016 Massimiliano Pinto A new option allows displaying of replication header * * * @endverbatim @@ -60,13 +61,14 @@ static struct option long_options[] = {"version", no_argument, 0, 'V'}, {"fix", no_argument, 0, 'f'}, {"mariadb10", no_argument, 0, 'M'}, + {"header", no_argument, 0, 'H'}, {"key_file", required_argument, 0, 'K'}, {"aes_algo", required_argument, 0, 'A'}, {"help", no_argument, 0, '?'}, {0, 0, 0, 0} }; -char *binlog_check_version = "2.0.1"; +char *binlog_check_version = "2.1.0"; int maxscale_uptime() @@ -82,16 +84,19 @@ int main(int argc, char **argv) int mariadb10_compat = 0; char *key_file = NULL; char *aes_algo = NULL; - - + int report_header = 0; char c; - while ((c = getopt_long(argc, argv, "dVfMK:A:?", long_options, &option_index)) >= 0) + + while ((c = getopt_long(argc, argv, "dVfMHK:A:?", long_options, &option_index)) >= 0) { switch (c) { case 'd': debug_out = 1; break; + case 'H': + report_header = BLR_REPORT_REP_HEADER; + break; case 'V': printVersion(*argv); exit(EXIT_SUCCESS); @@ -196,7 +201,7 @@ int main(int argc, char **argv) MXS_NOTICE("Checking %s (%s), size %lu bytes", path, inst->binlog_name, filelen); /* read binary log */ - int ret = blr_read_events_all_events(inst, fix_file, debug_out); + int ret = blr_read_events_all_events(inst, fix_file, debug_out | report_header); mxs_log_flush_sync();