revision-id: d34839cacbef0f4c76b7aa7ae6165b37b293685c (mariadb-10.1.41-51-gd34839cacbe) parent(s): 4bcf524482b3a4260347b0fe912fa2660af97c43 author: Sujatha committer: Sujatha timestamp: 2019-10-04 13:45:33 +0530 message: MDEV-18046: Assortment of crashes, assertion failures and ASAN errors in mysql_show_binlog_events Problem: ======== SHOW BINLOG EVENTS FROM <pos> causes a variety of failures, some of which are listed below. It is not a race condition issue, but there is some non-determinism in it. Fix: ==== Assert 1: With ASAN ======== Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' Implemented upstream patch. commit a3a497ccf7ecacc900551fb1e47ea4078b45c351 Fix: Added checks to avoid reading out of buffer limits. Assert 2: ========= Table_map_log_event::Table_map_log_event(const char*, uint, const Format_description_log_event*) Assertion `m_field_metadata_size <= (m_colcnt * 2)' failed. Fix: Converted debug assert to error handler code. ASAN Error: head-buffer-overflow within "my_strndup" in Rotate_log_event =========== my_strndup /home/sujatha/bug_repo/tmp-10.1/mysys/my_malloc.c:254 Rotate_log_event::Rotate_log_event(char const*, unsigned int, Format_description_log_event const*) Fix: Improved the check for event_len validation. ASAN Error: AddressSanitizer: SEGV on unknown address ========== in inline_mysql_mutex_destroy in my_bitmap_free in Update_rows_log_event::~Update_rows_log_event() Fix: Intialize m_cols_ai.bitmap to NULL. ASAN Error: AddressSanitizer: heap-buffer-overflow on address 0x60400002acb8 ========== Load_log_event::copy_log_event(char const*, unsigned long, int, Format_description_log_event const*) Fix: Moved the event_len validation to the begin of copy_log_event function. ASAN Error: AddressSanitizer: SEGV on unknown address ========== The signal is caused by a READ memory access. User_var_log_event::User_var_log_event(char const*, unsigned int, Format_description_log_event const*) Implemented upstream patch. commit a3a497ccf7ecacc900551fb1e47ea4078b45c351 User_var_log_event::User_var_log_event: added checks to avoid reading out of buffer limits. ASAN Error: AddressSanitizer: heap-buffer-overflow on address ========== String::append(char const*, unsigned int) Query_log_event::pack_info(Protocol*) Fix: Added check to ensure that query_len is within event_length --- .../binlog/r/binlog_invalid_read_in_rotate.result | 17 +++++ .../r/binlog_show_binlog_event_random_pos.result | 13 ++++ .../binlog/t/binlog_invalid_read_in_rotate.test | 47 ++++++++++++++ .../t/binlog_show_binlog_event_random_pos.test | 37 +++++++++++ sql/log_event.cc | 75 ++++++++++++++++------ 5 files changed, 168 insertions(+), 21 deletions(-) diff --git a/mysql-test/suite/binlog/r/binlog_invalid_read_in_rotate.result b/mysql-test/suite/binlog/r/binlog_invalid_read_in_rotate.result new file mode 100644 index 00000000000..28131d2645c --- /dev/null +++ b/mysql-test/suite/binlog/r/binlog_invalid_read_in_rotate.result @@ -0,0 +1,17 @@ +RESET MASTER; +call mtr.add_suppression("Error in Log_event::read_log_event*"); +DROP TABLE /*! IF EXISTS*/ t1; +Warnings: +Note 1051 Unknown table 'test.t1' +CREATE TABLE `t1` ( +`col_int` int, +pk integer auto_increment, +`col_char_12_key` char(12), +`col_int_key` int, +`col_char_12` char(12), +primary key (pk), +key (`col_char_12_key` ), +key (`col_int_key` )) ENGINE=InnoDB; +INSERT /*! IGNORE */ INTO t1 VALUES (183173120, NULL, 'abcd', 1, 'efghijk'), (1, NULL, 'lmno', 2, 'p'); +ALTER TABLE `t1` ENABLE KEYS; +DROP TABLE t1; diff --git a/mysql-test/suite/binlog/r/binlog_show_binlog_event_random_pos.result b/mysql-test/suite/binlog/r/binlog_show_binlog_event_random_pos.result new file mode 100644 index 00000000000..98385a7ac5e --- /dev/null +++ b/mysql-test/suite/binlog/r/binlog_show_binlog_event_random_pos.result @@ -0,0 +1,13 @@ +RESET MASTER; +call mtr.add_suppression("Error in Log_event::read_log_event*"); +DROP TABLE IF EXISTS t1; +Warnings: +Note 1051 Unknown table 'test.t1' +CREATE TABLE t1 (c1 CHAR(255), c2 CHAR(255), c3 CHAR(255), c4 CHAR(255), c5 CHAR(255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +UPDATE t1 SET c1=repeat('b',255); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +DROP TABLE t1; diff --git a/mysql-test/suite/binlog/t/binlog_invalid_read_in_rotate.test b/mysql-test/suite/binlog/t/binlog_invalid_read_in_rotate.test new file mode 100644 index 00000000000..8360f2dcac4 --- /dev/null +++ b/mysql-test/suite/binlog/t/binlog_invalid_read_in_rotate.test @@ -0,0 +1,47 @@ +# ==== Purpose ==== +# +# Test verifies that reading binary log by using "SHOW BINLOG EVENTS" command +# from various random positions doesn't lead to crash. It should exit +# gracefully with appropriate error. +# +# ==== References ==== +# +# MDEV-18046:Assortment of crashes, assertion failures and ASAN errors in mysql_show_binlog_events + +--source include/have_log_bin.inc +--source include/have_innodb.inc + +RESET MASTER; + +call mtr.add_suppression("Error in Log_event::read_log_event*"); + +DROP TABLE /*! IF EXISTS*/ t1; +CREATE TABLE `t1` ( +`col_int` int, +pk integer auto_increment, +`col_char_12_key` char(12), +`col_int_key` int, +`col_char_12` char(12), +primary key (pk), +key (`col_char_12_key` ), +key (`col_int_key` )) ENGINE=InnoDB; + +INSERT /*! IGNORE */ INTO t1 VALUES (183173120, NULL, 'abcd', 1, 'efghijk'), (1, NULL, 'lmno', 2, 'p'); + +--disable_warnings +ALTER TABLE `t1` ENABLE KEYS; +--enable_warnings + +--let $max_pos= query_get_value(SHOW MASTER STATUS,Position,1) +--let $pos= 1 +while ($pos <= $max_pos) +{ + --disable_query_log + --disable_result_log + --error 0,1220 + eval SHOW BINLOG EVENTS FROM $pos; + --inc $pos + --enable_result_log + --enable_query_log +} +DROP TABLE t1; diff --git a/mysql-test/suite/binlog/t/binlog_show_binlog_event_random_pos.test b/mysql-test/suite/binlog/t/binlog_show_binlog_event_random_pos.test new file mode 100644 index 00000000000..aaf56faa57e --- /dev/null +++ b/mysql-test/suite/binlog/t/binlog_show_binlog_event_random_pos.test @@ -0,0 +1,37 @@ +# ==== Purpose ==== +# +# Test verifies that reading binary log by using "SHOW BINLOG EVENTS" command +# from various random positions doesn't lead to crash. It should exit +# gracefully with appropriate error. +# +# ==== References ==== +# +# MDEV-18046:Assortment of crashes, assertion failures and ASAN errors in mysql_show_binlog_events + +--source include/have_log_bin.inc +--source include/have_innodb.inc + +RESET MASTER; +call mtr.add_suppression("Error in Log_event::read_log_event*"); +DROP TABLE IF EXISTS t1; +CREATE TABLE t1 (c1 CHAR(255), c2 CHAR(255), c3 CHAR(255), c4 CHAR(255), c5 CHAR(255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +UPDATE t1 SET c1=repeat('b',255); +INSERT INTO t1 VALUES (repeat('a', 255), repeat('a', 255),repeat('a', 255),repeat('a', 255),repeat('a', 255)); +--let $max_pos= query_get_value(SHOW MASTER STATUS,Position,1) +--let $pos= 1 +while ($pos <= $max_pos) +{ + --disable_query_log + --disable_result_log + --error 0,1220 + eval SHOW BINLOG EVENTS FROM $pos LIMIT 100; + --inc $pos + --enable_result_log + --enable_query_log +} + +DROP TABLE t1; diff --git a/sql/log_event.cc b/sql/log_event.cc index 65f29441e1a..293bfa6680e 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -3502,7 +3502,6 @@ code_name(int code) #define CHECK_SPACE(PTR,END,CNT) \ do { \ DBUG_PRINT("info", ("Read %s", code_name(pos[-1]))); \ - DBUG_ASSERT((PTR) + (CNT) <= (END)); \ if ((PTR) + (CNT) > (END)) { \ DBUG_PRINT("info", ("query= 0")); \ query= 0; \ @@ -3815,7 +3814,7 @@ Query_log_event::Query_log_event(const char* buf, uint event_len, uint32 max_length= uint32(event_len - ((const char*)(end + db_len + 1) - (buf - common_header_len))); - if (q_len != max_length) + if (q_len != max_length || q_len > event_len) { q_len= 0; query= NULL; @@ -5889,6 +5888,9 @@ int Load_log_event::copy_log_event(const char *buf, ulong event_len, { DBUG_ENTER("Load_log_event::copy_log_event"); uint data_len; + + if ((int) event_len < body_offset) + DBUG_RETURN(1); char* buf_end = (char*)buf + event_len; /* this is the beginning of the post-header */ const char* data_head = buf + description_event->common_header_len; @@ -5898,18 +5900,17 @@ int Load_log_event::copy_log_event(const char *buf, ulong event_len, table_name_len = (uint)data_head[L_TBL_LEN_OFFSET]; db_len = (uint)data_head[L_DB_LEN_OFFSET]; num_fields = uint4korr(data_head + L_NUM_FIELDS_OFFSET); - - if ((int) event_len < body_offset) - DBUG_RETURN(1); + /* Sql_ex.init() on success returns the pointer to the first byte after the sql_ex structure, which is the start of field lengths array. */ + if (!(field_lens= (uchar*)sql_ex.init((char*)buf + body_offset, buf_end, (uchar)buf[EVENT_TYPE_OFFSET] != LOAD_EVENT))) DBUG_RETURN(1); - + data_len = event_len - body_offset; if (num_fields > data_len) // simple sanity check against corruption DBUG_RETURN(1); @@ -6449,7 +6450,7 @@ Rotate_log_event::Rotate_log_event(const char* buf, uint event_len, // The caller will ensure that event_len is what we have at EVENT_LEN_OFFSET uint8 post_header_len= description_event->post_header_len[ROTATE_EVENT-1]; uint ident_offset; - if (event_len < LOG_EVENT_MINIMAL_HEADER_LEN) + if (event_len < (uint)(LOG_EVENT_MINIMAL_HEADER_LEN + post_header_len)) DBUG_VOID_RETURN; buf+= LOG_EVENT_MINIMAL_HEADER_LEN; pos= post_header_len ? uint8korr(buf + R_POS_OFFSET) : 4; @@ -7955,6 +7956,12 @@ User_var_log_event(const char* buf, uint event_len, we keep the flags set to UNDEF_F. */ uint bytes_read= ((val + val_len) - buf_start); + if (bytes_read > event_len) + { + error= true; + goto err; + } + if ((data_written - bytes_read) > 0) { flags= (uint) *(buf + UV_VAL_IS_NULL + UV_VAL_TYPE_SIZE + @@ -9513,7 +9520,8 @@ Rows_log_event::Rows_log_event(const char *buf, uint event_len, uint8 const common_header_len= description_event->common_header_len; Log_event_type event_type= (Log_event_type) buf[EVENT_TYPE_OFFSET]; m_type= event_type; - + m_cols_ai.bitmap= 0; + uint8 const post_header_len= description_event->post_header_len[event_type-1]; DBUG_PRINT("enter",("event_len: %u common_header_len: %d " @@ -9546,7 +9554,16 @@ Rows_log_event::Rows_log_event(const char *buf, uint event_len, which includes length bytes */ var_header_len= uint2korr(post_start); - assert(var_header_len >= 2); + + /* Check length and also avoid out of buffer read */ + if (var_header_len < 2 || + event_len < static_cast<unsigned int>(var_header_len + + (post_start - buf))) + { + m_cols.bitmap= 0; + DBUG_VOID_RETURN; + } + var_header_len-= 2; /* Iterate over var-len header, extracting 'chunks' */ @@ -11047,6 +11064,10 @@ Table_map_log_event::Table_map_log_event(const char *buf, uint event_len, /* Length of table name + counter + terminating null */ uchar const *const ptr_colcnt= ptr_tbllen + m_tbllen + 2; uchar *ptr_after_colcnt= (uchar*) ptr_colcnt; + bytes_read= (unsigned int) (ptr_after_colcnt - (unsigned char *)buf); + /* Avoid reading out of buffer */ + if (event_len <= bytes_read) + DBUG_VOID_RETURN; m_colcnt= net_field_length(&ptr_after_colcnt); DBUG_PRINT("info",("m_dblen: %lu off: %ld m_tbllen: %lu off: %ld m_colcnt: %lu off: %ld", @@ -11074,15 +11095,24 @@ Table_map_log_event::Table_map_log_event(const char *buf, uint event_len, if (bytes_read < event_len) { m_field_metadata_size= net_field_length(&ptr_after_colcnt); - DBUG_ASSERT(m_field_metadata_size <= (m_colcnt * 2)); - uint num_null_bytes= (m_colcnt + 7) / 8; - m_meta_memory= (uchar *)my_multi_malloc(MYF(MY_WME), - &m_null_bits, num_null_bytes, - &m_field_metadata, m_field_metadata_size, - NULL); - memcpy(m_field_metadata, ptr_after_colcnt, m_field_metadata_size); - ptr_after_colcnt= (uchar*)ptr_after_colcnt + m_field_metadata_size; - memcpy(m_null_bits, ptr_after_colcnt, num_null_bytes); + if (m_field_metadata_size <= (m_colcnt * 2)) + { + uint num_null_bytes= (m_colcnt + 7) / 8; + m_meta_memory= (uchar *)my_multi_malloc(MYF(MY_WME), + &m_null_bits, num_null_bytes, + &m_field_metadata, m_field_metadata_size, + NULL); + memcpy(m_field_metadata, ptr_after_colcnt, m_field_metadata_size); + ptr_after_colcnt= (uchar*)ptr_after_colcnt + m_field_metadata_size; + memcpy(m_null_bits, ptr_after_colcnt, num_null_bytes); + } + else + { + m_coltype= NULL; + my_free(m_memory); + m_memory= NULL; + DBUG_VOID_RETURN; + } } } @@ -12739,9 +12769,12 @@ void Update_rows_log_event::init(MY_BITMAP const *cols) Update_rows_log_event::~Update_rows_log_event() { - if (m_cols_ai.bitmap == m_bitbuf_ai) // no my_malloc happened - m_cols_ai.bitmap= 0; // so no my_free in my_bitmap_free - my_bitmap_free(&m_cols_ai); // To pair with my_bitmap_init(). + if (m_cols_ai.bitmap) + { + if (m_cols_ai.bitmap == m_bitbuf_ai) // no my_malloc happened + m_cols_ai.bitmap= 0; // so no my_free in my_bitmap_free + my_bitmap_free(&m_cols_ai); // To pair with my_bitmap_init(). + } }