Description:
Reduced testcase from bug 70860 hits a code path where LOCK_log is locked twice instead of locked and unlocked because of a typo.
Run a testcase below, then open mysqld1.restart.err and you will see
safe_mutex: Trying to lock mutex at /Users/laurynas/percona/lp-mysql-server/mysql-server/sql/binlog.cc, line 6492, when the mutex was already locked at /Users/laurynas/percona/lp-mysql-server/mysql-server/sql/binlog.cc, line 6487 in thread T@1
16:14:05 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60980 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
0 mysqld 0x000000010f6202e2 my_print_stacktrace + 66
1 mysqld 0x000000010f5295f2 handle_fatal_signal + 962
2 libsystem_platform.dylib 0x00007fff99a6c5aa _sigtramp + 26
3 ??? 0x0000000000000000 0x0 + 0
4 libsystem_c.dylib 0x00007fff99accb1a abort + 125
5 mysqld 0x000000010f62573d safe_mutex_lock + 333
6 mysqld 0x000000010f572c82 _Z23inline_mysql_mutex_lockP14st_mysql_mutexPKcj + 98
7 mysqld 0x000000010f5857bc _ZN13MYSQL_BIN_LOG11open_binlogEPKc + 636
8 mysqld 0x000000010f59143d _ZN13MYSQL_BIN_LOG4openEPKc + 29
9 mysqld 0x000000010f5131a1 _ZL22init_server_componentsv + 3969
10 mysqld 0x000000010f510550 _Z11mysqld_mainiPPc + 1280
11 mysqld 0x000000010efe46f2 main + 34
12 libdyld.dylib 0x00007fff8e6175fd start + 1
How to repeat:
--source include/not_embedded.inc
--source include/not_valgrind.inc
--source include/have_debug.inc
--source include/have_innodb.inc
--source include/have_log_bin.inc
let $restart_file= $MYSQLTEST_VARDIR/tmp/mysqld.1.expect;
let $restart_log= $MYSQLTEST_VARDIR/log/mysqld.1.restart.err;
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
INSERT INTO t1 VALUES (1);
BEGIN;
INSERT INTO t1 VALUES (2);
SET SESSION debug="d,crash_commit_after_prepare";
--exec echo "wait" > $restart_file
--error 2006, 2013
COMMIT;
--source include/wait_until_disconnected.inc
--echo Restarting with --tc-heuristic-recover=ROLLBACK
--error 1
--exec $MYSQLD_CMD --tc-heuristic-recover=ROLLBACK --console > $restart_log 2>&1
--exec echo "restart" > $restart_file
--enable_reconnect
--source include/wait_until_connected_again.inc
--echo 2 should be absent:
SELECT * FROM t1;
DROP TABLE t1;
Suggested fix:
The code in question is
mysql_mutex_lock(&LOCK_log);
open_binlog(opt_name, 0, max_binlog_size, false,
true/*need_lock_index=true*/,
true/*need_sid_lock=true*/,
NULL);
mysql_mutex_lock(&LOCK_log);
The fix is obvious.
