Bug #41943 mysqlbinlog.exe crashes if --hexdump option is used

Description:
mysqlbinlog.exe crashes if --hexdump option is used.

How to repeat:
Command:
mysqlbinlog.exe --host=localhost --port=5072 --user=root --read-from-remote-server --hexdump "mysql-bin.000001" -p

Command Output:

- 5.0.72 Enterprise ("Unzip in C" package)

D:\MySQL\mysql-enterprise-gpl-5.0.72-win32\bin>mysqlbinlog.exe --host=localhost --port=5072 --user=root --read-from-remote-server "mysql-bin.000001" -p

# ok, I get the output

D:\MySQL\mysql-enterprise-gpl-5.0.72-win32\bin>mysqlbinlog.exe --host=localhost --port=5072 --user=root --read-from-remote-server --hexdump "mysql-bin.000001" -p

# program crashes

- 5.1.30 ("Unzip in C" package)

D:\MySQL\mysql-5.1.30-win32\bin>mysqlbinlog.exe --host=localhost --port=51301 --user=root --read-from-remote-server --hexdump "mysql-bin.000006" -p

# all works fine

Workaround:
Copy mysqlbinlog.exe from 5.1 and past it in the bin directory of 5.0.72 (do a backup copy of the old executable first).

Thank you for a problem report. I can not repeat this with 5.0.74 on XP SP3. Can you try that newer version? Can you upload the problematic binary log, or this happens with any one for you?

Valeriy,

I verified this with version 5.0.74 too.
Attached please find a screenshot.

I can't see any correlation with the used binlog. I tested this also with the first binlog the server creates at first startup.
Attached please find the file I've used.

Are you sure you used the --hexdump option?

screenshot related to #41943

Attachment: binlog.jpg (image/jpeg, text), 220.43 KiB.

binlog file related to #41943

Attachment: mysql-bin.000001 (application/octet-stream, text), 98 bytes.

I tried 5.0.76 built from source and I couldn't repeat too.

I've asked to a colleague of mine to check this, and he answered he got the same crash on his XP machine too.

I'll try to test this on a fresh virtual machine if I can, and get back to you as soon as possible. 

Thanks.

I repeat this easily on 5.0.74-winx64:

mysqlbinlog.exe!Log_event::print_header  Line 992
mysqlbinlog.exe!Start_log_event_v3::print  Line 2232
mysqlbinlog.exe!process_event
mysqlbinlog.exe!dump_remote_log_entries
mysqlbinlog.exe!dump_log_entries
mysqlbinlog.exe!main

So I'd suggest using valgrind or debug build to see a problem easier.

valgrind errors in 5.1.30:

Conditional jump or move depends on uninitialised value(s)
: Query_log_event::print_query_header(st_io_cache*, st_print_event_info*) (log_event.cc:2750)
: Query_log_event::print(_IO_FILE*, st_print_event_info*) (log_event.cc:2827)
: process_event(st_print_event_info*, Log_event*, unsigned long long, char const*) (mysqlbinlog.cc:904)
: _ZL16dump_log_entriesPKc (mysqlbinlog.cc:1590)
: main (mysqlbinlog.cc:2003)
Discarding syms at 0x400A000-0x4015000 in /lib/libnss_files-2.5.so due to munmap()

ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 20 from 1)

1 errors in context 1 of 1:
Conditional jump or move depends on uninitialised value(s)
: Query_log_event::print_query_header(st_io_cache*, st_print_event_info*) (log_event.cc:2750)
: Query_log_event::print(_IO_FILE*, st_print_event_info*) (log_event.cc:2827)
: process_event(st_print_event_info*, Log_event*, unsigned long long, char const*) (mysqlbinlog.cc:904)
: _ZL16dump_log_entriesPKc (mysqlbinlog.cc:1590)
: main (mysqlbinlog.cc:2003)

valgrind errors from 5.0.74:

Invalid read of size 4
 Log_event::print_header(_IO_FILE*, st_print_event_info*) (log_event.cc:988)
 Start_log_event_v3::print(_IO_FILE*, st_print_event_info*) (log_event.cc:2230)
 process_event(st_print_event_info*, Log_event*, unsigned long long) (mysqlbinlog.cc:628)
 _ZL16dump_log_entriesPKc (mysqlbinlog.cc:1211)
 main (mysqlbinlog.cc:1534)
 Address 0x9 is not stack'd, malloc'd or (recently) free'd
