Description:
This server has been running for a while with git-mode enabled. Then I shutdown the server , set git-mode to OFF and restart the server. I got an endless crash....
the backtrace:
#0 0x0000003659e0c6bc in pthread_kill () from /lib64/libpthread.so.0
#1 0x000000000067eca2 in handle_fatal_signal (sig=11) at /u01/project/mysql-5.6.11/sql/signal_handler.cc:248
#2 <signal handler called>
#3 0x0000003659a80121 in strnlen () from /lib64/libc.so.6
#4 0x0000000000a95274 in process_str_arg (cs=0x12b38a0, to=0x7fff01b2426a "\340Y6", end=0x7fff01b2441f "", width=<value optimized out>, par=0xa8 <Address 0xa8 out of bounds>, print_type=0)
at /u01/project/mysql-5.6.11/strings/my_vsnprintf.c:195
#5 0x0000000000a9604d in my_vsnprintf_ex (cs=0x12b38a0, to=0x7fff01b2426a "\340Y6", n=<value optimized out>, fmt=0x2009873 "s'", ap=0x7fff01b24420) at /u01/project/mysql-5.6.11/strings/my_vsnprintf.c:607
#6 0x00000000008842cf in my_error (nr=1236, MyFlags=0) at /u01/project/mysql-5.6.11/mysys/my_error.c:181
#7 0x00000000008493e9 in read_gtids_from_binlog (filename=<value optimized out>, all_gtids=0x2094240, prev_gtids=0x0, verify_checksum=false) at /u01/project/mysql-5.6.11/sql/binlog.cc:2536
#8 0x0000000000849768 in MYSQL_BIN_LOG::init_gtid_sets (this=0x12da640, all_gtids=0x2094240, lost_gtids=0x20942c0, verify_checksum=false, need_lock=true) at /u01/project/mysql-5.6.11/sql/binlog.cc:2776
#9 0x00000000005e2e30 in mysqld_main (argc=84, argv=0x1f8ed98) at /u01/project/mysql-5.6.11/sql/mysqld.cc:5419
#10 0x0000003659a1ec9d in __libc_start_main () from /lib64/libc.so.6
#11 0x00000000005d8099 in _start ()
(gdb) f 4
#4 0x0000000000a95274 in process_str_arg (cs=0x12b38a0, to=0x7fff01b2426a "\340Y6", end=0x7fff01b2441f "", width=<value optimized out>, par=0xa8 <Address 0xa8 out of bounds>, print_type=0)
at /u01/project/mysql-5.6.11/strings/my_vsnprintf.c:195
195 plen= strnlen(par, width);
(gdb) p width
$7 = <value optimized out>
(gdb) p par
$8 = 0xa8 <Address 0xa8 out of bounds>
(gdb)
And It is strange that the binlog file that passed to read_gtids_from_binlog didn't have a PREVIOUS_GTIDS_LOG_EVENT
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130516 9:11:51 server id 336783306 end_log_pos 120 CRC32 0x942ff883 Start: binlog v 4, server v 5.6.11-log created 130516 9:11:51
BINLOG '
VzKUUQ/K5xIUdAAAAHgAAAAAAAQANS42LjExLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAYP4
L5Q=
'/*!*/;
# at 120
#130516 9:11:52 server id 336783306 end_log_pos 168 CRC32 0x0e66439c GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '8805e9c0-a0db-11e2-9673-ac162d7b9048:121135188'/*!*/;
# at 168
#130516 9:11:52 server id 336783306 end_log_pos 240 CRC32 0x94b6c8ba Query thread_id=590523 exec_time=0 error_code=0
SET TIMESTAMP=1368666712/*!*/;
SET @@session.pseudo_thread_id=590523/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=29360128/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C gbk *//*!*/;
SET @@session.character_set_client=28,@@session.collation_connection=28,@@session.collation_server=28/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 240
#130516 9:11:52 server id 336783306 end_log_pos 293 CRC32 0x8daf0e19 Table_map: `test`.`heartbeat` mapped to number 2192
# at 293
#130516 9:11:52 server id 336783306 end_log_pos 343 CRC32 0xff0e0143 Update_rows: table id 2192 flags: STMT_END_F
……
How to repeat:
I don't know
Suggested fix:
I am still debugging....
Description: This server has been running for a while with git-mode enabled. Then I shutdown the server , set git-mode to OFF and restart the server. I got an endless crash.... the backtrace: #0 0x0000003659e0c6bc in pthread_kill () from /lib64/libpthread.so.0 #1 0x000000000067eca2 in handle_fatal_signal (sig=11) at /u01/project/mysql-5.6.11/sql/signal_handler.cc:248 #2 <signal handler called> #3 0x0000003659a80121 in strnlen () from /lib64/libc.so.6 #4 0x0000000000a95274 in process_str_arg (cs=0x12b38a0, to=0x7fff01b2426a "\340Y6", end=0x7fff01b2441f "", width=<value optimized out>, par=0xa8 <Address 0xa8 out of bounds>, print_type=0) at /u01/project/mysql-5.6.11/strings/my_vsnprintf.c:195 #5 0x0000000000a9604d in my_vsnprintf_ex (cs=0x12b38a0, to=0x7fff01b2426a "\340Y6", n=<value optimized out>, fmt=0x2009873 "s'", ap=0x7fff01b24420) at /u01/project/mysql-5.6.11/strings/my_vsnprintf.c:607 #6 0x00000000008842cf in my_error (nr=1236, MyFlags=0) at /u01/project/mysql-5.6.11/mysys/my_error.c:181 #7 0x00000000008493e9 in read_gtids_from_binlog (filename=<value optimized out>, all_gtids=0x2094240, prev_gtids=0x0, verify_checksum=false) at /u01/project/mysql-5.6.11/sql/binlog.cc:2536 #8 0x0000000000849768 in MYSQL_BIN_LOG::init_gtid_sets (this=0x12da640, all_gtids=0x2094240, lost_gtids=0x20942c0, verify_checksum=false, need_lock=true) at /u01/project/mysql-5.6.11/sql/binlog.cc:2776 #9 0x00000000005e2e30 in mysqld_main (argc=84, argv=0x1f8ed98) at /u01/project/mysql-5.6.11/sql/mysqld.cc:5419 #10 0x0000003659a1ec9d in __libc_start_main () from /lib64/libc.so.6 #11 0x00000000005d8099 in _start () (gdb) f 4 #4 0x0000000000a95274 in process_str_arg (cs=0x12b38a0, to=0x7fff01b2426a "\340Y6", end=0x7fff01b2441f "", width=<value optimized out>, par=0xa8 <Address 0xa8 out of bounds>, print_type=0) at /u01/project/mysql-5.6.11/strings/my_vsnprintf.c:195 195 plen= strnlen(par, width); (gdb) p width $7 = <value optimized out> (gdb) p par $8 = 0xa8 <Address 0xa8 out of bounds> (gdb) And It is strange that the binlog file that passed to read_gtids_from_binlog didn't have a PREVIOUS_GTIDS_LOG_EVENT /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #130516 9:11:51 server id 336783306 end_log_pos 120 CRC32 0x942ff883 Start: binlog v 4, server v 5.6.11-log created 130516 9:11:51 BINLOG ' VzKUUQ/K5xIUdAAAAHgAAAAAAAQANS42LjExLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAYP4 L5Q= '/*!*/; # at 120 #130516 9:11:52 server id 336783306 end_log_pos 168 CRC32 0x0e66439c GTID [commit=yes] SET @@SESSION.GTID_NEXT= '8805e9c0-a0db-11e2-9673-ac162d7b9048:121135188'/*!*/; # at 168 #130516 9:11:52 server id 336783306 end_log_pos 240 CRC32 0x94b6c8ba Query thread_id=590523 exec_time=0 error_code=0 SET TIMESTAMP=1368666712/*!*/; SET @@session.pseudo_thread_id=590523/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=29360128/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C gbk *//*!*/; SET @@session.character_set_client=28,@@session.collation_connection=28,@@session.collation_server=28/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; BEGIN /*!*/; # at 240 #130516 9:11:52 server id 336783306 end_log_pos 293 CRC32 0x8daf0e19 Table_map: `test`.`heartbeat` mapped to number 2192 # at 293 #130516 9:11:52 server id 336783306 end_log_pos 343 CRC32 0xff0e0143 Update_rows: table id 2192 flags: STMT_END_F …… How to repeat: I don't know Suggested fix: I am still debugging....