Bug #82283 main.mysqlbinlog_debug fails with a LeakSanitizer error
| Submitted: | 19 Jul 2016 15:13 | Modified: | 14 Jul 2017 14:27 |
|---|---|---|---|
| Reporter: | Laurynas Biveinis (OCA) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.6,5.7, 5.7.13 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | asan, lsan, mysqlbinlog | ||
[19 Jul 2016 16:54]
MySQL Verification Team
Thank you for the bug repoprt. Which version of 5.7.X you tested? I couldn't repeat with 5.7.13 on MAC OSX: iguel:mysql-5.7.13 miguel$ cd mysql-test/ miguel:mysql-test miguel$ ./mtr --debug-server mysqlbinlog_debug Logging: ./mtr --debug-server mysqlbinlog_debug MySQL Version 5.7.13 Checking supported features... - SSL connections supported - binaries are debug compiled Collecting tests... Removing old var directory... Creating var directory '/Users/miguel/Downloads/mysql-5.7.13/mysql-test/var'... Installing system database... ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 main.mysqlbinlog_debug [ pass ] 924 -------------------------------------------------------------------------- The servers were restarted 0 times Spent 0.924 of 48 seconds executing testcases Completed: All 1 tests were successful. miguel:mysql-test miguel$ cmake -DWITH_ASAN=ON -DCMAKE_BUILD_TYPE=Debug -DWITH_BOOST=./boost/boost_1_59_0/
[20 Jul 2016 4:36]
Laurynas Biveinis
This is not on on Mac, as its AddressSanitizer does not contain LeakSanitizer. I have tested latest 5.6 and 5.7 on Ubuntu Xenial.
[20 Jul 2016 7:09]
MySQL Verification Team
Thank you for the details.
[20 Jul 2016 7:09]
MySQL Verification Team
test results
Attachment: 82283.log (text/x-log), 2.88 MiB.
[22 Jul 2016 7:08]
Laurynas Biveinis
Bug 82283 fix for 5.7 (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.
Contribution: bug82283-5.7.patch (application/octet-stream, text), 1.28 KiB.
[19 Apr 2017 2:28]
Laurynas Biveinis
Same issue seen with Valgrind on 8.0.1: ==1066== 78 bytes in 1 blocks are indirectly lost in loss record 573 of 636 ==1066== at 0x4C2E19F: operator new(unsigned long) (vg_replace_malloc.c:334) ==1066== by 0x2910FB: __gnu_cxx::new_allocator<unsigned char>::allocate(unsigned long, void const*) (new_allocator.h:104) ==1066== by 0x290BF7: std::allocator_traits<std::allocator<unsigned char> >::allocate(std::allocator<unsigned char>&, unsigned long) (alloc_traits.h:436) ==1066== by 0x2903D5: std::_Vector_base<unsigned char, std::allocator<unsigned char> >::_M_allocate(unsigned long) (stl_vector.h:170) ==1066== by 0x29067F: void std::vector<unsigned char, std::allocator<unsigned char> >::_M_range_insert<unsigned char const*>(__gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > >, unsigned char const*, unsigned char const*, std::forward_iterator_tag) (vector.tcc:659) ==1066== by 0x28F8A0: void std::vector<unsigned char, std::allocator<unsigned char> >::_M_insert_dispatch<unsigned char const*>(__gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > >, unsigned char const*, unsigned char const*, std::__false_type) (stl_vector.h:1375) ==1066== by 0x28F1AD: __gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > > std::vector<unsigned char, std::allocator<unsigned char> >::insert<unsigned char const*, void>(__gnu_cxx::__normal_iterator<unsigned char const*, std::vector<unsigned char, std::allocator<unsigned char> > >, unsigned char const*, unsigned char const*) (stl_vector.h:1100) ==1066== by 0x28D03F: binary_log::Format_description_event::Format_description_event(char const*, unsigned int, binary_log::Format_description_event const*) (control_events.cpp:339) ==1066== by 0x196EE6: Format_description_log_event::Format_description_log_event(char const*, unsigned int, binary_log::Format_description_event const*) (log_event.cc:5585) ==1066== by 0x1905EB: Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, bool) (log_event.cc:1717) ==1066== by 0x188B39: dump_remote_log_entries(st_print_event_info*, char const*) (mysqlbinlog.cc:2377) ==1066== by 0x18803E: dump_single_log(st_print_event_info*, char const*) (mysqlbinlog.cc:2069) ==1066== by 0x188240: dump_multiple_logs(int, char**) (mysqlbinlog.cc:2110) ==1066== by 0x18A5A5: main (mysqlbinlog.cc:3088) ==1066== ==1066== 382 (304 direct, 78 indirect) bytes in 1 blocks are definitely lost in loss record 592 of 636 ==1066== at 0x212C35: my_malloc (my_malloc.cc:80) ==1066== by 0x18F8C3: Log_event::operator new(unsigned long) (log_event.cc:872) ==1066== by 0x1905CF: Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, bool) (log_event.cc:1717) ==1066== by 0x188B39: dump_remote_log_entries(st_print_event_info*, char const*) (mysqlbinlog.cc:2377) ==1066== by 0x18803E: dump_single_log(st_print_event_info*, char const*) (mysqlbinlog.cc:2069) ==1066== by 0x188240: dump_multiple_logs(int, char**) (mysqlbinlog.cc:2110) ==1066== by 0x18A5A5: main (mysqlbinlog.cc:3088) ==1066==
[6 Jun 2017 10:55]
Laurynas Biveinis
Bug 82283 fix for 8.0.1
Attachment: bug82283-8.0.1.patch (application/octet-stream, text), 1.75 KiB.
[14 Jul 2017 14:27]
Margaret Fisher
Posted by developer:
Changelog entry added for MySQL 8.0.2, 5.7.19, and 5.6.37:
A memory leak in <command>mysqlbinlog</command> was fixed. The
leak happened when processing fake rotate events, or when using
<literal>--raw</literal> and the destination log file could not
be created. The leak only occurred when processing events from a
remote server. Thanks to Laurynas Biveinis for his contribution
to fixing this bug.
Portions of this website are copyright © 2001, 2002 The PHP Group
Page generated in 0.045 sec. using MySQL 8.4.7-u6-cloud
Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the
respective copyright holders.
It is not reviewed in advance
by Oracle and does not necessarily represent the opinion of
Oracle or any other party.
Description: On a system with AddressSanitizer support that includes LeakSanitizer, -DWITH_ASAN=ON -DCMAKE_BUILD_TYPE=Debug configured server will give $ ./mtr --debug-server mysqlbinlog_debug ... main.mysqlbinlog_debug [ fail ] Test ended at 2016-07-19 18:09:31 CURRENT_TEST: main.mysqlbinlog_debug mysqltest: At line 14: command "$MYSQL_BINLOG -#d,simulate_result_file_write_error_for_FD_event --raw --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT -r$MYSQLTEST_VARDIR/tmp/ master-bin.000001 2>&1" failed with wrong error: 42 The result from queries just before the failure was: # # Bug#18742916 : MYSQLBINLOG --RAW DOES NOT CHECK FOR ERRORS # safe_process[939]: Child process: 940, exit: 1 If "2>&1" is removed, then the output contains URRENT_TEST: main.mysqlbinlog_debug ERROR: Could not write into log file '/home/laurynas/obj-5.7-asan-debug/mysql-test/var/tmp/master-bin.000001' ================================================================= ==1117==ERROR: LeakSanitizer: detected memory leaks Direct leak of 336 byte(s) in 1 object(s) allocated from: #0 0x7fd08b154602 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x98602) #1 0x4e9004 in my_raw_malloc /home/laurynas/mysql-server/mysys/my_malloc.c:191 #2 0x4e9004 in my_malloc /home/laurynas/mysql-server/mysys/my_malloc.c:54 #3 0x4168c2 in Log_event::operator new(unsigned long) /home/laurynas/mysql-server/sql/log_event.cc:737 #4 0x42cdb7 in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /home/laurynas/mysql-server/sql/log_event.cc:1592 #5 0x449231 in dump_remote_log_entries /home/laurynas/mysql-server/client/mysqlbinlog.cc:2692 #6 0x449231 in dump_single_log /home/laurynas/mysql-server/client/mysqlbinlog.cc:2328 #7 0x449231 in dump_multiple_logs /home/laurynas/mysql-server/client/mysqlbinlog.cc:2368 #8 0x44a6de in main /home/laurynas/mysql-server/client/mysqlbinlog.cc:3430 #9 0x7fd08a05182f in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2082f) Indirect leak of 78 byte(s) in 1 object(s) allocated from: #0 0x7fd08b155532 in operator new(unsigned long) (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x99532) #1 0x5be727 in __gnu_cxx::new_allocator<unsigned char>::allocate(unsigned long, void const*) /usr/include/c++/5/ext/new_allocator.h:104 #2 0x5be727 in __gnu_cxx::__alloc_traits<std::allocator<unsigned char> >::allocate(std::allocator<unsigned char>&, unsigned long) /usr/include/c++/5/ext/alloc_traits.h:182 #3 0x5be727 in std::_Vector_base<unsigned char, std::allocator<unsigned char> >::_M_allocate(unsigned long) /usr/include/c++/5/bits/stl_vector.h:170 #4 0x5be727 in void std::vector<unsigned char, std::allocator<unsigned char> >::_M_range_insert<char const*>(__gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > >, char const*, char const*, std::forward_iterator_tag) /usr/include/c++/5/bits/vector.tcc:659 #5 0x5bc215 in void std::vector<unsigned char, std::allocator<unsigned char> >::_M_insert_dispatch<char const*>(__gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > >, char const*, char const*, std::__false_type) /usr/include/c++/5/bits/stl_vector.h:1377 #6 0x5bc215 in void std::vector<unsigned char, std::allocator<unsigned char> >::insert<char const*>(__gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > >, char const*, char const*) /usr/include/c++/5/bits/stl_vector.h:1125 #7 0x5bc215 in binary_log::Format_description_event::Format_description_event(char const*, unsigned int, binary_log::Format_description_event const*) /home/laurynas/mysql-server/libbinlogevents/src/control_events.cpp:345 #8 0x41ae85 in Format_description_log_event::Format_description_log_event(char const*, unsigned int, binary_log::Format_description_event const*) /home/laurynas/mysql-server/sql/log_event.cc:5242 #9 0x42cdd2 in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /home/laurynas/mysql-server/sql/log_event.cc:1592 #10 0x449231 in dump_remote_log_entries /home/laurynas/mysql-server/client/mysqlbinlog.cc:2692 #11 0x449231 in dump_single_log /home/laurynas/mysql-server/client/mysqlbinlog.cc:2328 #12 0x449231 in dump_multiple_logs /home/laurynas/mysql-server/client/mysqlbinlog.cc:2368 #13 0x44a6de in main /home/laurynas/mysql-server/client/mysqlbinlog.cc:3430 #14 0x7fd08a05182f in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2082f) SUMMARY: AddressSanitizer: 414 byte(s) leaked in 2 allocation(s). mysqltest: At line 14: command "$MYSQL_BINLOG -#d,simulate_result_file_write_error_for_FD_event --raw --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT -r$MYSQLTEST_VARDIR/tmp/ master-bin.000001" failed with wrong error: 42 The result from queries just before the failure was: # # Bug#18742916 : MYSQLBINLOG --RAW DOES NOT CHECK FOR ERRORS # safe_process[1109]: Child process: 1110, exit: 1 How to repeat: CMake options -DWITH_ASAN=ON -DCMAKE_BUILD_TYPE=Debug $ ./mtr --debug-server mysqlbinlog_debug