=

Got the crash now:

>	mysqlbinlog.exe!Log_event::print_header(_iobuf * file=0x0064d2d8, st_print_event_info * print_event_info=0x0012fba8)  Line 988 + 0x3	C++
 	mysqlbinlog.exe!Start_log_event_v3::print(_iobuf * file=0x0064d2d8, st_print_event_info * print_event_info=0x0012fba8)  Line 2232	C++
 	mysqlbinlog.exe!process_event(st_print_event_info * print_event_info=0x0012fba8, Log_event * ev=0x00b793e8, unsigned __int64 pos=0x0000000000000004)  Line 628 + 0x16	C++
 	mysqlbinlog.exe!dump_remote_log_entries(st_print_event_info * print_event_info=0x0012fba8, const char * logname=0x00373309)  Line 1211 + 0x1e	C++
 	mysqlbinlog.exe!dump_log_entries(const char * logname=0x00373309)  Line 997 + 0x1b	C++
 	mysqlbinlog.exe!main(int argc=0x00000000, char * * argv=0x00372628)  Line 1534 + 0x1a	C++
 	mysqlbinlog.exe!mainCRTStartup()  Line 259 + 0x19	C
 	kernel32.dll!7c817067()

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/73578

2734 Alexey Kopytov	2009-05-07
      Bug #41943: mysqlbinlog.exe crashes if --hexdump option is used  
        
      The --hexdump option crashed mysqlbinlog when used together  
      with the --read-from-remote-server option due to use of  
      uninitialized memory.  
        
      Since Log_event::print_header() relies on temp_buf to be  
      initialized when the --hexdump option is present,  
      dump_remote_log_entries() was fixed to setup temp_buf to point  
      to the start of a binlog event as done in  
      dump_local_log_entries().  
       
      The root cause of this bug is identical to the one for 
      bug #17654. The latter was fixed in 5.1 and up, so this 
      patch is backport of the patches for bug #17654 to 5.0. 
       
      Only 5.0 needs a changelog entry. 
      modified:
        client/mysqlbinlog.cc
        mysql-test/r/mysqlbinlog.result
        mysql-test/t/mysqlbinlog.test

Pushed into 5.0.83 (revid:joro@sun.com-20090528073529-q9b8s60vlpu28fny) (version source revid:jimw@mysql.com-20090512212033-5f2l893u3rhrsw53) (merge vers: 5.0.82) (pib:6)

Pushed into 5.1.36 (revid:joro@sun.com-20090528073639-yohsb4q1jzg7ycws) (version source revid:mats@sun.com-20090511132802-nnkiyb2huih1tklz) (merge vers: 5.1.35) (pib:6)

Noted in 5.0.83, 5.1.36 changelogs.

Using --hexdump together with --read-from-remote-server caused
mysqlbinlog to crash. 

Setting report to NDI pending push into 6.0.x.

Correction: This bug was fixed previously in 5.1 and 6.0 so the changelog entry is only in 5.0.83.

Pushed into 5.4.4-alpha (revid:alik@sun.com-20090616183122-chjzbaa30qopdra9) (version source revid:alexey.kopytov@sun.com-20090508175345-5yq0ntwtz7d99d1i) (merge vers: 6.0.12-alpha) (pib:11)

Pushed into 5.1.37-ndb-7.0.8 (revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (version source revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)

Pushed into 5.1.37-ndb-6.3.27 (revid:jonas@mysql.com-20090826105955-bkj027t47gfbamnc) (version source revid:jonas@mysql.com-20090826105955-bkj027t47gfbamnc) (merge vers: 5.1.37-ndb-6.3.27) (pib:11)

Pushed into 5.1.37-ndb-6.2.19 (revid:jonas@mysql.com-20090825194404-37rtosk049t9koc4) (version source revid:jonas@mysql.com-20090825194404-37rtosk049t9koc4) (merge vers: 5.1.37-ndb-6.2.19) (pib:11)

Pushed into 5.1.35-ndb-7.1.0 (revid:magnus.blaudd@sun.com-20090827163030-6o3kk6r2oua159hr) (version source revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)