[MDEV-20582] Asan failure in table_def::calc_field_size Created: 2019-09-13  Updated: 2019-10-08  Resolved: 2019-10-08

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.3, 10.4
Fix Version/s: 10.3.19, 10.4.9, 10.5.0

Type: Bug Priority: Minor
Reporter: Sachin Setiya (Inactive) Assignee: Sachin Setiya (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Environment:

Asan debug build


Issue Links:
Problem/Incident
is caused by MDEV-20591 Wrong Number of rows in mysqlbinlog o... Closed

 Description   

Following test fails with ASAN build

--source include/have_binlog_format_row.inc
 
--let $MYSQLD_DATADIR= `select @@datadir`
--let $binlog_file= $MYSQLD_DATADIR/master-bin.000001
--let $output_file= $MYSQLTEST_VARDIR/tmp/mysqlbinlog.output
 
CREATE TABLE t1(c_char_utf8 CHAR(1) ,
  c_varchar_utf8 VARCHAR(1) ,
  c_text_utf8 TEXT );
 
INSERT INTO t1 VALUES("1", "2", "3");
 
--exec $MYSQL_BINLOG -F $binlog_file > $output_file

binlog.xyz 'row'                         [ fail ]
        Test ended at 2019-09-13 13:54:54
 
CURRENT_TEST: binlog.xyz
=================================================================
==9067==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x6020000049e0 at pc 0x55850271a846 bp 0x7ffcaa1efd80 sp 0x7ffcaa1efd70
READ of size 2 at 0x6020000049e0 thread T0
    #0 0x55850271a845 in table_def::calc_field_size(unsigned int, unsigned char*) const /home/sachin/10.3/server/sql/rpl_utility.cc:330
    #1 0x5585026f3c33 in Rows_log_event::calc_row_event_length(table_def*, st_print_event_info*, st_bitmap*, unsigned char const*) /home/sachin/10.3/server/sql/log_event.cc:3472
    #2 0x5585026f3f04 in Rows_log_event::count_row_events(st_print_event_info*) /home/sachin/10.3/server/sql/log_event.cc:3529
    #3 0x5585026f56c0 in Log_event::print_base64(st_io_cache*, st_print_event_info*, bool) /home/sachin/10.3/server/sql/log_event.cc:3905
    #4 0x558502712620 in Rows_log_event::print_helper(_IO_FILE*, st_print_event_info*, char const*) /home/sachin/10.3/server/sql/log_event.cc:12156
    #5 0x5585027159fc in Write_rows_log_event::print(_IO_FILE*, st_print_event_info*) /home/sachin/10.3/server/sql/log_event.cc:13691
    #6 0x5585026bb676 in print_base64 /home/sachin/10.3/server/client/mysqlbinlog.cc:899
    #7 0x5585026bb986 in print_row_event /home/sachin/10.3/server/client/mysqlbinlog.cc:983
    #8 0x5585026bd2d5 in process_event(st_print_event_info*, Log_event*, unsigned long long, char const*) /home/sachin/10.3/server/client/mysqlbinlog.cc:1474
    #9 0x5585026c3839 in dump_local_log_entries /home/sachin/10.3/server/client/mysqlbinlog.cc:2990
    #10 0x5585026bf931 in dump_log_entries /home/sachin/10.3/server/client/mysqlbinlog.cc:2217
    #11 0x5585026c40b0 in main /home/sachin/10.3/server/client/mysqlbinlog.cc:3150
    #12 0x7f38147ccb6a in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x26b6a)
    #13 0x5585026b8059 in _start (/home/sachin/10.3/build/client/mysqlbinlog+0xb3059)
 
0x6020000049e0 is located 0 bytes to the right of 16-byte region [0x6020000049d0,0x6020000049e0)
allocated by thread T0 here:
    #0 0x7f3814fcf448 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10c448)
    #1 0x5585028067fd in my_malloc /home/sachin/10.3/server/mysys/my_malloc.c:101
    #2 0x558502710a05 in Rows_log_event::Rows_log_event(char const*, unsigned int, Format_description_log_event const*) /home/sachin/10.3/server/sql/log_event.cc:10991
    #3 0x55850271588b in Write_rows_log_event::Write_rows_log_event(char const*, unsigned int, Format_description_log_event const*) /home/sachin/10.3/server/sql/log_event.cc:13145
    #4 0x5585026f5421 in Log_event::print_base64(st_io_cache*, st_print_event_info*, bool) /home/sachin/10.3/server/sql/log_event.cc:3817
    #5 0x558502712620 in Rows_log_event::print_helper(_IO_FILE*, st_print_event_info*, char const*) /home/sachin/10.3/server/sql/log_event.cc:12156
    #6 0x5585027159fc in Write_rows_log_event::print(_IO_FILE*, st_print_event_info*) /home/sachin/10.3/server/sql/log_event.cc:13691
    #7 0x5585026bb676 in print_base64 /home/sachin/10.3/server/client/mysqlbinlog.cc:899
    #8 0x5585026bb986 in print_row_event /home/sachin/10.3/server/client/mysqlbinlog.cc:983
    #9 0x5585026bd2d5 in process_event(st_print_event_info*, Log_event*, unsigned long long, char const*) /home/sachin/10.3/server/client/mysqlbinlog.cc:1474
    #10 0x5585026c3839 in dump_local_log_entries /home/sachin/10.3/server/client/mysqlbinlog.cc:2990
    #11 0x5585026bf931 in dump_log_entries /home/sachin/10.3/server/client/mysqlbinlog.cc:2217
    #12 0x5585026c40b0 in main /home/sachin/10.3/server/client/mysqlbinlog.cc:3150
    #13 0x7f38147ccb6a in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x26b6a)
 
SUMMARY: AddressSanitizer: heap-buffer-overflow /home/sachin/10.3/server/sql/rpl_utility.cc:330 in table_def::calc_field_size(unsigned int, unsigned char*) const
Shadow bytes around the buggy address:
  0x0c047fff88e0: fa fa fd fd fa fa fd fd fa fa fd fd fa fa fd fd
  0x0c047fff88f0: fa fa fd fd fa fa fd fd fa fa fd fd fa fa fd fd
  0x0c047fff8900: fa fa 00 00 fa fa 00 00 fa fa fd fd fa fa fd fd
  0x0c047fff8910: fa fa fd fd fa fa fd fd fa fa fd fd fa fa fd fd
  0x0c047fff8920: fa fa fd fd fa fa fd fd fa fa fd fd fa fa fd fd
=>0x0c047fff8930: fa fa 00 00 fa fa 00 07 fa fa 00 00[fa]fa fa fa
  0x0c047fff8940: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff8950: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff8960: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff8970: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff8980: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==9067==ABORTING
mysqltest: At line 13: exec of '/home/sachin/10.3/build/client/mysqlbinlog --defaults-file=/home/sachin/10.3/build/mysql-test/var/my.cnf --local-load=/home/sachin/10.3/build/mysql-test/var/tmp -F /home/sachin/10.3/build/mysql-test/var/mysqld.1/data//master-bin.000001 > /home/sachin/10.3/build/mysql-test/var/tmp/mysqlbinlog.output' failed, error: 256, status: 1, errno: 11
Output from before failure:
INSERT INTO t1 VALUES("1", "2", "3");
 
 - saving '/home/sachin/10.3/build/mysql-test/var/log/binlog.xyz-row/' to '/home/sachin/10.3/build/mysql-test/var/log/binlog.xyz-row/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 4 seconds executing testcases
 
Failure: Failed 1/1 tests, 0.00% were successful.
 
Failing test(s): binlog.xyz
 
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
 

Please uncomment the part on test case in binlog_table_map_optional_metadata.test which was commented because of this bug



 Comments   
Comment by Sachin Setiya (Inactive) [ 2019-09-13 ]

This fails

INSERT INTO t1 VALUES("1", "1", "1");

This passes

INSERT INTO t1 VALUES("1", "1", "i1");

So if length > 1 for any column then it will pass

Comment by Sachin Setiya (Inactive) [ 2019-10-08 ]

MDEV-20591 already fixes the issue , I only enabled the commented parts in test case

Generated at Thu Feb 08 09:00:35 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.