Bug #94319 Format_description_log_event::write can cause segfaults
Submitted: 14 Feb 2019 2:29 Modified: 25 Jun 2019 15:59
Reporter: Manuel Ung Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:8.0.15 OS:Any
Assigned to: CPU Architecture:Any

[14 Feb 2019 2:29] Manuel Ung
Description:
In this function:

Format_description_log_event::write

We have this:

```
  memcpy((char *)buff + ST_COMMON_HEADER_LEN_OFFSET + 1, &post_header_len[0],
         Binary_log_event::LOG_EVENT_TYPES);
```

This works fine, if the server generating the FDE is the same as the server writing it out (hence post_header_len.size == Binary_log_event::LOG_EVENT_TYPES).

However, when we rotate relay logs, we use this function to write out the FDE by using the event obtained from the master directly. If the master is on an older version of MySQL with not as many event types, then this memcpy will read beyond its buffer.

The call to rotate relay logs is as follows (and you can see the FDE event being passed in via extra_description_event):

#0  Format_description_log_event::write (this=0x7f773562c420, ostream=0x7f773bca70c0) at ../../sql/log_event.cc:5152
#1  0x0000000001a39f8e in binary_event_serialize<Format_description_log_event> (ostream=<optimized out>, ev=0x7f773562c420) at ../../sql/log_event.h:4186
#2  MYSQL_BIN_LOG::open_binlog (this=this@entry=0x7f773bc45808, log_name=log_name@entry=0x7f77356ccea0 "/binlogs/mysqld-relay-bin-3306", new_name=new_name@entry=0x7f7bf7e86d60 "/binlogs/mysqld-relay-bin-3306.012129", max_size_arg=<optimized out>,
    null_created_arg=null_created_arg@entry=true, need_lock_index=need_lock_index@entry=false, need_sid_lock=true, extra_description_event=0x7f773562c420, new_index_number=0) at ../../sql/binlog.cc:4800
#3  0x0000000001a3b52a in MYSQL_BIN_LOG::new_file_impl (this=this@entry=0x7f773bc45808, need_lock_log=need_lock_log@entry=false, extra_description_event=0x7f773562c420) at ../../sql/binlog.cc:6370
#4  0x0000000001a3b63a in MYSQL_BIN_LOG::new_file_without_locking (this=this@entry=0x7f773bc45808, extra_description_event=<optimized out>) at ../../sql/binlog.cc:6211
#5  0x0000000001a3b803 in MYSQL_BIN_LOG::after_write_to_relay_log (this=this@entry=0x7f773bc45808, mi=mi@entry=0x7f773bc86800) at ../../sql/binlog.cc:6505
#6  0x0000000001a3bb09 in MYSQL_BIN_LOG::write_buffer (this=this@entry=0x7f773bc45808, buf=buf@entry=0x7f7728700021 "\241\317d\\\020\212\215)\003\037", len=len@entry=31, mi=mi@entry=0x7f773bc86800) at ../../sql/binlog.cc:6559
#7  0x0000000001a70c6c in queue_event (mi=mi@entry=0x7f773bc86800, buf=<optimized out>, event_len=31, do_flush_mi=do_flush_mi@entry=true) at ../../sql/rpl_slave.cc:7600
#8  0x0000000001a72ae1 in handle_slave_io (arg=arg@entry=0x7f773bc86800) at ../../sql/rpl_slave.cc:5358
#9  0x000000000226725f in pfs_spawn_thread (arg=0x7f773bd41b20) at ../../../storage/perfschema/pfs.cc:2836
#10 0x00007f7bf77ba7c9 in start_thread () from /usr/local/fbcode/gcc-5-glibc-2.23/lib/libpthread.so.0
#11 0x00007f7bf6137bad in clone () from /usr/local/fbcode/gcc-5-glibc-2.23/lib/libc.so.6

How to repeat:
There's no easy mtr test for this, since you need to replicate using an 5.6/5.7 master and an 8.0 slave.

If you use this setup with ASAN, you'll be able to hit this failure fairly quickly during relay log rotation.

Suggested fix:
Just memcpy the size of post_header_len:
  memcpy((char *)buff + ST_COMMON_HEADER_LEN_OFFSET + 1, &post_header_len[0],
         post_header_len.size());

If we have the master on a new version, and slaves being on an older version, it's possible that the buffer 'buff' is not big enough for post_header_len.size(), so a dynamic buffer might be needed.
[15 Feb 2019 9:32] MySQL Verification Team
Hello Manuel Ung,

Thank you for the report.

Thanks,
Umesh
[25 Jun 2019 8:16] Luis Soares
See: BUG#94500 .
[25 Jun 2019 16:01] Luis Soares
Same issue as in BUG#94500.