Bug #69087 the server was crashed while executing "show binlog events "
Submitted: 27 Apr 2013 8:51 Modified: 6 Nov 2013 15:08
Reporter: zhai weixiang (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.5.30 OS:Any
Assigned to: CPU Architecture:Any

[27 Apr 2013 8:51] zhai weixiang
Description:
mysql was crashed after executing "show binlog events in 'mysql-bin.000005' from 99"

the crash happened randomly (I am still confused about this  ). 

backtrace:

(gdb) bt
#0  0x0000003038e0c6bc in pthread_kill () from /lib64/libpthread.so.0
#1  0x000000000067e93e in handle_fatal_signal (sig=11) at /u01/project/mysql-5.5.30/sql/signal_handler.cc:247
#2  <signal handler called>
#3  0x00000038888800c2 in __strlen_sse2 () from /lib64/libc.so.6
#4  0x00000000006fa9a7 in Load_log_event::copy_log_event (this=0x7fec80c89e50, buf=Unhandled dwarf expression opcode 0xf3
) at /u01/project/mysql-5.5.30/sql/log_event.cc:4709
#5  0x00000000006fde1d in Log_event::read_log_event (buf=0x7fec80009df0 "\017\b\002\001\f\f.", <incomplete sequence \310>, event_len=Unhandled dwarf expression opcode 0xf3
) at /u01/project/mysql-5.5.30/sql/log_event.cc:1280
#6  0x00000000006fe420 in Log_event::read_log_event (file=0x7fec9c25e410, log_lock=0x0, description_event=0x7fec80009d10) at /u01/project/mysql-5.5.30/sql/log_event.cc:1187
#7  0x00000000005b9d58 in mysql_show_binlog_events (thd=0x34d4ab0) at /u01/project/mysql-5.5.30/sql/sql_repl.cc:1851
#8  0x00000000005a479d in mysql_execute_command (thd=0x34d4ab0) at /u01/project/mysql-5.5.30/sql/sql_parse.cc:2260
#9  0x00000000005a7a3d in mysql_parse (thd=0x34d4ab0, rawbuf=Unhandled dwarf expression opcode 0xf3
) at /u01/project/mysql-5.5.30/sql/sql_parse.cc:5627
#10 0x00000000005a896d in dispatch_command (command=<value optimized out>, thd=0x34d4ab0, packet=0x7fec80004b60 "show binlog events in 'mysql-bin.000005' from 99", packet_length=48)
    at /u01/project/mysql-5.5.30/sql/sql_parse.cc:1037
#11 0x000000000062932f in do_handle_one_connection (thd_arg=Unhandled dwarf expression opcode 0xf3
) at /u01/project/mysql-5.5.30/sql/sql_connect.cc:853
#12 0x00000000006293a0 in handle_one_connection (arg=0x34d4ab0) at /u01/project/mysql-5.5.30/sql/sql_connect.cc:772
#13 0x0000003038e077e1 in start_thread () from /lib64/libpthread.so.0
#14 0x00000038888e68ed in clone () from /lib64/libc.so.6

How to repeat:
I don't know , but I can repeat this crash using the special binlog file. It's a little big , I'll upload the binary file and core file  later.

Suggested fix:
It seems some invalid event was considered to be valid event
[27 Apr 2013 10:26] zhai weixiang
I've uploaded  the tarball in google doc 

https://docs.google.com/file/d/0B6eilAPVEY6HVEZzdTNwc1REX1E/edit
[29 Apr 2013 6:59] MySQL Verification Team
I can repeat this on 5.5.32, and even 5.7.1, but it's a known class of problem.  The position given "99" here, must be a correct and valid position.  Random numbers will likely cause problems.

Version: '5.5.32-debug-log'  MySQL Community Server (GPL)
06:53:17 UTC - mysqld got exception 0xc0000005 ;
mysqld.exe!strlen()[strlen.asm:58]
mysqld.exe!Load_log_event::copy_log_event()[log_event.cc:4715]
mysqld.exe!Load_log_event::Load_log_event()[log_event.cc:4670]
mysqld.exe!Log_event::read_log_event()[log_event.cc:1286]
mysqld.exe!Log_event::read_log_event()[log_event.cc:1193]
mysqld.exe!mysql_show_binlog_events()[sql_repl.cc:1837]
mysqld.exe!mysql_execute_command()[sql_parse.cc:2265]
mysqld.exe!mysql_parse()[sql_parse.cc:5632]
mysqld.exe!dispatch_command()[sql_parse.cc:1040]
mysqld.exe!do_command()[sql_parse.cc:773]
mysqld.exe!do_handle_one_connection()[sql_connect.cc:853]
mysqld.exe!handle_one_connection()[sql_connect.cc:773]
mysqld.exe!pthread_start()[my_winthread.c:62]
mysqld.exe!_callthreadstartex()[threadex.c:314]
mysqld.exe!_threadstartex()[threadex.c:297]
[29 Apr 2013 7:01] MySQL Verification Team
Related:

Bug 15830865 - INVALID MEMCPY OF SERVER_VERSION IN WRONG BINLOG POSITION/CORRUPTED LOG
Bug 15830825 - INVALID FREE OF POST_HEADER_LEN WHEN GIVEN WRONG BINLOG POSITION
Bug 15830022 - ASSERTION FAILED: M_FIELD_METADATA_SIZE <= (M_COLCNT * 2), FILE LOG_EVENT.CC,
Bug 15829582 - DO_SERVER_VERSION_SPLIT: ASSERTION FAILED: !((I == 0) && (*R != '.'))
Bug 15829568 - ASSERTION FAILED: VAR_HEADER_LEN >= 2
Bug 15829548 - DO_SERVER_VERSION_SPLIT: ASSERTION FAILED: NUMBER < 256
[6 Nov 2013 15:08] Jon Stephens
Documented fix in the 5.5.36 changelog as follows:

        Invalid event offsets in the binary log were not always handled
        correctly, which could lead to replication failure.
      
Closed.
[2 Feb 2014 17:22] Laurynas Biveinis
5.5$ bzr log -r 4539
------------------------------------------------------------
revno: 4539
committer: Sujatha Sivakumar <sujatha.sivakumar@oracle.com>
branch nick: Bug16736412_mysql-5.5
timestamp: Wed 2013-11-06 15:00:49 +0530
message:
  Bug#16736412: THE SERVER WAS CRASHED WHILE EXECUTING
  "SHOW BINLOG EVENTS"
  
  Problem:
  ========
  mysql was crashed after executing "show binlog events in
  'mysql-bin.000005' from 99", the crash happened randomly.
  
  Analysis:
  ========
  During construction of LOAD EVENT or NEW LOAD EVENT object
  if the starting offset is provided as incorrect value then
  all the object members that are retrieved from the offset
  are also invalid.  Some times it will lead to out of bound
  address offsets.  In the bug scenario, the file name is
  extracrated from an invalid address and the same is fed to
  strlen(fname) function. Passing invalid address to strlen
  will lead to crash.
  
  Fix:
  ===
  Validate if the given offset falls within the event boundary
  or not.
[2 Feb 2014 17:24] Laurynas Biveinis
5.5$ bzr log -r 4542
------------------------------------------------------------
revno: 4542
committer: Sujatha Sivakumar <sujatha.sivakumar@oracle.com>
branch nick: Bug16736412_mysql-5.5
timestamp: Thu 2013-11-07 17:30:57 +0530
message:
  Bug#16736412: THE SERVER WAS CRASHED WHILE EXECUTING
  "SHOW BINLOG EVENTS"
  
  Fixing post push test issue. 
  Changing the debug simulation.