← Back to team overview

maria-developers team mailing list archive

Re: [Commits] 8ae7a5eb037: MDEV-17260: Memory leaks in mysqlbinlog

 

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