[Commits] cb8d888c42a: MDEV-17260: Memory leaks in mysqlbinlog
revision-id: cb8d888c42aa9504db2df686f0e963b99079e287 (mariadb-5.5.63-20-gcb8d888c42a) parent(s): e5aa8ea52552759453fdd86eeab0007df1781b62 author: Sujatha Sivakumar committer: Sujatha Sivakumar timestamp: 2019-04-24 11:40:52 +0530 message: MDEV-17260: Memory leaks in mysqlbinlog Problem: ======== The mysqlbinlog tool is leaking memory, causing failures in various tests when compiling and testing with AddressSanitizer or LeakSanitizer like this: cmake -DCMAKE_BUILD_TYPE=Debug -DWITH_ASAN:BOOL=ON /path/to/source make -j$(nproc) cd mysql-test ASAN_OPTIONS=abort_on_error=1 ./mtr --parallel=auto rpl.rpl_row_mysqlbinlog CURRENT_TEST: rpl.rpl_row_mysqlbinlog Direct leak of 112 byte(s) in 1 object(s) allocated from: #0 0x4eff87 in __interceptor_malloc (/dev/shm/5.5/client/mysqlbinlog+0x4eff87) #1 0x60eaab in my_malloc /mariadb/5.5/mysys/my_malloc.c:41:10 #2 0x5300dd in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /mariadb/5.5/sql/log_event.cc:1568: #3 0x564a9c in dump_remote_log_entries(st_print_event_info*, char const*) /mariadb/5.5/client/mysqlbinlog.cc:1978:17 Analysis: ======== 'mysqlbinlog' tool is being used to read binary log events from a remote server. While reading binary log, if a fake rotate event is found following actions are taken. If 'to-last-log' option is specified, then fake rotate event is processed. In the absence of 'to-last-log' skip the fake rotate event. In this skipped case the fake rotate event object is not getting cleaned up resulting in memory leak. Fix: === Cleanup the fake rotate event. This issues is already fixed in MariaDB 10.0.23 and higher versions as part of commit c3018b0ff4fb02c029787d03867adf0530607bab --- client/mysqlbinlog.cc | 2 ++ 1 file changed, 2 insertions(+) diff --git a/client/mysqlbinlog.cc b/client/mysqlbinlog.cc index 250dc609891..1a11e3e697b 100644 --- a/client/mysqlbinlog.cc +++ b/client/mysqlbinlog.cc @@ -2020,6 +2020,7 @@ static Exit_status dump_remote_log_entries(PRINT_EVENT_INFO *print_event_info, if ((rev->ident_len != logname_len) || memcmp(rev->new_log_ident, logname, logname_len)) { + delete ev; DBUG_RETURN(OK_CONTINUE); } /* @@ -2028,6 +2029,7 @@ static Exit_status dump_remote_log_entries(PRINT_EVENT_INFO *print_event_info, log. If we are running with to_last_remote_log, we print it, because it serves as a useful marker between binlogs then. */ + delete ev; continue; } len= 1; // fake Rotate, so don't increment old_off
Sujatha, hello. The patch looks good, I only have a suggestion to the test for better readability, within the quoted patch below. Thanks for a good piece of work! Cheers, Andrei
commit 8ae7a5eb03725441393c353e4e203f80b666c035 Author: Sujatha Sivakumar <sujatha.sivakumar@mariadb.com> Date: Tue Apr 23 19:47:59 2019 +0530
MDEV-17260: Memory leaks in mysqlbinlog
Problem: ======== The mysqlbinlog tool is leaking memory, causing failures in various tests when compiling and testing with AddressSanitizer or LeakSanitizer like this:
cmake -DCMAKE_BUILD_TYPE=Debug -DWITH_ASAN:BOOL=ON /path/to/source make -j$(nproc) cd mysql-test ASAN_OPTIONS=abort_on_error=1 ./mtr --parallel=auto
Analysis: ========= Two types of leaks were observed during above execution.
1) Leak in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) File: sql/log_event.cc:2150
For all row based replication events the memory which is allocated during read_log_event is not freed after the event is processed. The event specific memory has to be retained only when flashback option is enabled with mysqlbinlog tool. In this case all the events are retained till the end statement is received and they are processed in reverse order and they are destroyed. But in the existing code all events are retained irrespective of flashback mode. Hence the memory leaks are observed.
2) read_remote_annotate_event(unsigned char*, unsigned long, char const**) File: client/mysqlbinlog.cc:194
In general the Annotate event is not printed immediately because all subsequent rbr-events can be filtered away. Instead it will be printed together with the first not filtered away Table map or the last rbr will be processed. While reading remote annotate events memory is allocated for event buffer and event's temp_buf is made to point to the allocated buffer as shown below. The TRUE flag is used for doing proper cleanup using free_temp_buf(). i.e at the time of deletion of annotate event its destructor takes care of clearing the temp_buf.
/* Ensure the event->temp_buf is pointing to the allocated buffer. (TRUE = free temp_buf on the event deletion) */ event->register_temp_buf((char*)event_buf, TRUE);
But existing code does the following when it receives a remote annotate_event.
if (remote_opt) ev->temp_buf= 0;
That is code immediately sets temp_buf=0, because of which free_temp_buf() call will return empty handed as it has lost the reference to the allocated temporary buffer. This results in memory leak
Fix: ==== 1) If not in flashback mode, destroy the memory for events once they are processed.
2) Remove the ev->temp_buf=0 code for remote option. Let the proper cleanup to be done as part of free_temp_buf().
diff --git a/client/mysqlbinlog.cc b/client/mysqlbinlog.cc index cfc05cbf794..3dad4fef67b 100644 --- a/client/mysqlbinlog.cc +++ b/client/mysqlbinlog.cc @@ -227,8 +227,7 @@ void print_annotate_event(PRINT_EVENT_INFO *print_event_info) if (annotate_event) { annotate_event->print(result_file, print_event_info); - delete annotate_event; // the event should not be printed more than once - annotate_event= 0; + free_annotate_event(); } }
@@ -1465,7 +1464,7 @@ Exit_status process_event(PRINT_EVENT_INFO *print_event_info, Log_event *ev, if (print_row_event(print_event_info, ev, e->get_table_id(), e->get_flags(Rows_log_event::STMT_END_F))) goto err; - if (!is_stmt_end) + if (opt_flashback && !is_stmt_end) destroy_evt= FALSE; break; } @@ -1478,7 +1477,7 @@ Exit_status process_event(PRINT_EVENT_INFO *print_event_info, Log_event *ev, if (print_row_event(print_event_info, ev, e->get_table_id(), e->get_flags(Old_rows_log_event::STMT_END_F))) goto err; - if (!is_stmt_end) + if (opt_flashback && !is_stmt_end) destroy_evt= FALSE; break; } @@ -1539,8 +1538,6 @@ Exit_status process_event(PRINT_EVENT_INFO *print_event_info, Log_event *ev, } }
- if (remote_opt) - ev->temp_buf= 0; if (destroy_evt) /* destroy it later if not set (ignored table map) */ delete ev; } diff --git a/mysql-test/suite/binlog/r/flashback.result b/mysql-test/suite/binlog/r/flashback.result index c96eaebe838..047c032b5df 100644 --- a/mysql-test/suite/binlog/r/flashback.result +++ b/mysql-test/suite/binlog/r/flashback.result @@ -674,6 +674,28 @@ world.city 563256876 DROP TABLE test.test; DROP TABLE world.city; DROP DATABASE world; +# < CASE 7 > +# Test Case for MDEV-17260 +# +RESET MASTER; +CREATE TABLE t1 ( f INT PRIMARY KEY ) ENGINE=innodb; +INSERT INTO t1 VALUES (1),(2),(3),(4),(5),(6); +# 6- Rows must be present +SELECT COUNT(*) FROM t1; +COUNT(*) +6 +FLUSH LOGS; +DELETE FROM t1; +FLUSH LOGS; +# 0- Rows must be present +SELECT COUNT(*) FROM t1; +COUNT(*) +0 +# 6- Rows must be present upon restoring from flashback +SELECT COUNT(*) FROM t1; +COUNT(*) +6 +DROP TABLE t1; SET binlog_format=statement; Warnings: Warning 1105 MariaDB Galera and flashback do not support binlog format: STATEMENT diff --git a/mysql-test/suite/binlog/t/flashback.test b/mysql-test/suite/binlog/t/flashback.test index 3fc8c44c60c..fb80669ca51 100644 --- a/mysql-test/suite/binlog/t/flashback.test +++ b/mysql-test/suite/binlog/t/flashback.test @@ -335,8 +335,29 @@ DROP TABLE test.test; DROP TABLE world.city; DROP DATABASE world;
-## Clear +--echo # < CASE 7 > +--echo # Test Case for MDEV-17260 +--echo # +RESET MASTER; + +CREATE TABLE t1 ( f INT PRIMARY KEY ) ENGINE=innodb; +INSERT INTO t1 VALUES (1),(2),(3),(4),(5),(6); +--echo # 6- Rows must be present +SELECT COUNT(*) FROM t1;
SELECT COUNT(*) as six FROM t1; would read better though it's far from being the optimal automation. (The optimal one clearly must also count 'six' or whatever number itself, as well as bail out with an error when count(*) won't match the expected # - sure not for the current patch).
+FLUSH LOGS; +DELETE FROM t1; +FLUSH LOGS; +--echo # 0- Rows must be present +SELECT COUNT(*) FROM t1; +--exec $MYSQL_BINLOG -vv -B --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000002> $MYSQLTEST_VARDIR/tmp/mysqlbinlog_row_flashback_7.sql +--exec $MYSQL -e "SET binlog_format= ROW; source $MYSQLTEST_VARDIR/tmp/mysqlbinlog_row_flashback_7.sql;" + +--echo # 6- Rows must be present upon restoring from flashback +SELECT COUNT(*) FROM t1;
+DROP TABLE t1; + +## Clear SET binlog_format=statement; --error ER_FLASHBACK_NOT_SUPPORTED SET GLOBAL binlog_format=statement;
participants (2)
-
andrei.elkin＠pp.inet.fi -
sujatha