| Bug #79000 | Valgrind error on rpl.rpl_4threads_deadlock | ||
|---|---|---|---|
| Submitted: | 28 Oct 2015 11:11 | Modified: | 7 Dec 2015 9:09 |
| Reporter: | Laurynas Biveinis (OCA) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.7.9 | OS: | Ubuntu (15.10) |
| Assigned to: | CPU Architecture: | Any | |
[29 Oct 2015 12:22]
MySQL Verification Team
Which OS are you using?. On CentOS 6.5 I got valgrind report fail but the test passed:
[miguel@miguelbr mysql-test]$ ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock
Logging: ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock
2015-10-29T12:13:03.988508Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
2015-10-29T12:13:03.988592Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
MySQL Version 5.7.9
Turning on valgrind for all executables
Running valgrind with options " --track-origins=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
- SSL connections supported
- binaries are debug compiled
Collecting tests...
- adding combinations for rpl
Removing old var directory...
Creating var directory '/home/miguel/bugtest/mysql-5.7.9/mysql-test/var'...
Installing system database...
==============================================================================
TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
rpl.rpl_4threads_deadlock 'mix' [ skipped ] Doesn't support --binlog-format='mixed'
rpl.rpl_4threads_deadlock 'row' [ skipped ] Doesn't support --binlog-format='row'
rpl.rpl_4threads_deadlock 'stmt' [ pass ] 88861
worker[1] Valgrind report from /home/miguel/bugtest/mysql-5.7.9/mysql-test/var/log/mysqld.2.err after tests:
rpl.rpl_4threads_deadlock
--------------------------------------------------------------------------
HEAP SUMMARY:
in use at exit: 64 bytes in 2 blocks
total heap usage: 118,565 allocs, 118,563 frees, 397,780,008 bytes allocated
LEAK SUMMARY:
definitely lost: 0 bytes in 0 blocks
indirectly lost: 0 bytes in 0 blocks
possibly lost: 0 bytes in 0 blocks
still reachable: 64 bytes in 2 blocks
suppressed: 0 bytes in 0 blocks
Reachable blocks (those to which a pointer was found) are not shown.
To see them, rerun with: --leak-check=full --show-reachable=yes
[miguel@miguelbr mysql-test]$ ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock
Logging: ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock
2015-10-29T12:13:03.988508Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
2015-10-29T12:13:03.988592Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
MySQL Version 5.7.9
Turning on valgrind for all executables
Running valgrind with options " --track-origins=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
- SSL connections supported
- binaries are debug compiled
Collecting tests...
- adding combinations for rpl
Removing old var directory...
Creating var directory '/home/miguel/bugtest/mysql-5.7.9/mysql-test/var'...
Installing system database...
==============================================================================
TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
rpl.rpl_4threads_deadlock 'mix' [ skipped ] Doesn't support --binlog-format='mixed'
rpl.rpl_4threads_deadlock 'row' [ skipped ] Doesn't support --binlog-format='row'
rpl.rpl_4threads_deadlock 'stmt' [ pass ] 88861
worker[1] Valgrind report from /home/miguel/bugtest/mysql-5.7.9/mysql-test/var/log/mysqld.2.err after tests:
rpl.rpl_4threads_deadlock
--------------------------------------------------------------------------
HEAP SUMMARY:
in use at exit: 64 bytes in 2 blocks
total heap usage: 118,565 allocs, 118,563 frees, 397,780,008 bytes allocated
LEAK SUMMARY:
definitely lost: 0 bytes in 0 blocks
indirectly lost: 0 bytes in 0 blocks
possibly lost: 0 bytes in 0 blocks
still reachable: 64 bytes in 2 blocks
suppressed: 0 bytes in 0 blocks
Reachable blocks (those to which a pointer was found) are not shown.
To see them, rerun with: --leak-check=full --show-reachable=yes
For counts of detected and suppressed errors, rerun with: -v
ERROR SUMMARY: 143 errors from 37 contexts (suppressed: 6 from 6)
safe_process[19009]: Child process: 19010, exit: 42
valgrind_report [ fail ]
Test ended at 2015-10-29 10:17:05
Valgrind reported failures at shutdown, see above
For counts of detected and suppressed errors, rerun with: -v
ERROR SUMMARY: 143 errors from 37 contexts (suppressed: 6 from 6)
safe_process[19009]: Child process: 19010, exit: 42
valgrind_report [ fail ]
Test ended at 2015-10-29 10:17:05
Valgrind reported failures at shutdown, see above
[29 Oct 2015 14:19]
Laurynas Biveinis
Miguel, this is on Ubuntu 15.10.
[30 Oct 2015 9:40]
MySQL Verification Team
Thank you for the feedback.
Verified as described on Ubuntu 15.10 with 5.7.9 build as reported.
ushastry@ubuntu1510:~/Downloads/mysql-5.7.9/mysql-test$ ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock
Logging: ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock
MySQL Version 5.7.9
Turning on valgrind for all executables
Running valgrind with options " --track-origins=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
- SSL connections supported
- binaries are debug compiled
Collecting tests...
- adding combinations for rpl
Removing old var directory...
Creating var directory '/home/ushastry/Downloads/mysql-5.7.9/mysql-test/var'...
Installing system database...
==============================================================================
TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
rpl.rpl_4threads_deadlock 'mix' [ skipped ] Doesn't support --binlog-format='mixed'
rpl.rpl_4threads_deadlock 'row' [ skipped ] Doesn't support --binlog-format='row'
worker[1] mysql-test-run: WARNING: Waited 60 seconds for /home/ushastry/Downloads/mysql-5.7.9/mysql-test/var/run/mysqld.1.pid to be created, still waiting for 1740 seconds...
rpl.rpl_4threads_deadlock 'stmt' [ fail ] Found warnings/errors in server log file!
Test ended at 2015-10-30 15:00:50
line
==30353== Thread 30:
==30353== Conditional jump or move depends on uninitialised value(s)
==30353== at 0x4C31C12: __GI_memcmp (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==30353== by 0x1859F89: Log_in_use::operator()(THD*) (binlog.cc:2477)
==30353== by 0xE9E98F: Do_THD::operator()(THD*) (mysqld_thd_manager.cc:46)
==30353== by 0xE9EF6B: Do_THD std::for_each<THD**, Do_THD>(THD**, THD**, Do_THD) (stl_algo.h:3767)
==30353== by 0xE9E5C0: Global_THD_manager::do_for_all_thd(Do_THD_Impl*) (mysqld_thd_manager.cc:273)
==30353== by 0x18411FE: log_in_use(char const*) (binlog.cc:2500)
==30353== by 0x184A8A6: MYSQL_BIN_LOG::purge_logs_before_date(long, bool) (binlog.cc:6160)
==30353== by 0x18418C4: purge_master_logs_before_date(THD*, long) (binlog.cc:2717)
==30353== by 0x1599AD6: mysql_execute_command(THD*, bool) (sql_parse.cc:2665)
==30353== by 0x15A1800: mysql_parse(THD*, Parser_state*) (sql_parse.cc:5357)
==30353== by 0x159662F: dispatch_command(THD*, COM_DATA const*, enum_server_command) (sql_parse.cc:1284)
==30353== by 0x1595533: do_command(THD*) (sql_parse.cc:852)
==30353== by 0x16D6829: handle_connection (connection_handler_per_thread.cc:295)
==30353== by 0x1922412: pfs_spawn_thread (pfs.cc:2192)
==30353== by 0x5D376A9: start_thread (pthread_create.c:333)
==30353== by 0x68F5EEC: clone (clone.S:109)
==30353== Uninitialised value was created by a stack allocation
==30353== at 0x186C947: mysql_binlog_send(THD*, char*, unsigned long long, Gtid_set*, unsigned int) (rpl_master.cc:412)
^ Found warnings in /home/ushastry/Downloads/mysql-5.7.9/mysql-test/var/log/mysqld.1.err
ok
- the logfile can be found in '/home/ushastry/Downloads/mysql-5.7.9/mysql-test/var/log/rpl.rpl_4threads_deadlock-stmt/rpl_4threads_deadlock.log'
worker[1] Valgrind report from /home/ushastry/Downloads/mysql-5.7.9/mysql-test/var/log/mysqld.2.err after tests:
rpl.rpl_4threads_deadlock
--------------------------------------------------------------------------
HEAP SUMMARY:
in use at exit: 72,768 bytes in 3 blocks
total heap usage: 118,687 allocs, 118,684 frees, 397,891,109 bytes allocated
LEAK SUMMARY:
definitely lost: 0 bytes in 0 blocks
indirectly lost: 0 bytes in 0 blocks
possibly lost: 0 bytes in 0 blocks
still reachable: 72,768 bytes in 3 blocks
suppressed: 0 bytes in 0 blocks
Reachable blocks (those to which a pointer was found) are not shown.
To see them, rerun with: --leak-check=full --show-leak-kinds=all
For counts of detected and suppressed errors, rerun with: -v
ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
valgrind_report [ fail ]
Test ended at 2015-10-30 15:00:50
Valgrind reported failures at shutdown, see above
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 240 seconds executing testcases
mysql-test-run: WARNING: Got errors/warnings while running tests, please examine '/home/ushastry/Downloads/mysql-5.7.9/mysql-test/var/log/warnings' for details.
Completed: Failed 2/2 tests, 0.00% were successful.
Failing test(s): rpl.rpl_4threads_deadlock valgrind_report
The log files in var/log may give you some hint of what went wrong.
If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
2 tests were skipped, 0 by the test itself.
mysql-test-run: *** ERROR: there were failing test cases
// OS and other details
ushastry@ubuntu1510:~/Downloads/mysql-5.7.9/mysql-test$ cat /etc/*release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=15.10
DISTRIB_CODENAME=wily
DISTRIB_DESCRIPTION="Ubuntu 15.10"
NAME="Ubuntu"
VERSION="15.10 (Wily Werewolf)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 15.10"
VERSION_ID="15.10"
HOME_URL="http://www.ubuntu.com/"
SUPPORT_URL="http://help.ubuntu.com/"
BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
ushastry@ubuntu1510:~/Downloads/mysql-5.7.9/mysql-test$ valgrind --version
valgrind-3.11.0
ushastry@ubuntu1510:~/Downloads/mysql-5.7.9/mysql-test$ cmake --version
cmake version 3.2.2
CMake suite maintained and supported by Kitware (kitware.com/cmake).
[30 Oct 2015 9:43]
MySQL Verification Team
// With the same build, etc I didn't see any issue on OL7(test passed and valgrind error as also seen by Miguel on Cent OS 6.5)
[7 Dec 2015 9:09]
David Moss
Thanks for your feedback. This is fixed in upcoming versions. This seems to be related to testing only, therefore closing without a change log entry.
Description: cmake ... -DBUILD_CONFIG=mysql_release -DWITH_DEBUG=ON -DWITH_VALGRIND=ON -DWITH_SSL=system -DWITH_BOOST=... ... ./mtr --debug-server --valgrind-mysqld --valgrind-option=--track-origins=yes rpl_4threads_deadlock ... rpl.rpl_4threads_deadlock 'stmt' [ fail ] Found warnings/errors in server log file! Test ended at 2015-10-28 13:05:47 line ==21657== Thread 30: ==21657== Conditional jump or move depends on uninitialised value(s) ==21657== at 0x4C31D52: __memcmp_sse4_1 (vg_replace_strmem.c:1094) ==21657== by 0x1837D3B: Log_in_use::operator()(THD*) (binlog.cc:2477) ==21657== by 0xE9E4A7: Do_THD::operator()(THD*) (mysqld_thd_manager.cc:46) ==21657== by 0xE9EA83: Do_THD std::for_each<THD**, Do_THD>(THD**, THD**, Do_THD) (stl_algo.h:3767) ==21657== by 0xE9E0D8: Global_THD_manager::do_for_all_thd(Do_THD_Impl*) (mysqld_thd_manager.cc:273) ==21657== by 0x181EFB0: log_in_use(char const*) (binlog.cc:2500) ==21657== by 0x1828658: MYSQL_BIN_LOG::purge_logs_before_date(long, bool) (binlog.cc:6160) ==21657== by 0x181F676: purge_master_logs_before_date(THD*, long) (binlog.cc:2717) ==21657== by 0x158AFAC: mysql_execute_command(THD*, bool) (sql_parse.cc:2665) ==21657== by 0x1592ADA: mysql_parse(THD*, Parser_state*) (sql_parse.cc:5357) ==21657== by 0x1587B05: dispatch_command(THD*, COM_DATA const*, enum_server_command) (sql_parse.cc:1284) ==21657== by 0x1586A09: do_command(THD*) (sql_parse.cc:852) ==21657== by 0x16BFCA1: handle_connection (connection_handler_per_thread.cc:295) ==21657== by 0x1D738C4: pfs_spawn_thread (pfs.cc:2192) ==21657== by 0x5D376A9: start_thread (pthread_create.c:333) ==21657== by 0x68F5EEC: clone (clone.S:109) ==21657== Uninitialised value was created by a stack allocation ==21657== at 0x1848E85: mysql_binlog_send(THD*, char*, unsigned long long, Gtid_set*, unsigned int) (rpl_master.cc:412) How to repeat: See above