Binlog encryption is now working with events larger than 16MBytes

Events larger than 16MBytes are now encrypted when being saved.

Some changes to binlog event details report and maxbinlogcheck supports
-H option for replication header display
This commit is contained in:
MassimilianoPinto 2016-12-07 12:17:22 +01:00
parent 76a2475c33
commit 9444ded6da
5 changed files with 149 additions and 102 deletions

View File

@ -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
{

View File

@ -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);
}
}

View File

@ -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);

View File

@ -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;
}

View File

@ -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();