Bug #72878 Buffer overflow in Slave_reporting_capability::va_report Edit
Submitted: 4 Jun 2014 15:33 Modified: 3 Jul 2014 5:16
Reporter: Sergei Glushchenko Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:5.6.14 OS:Any
Assigned to: CPU Architecture:Any
Tags: crash

[4 Jun 2014 15:33] Sergei Glushchenko
Description:
Hello,

Lines

  curr_buff= pbuff;
  if (prefix_msg)
    curr_buff += sprintf(curr_buff, "%s; ", prefix_msg);
  my_vsnprintf(curr_buff, pbuffsize, msg, args);

in Slave_reporting_capability::va_report, rpl_reporting.cc are not safe.

pbuffsize here is the size of buffer pointed by pbuff. curr_buff can have less space in case of prefix_msg is not null.

Example crash:

(gdb) bt
#0 __pthread_kill (threadid=<optimized out>, signo=<optimized out>)
    at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
#1 0x0000000000671eee in handle_fatal_signal (sig=11)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/signal_handler.cc:254
#2 <signal handler called>
#3 __strnlen_sse2 () at ../sysdeps/x86_64/multiarch/../strnlen.S:35
#4 0x0000000000b615ff in process_str_arg (print_type=0, par=<optimized out>, width=18446744073709551615,
    end=<optimized out>, to=0x7f3d6e3088f6 "", cs=0x1247fe0)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/strings/my_vsnprintf.c:195
#5 my_vsnprintf_ex (cs=0x1247fe0, to=<optimized out>, n=<optimized out>, fmt=<optimized out>, ap=0x7f3d6e308da8)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/strings/my_vsnprintf.c:607
#6 0x0000000000661c00 in vprint_msg_to_log (level=ERROR_LEVEL, format=<optimized out>, args=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/log.cc:2457
#7 0x0000000000661da1 in Log_to_file_event_handler::log_error (this=<optimized out>, level=<optimized out>,
    format=<optimized out>, args=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/log.cc:776
#8 0x000000000065d13b in LOGGER::error_log_print (this=<optimized out>, level=ERROR_LEVEL,
    format=0xbefb45 "Slave %s: %s%s Error_code: %d", args=0x7f3d6e308da8)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/log.cc:890
#9 0x000000000065e028 in error_log_print (level=<optimized out>, format=<optimized out>, args=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/log.cc:2192
#10 0x000000000065e200 in sql_print_error (format=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/log.cc:2475
#11 0x00000000008a076c in Slave_reporting_capability::va_report (this=0x516c69d0, level=<optimized out>,
    err_code=1452,
    prefix_msg=0x7f3d6e3093c0 "Worker 0 failed executing transaction '' at master log mysql-bin.001642, end_log_pos 1068877553", msg=0xbe7aa0 "Error '%s' on query. Default database: '%s'. Query: '%s'", args=0x7f3d6e309858)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/rpl_reporting.cc:174
#12 0x00000000008a84ac in Slave_worker::do_report (this=0x7f3bbf587780, level=ERROR_LEVEL, err_code=1452,
    msg=0xbe7aa0 "Error '%s' on query. Default database: '%s'. Query: '%s'", args=0x7f3d6e309858)
    at /mnt/workspace/percona-server-5.6-debs/label_exp/ubuntu-precise-64bit/target/Percona-Server-5.6.14-rel62.0/sql/rpl_rli_pdb.cc:1499

...

How to repeat:
it is obvious from source code

Suggested fix:
my_vsnprintf(curr_buff, pbuffsize - curr_buff, msg, args);

probably
[3 Jul 2014 5:16] Erlend Dahl
[26 Jun 2014 3:35] Jon Stephens

Documented fix as follows in the 5.6.20 and 5.7.5 changelogs:

    When a slave worker thread tried to execute a statement was too
    large, the resulting error caused a crash. Now in such cases,
    the error is truncated to fit the size of the buffer.

Closed.
[6 Aug 2014 17:21] Laurynas Biveinis
$ bzr log -n0 -r 5934
------------------------------------------------------------
revno: 5934
committer: Andrei Elkin <andrei.elkin@oracle.com>
branch nick: 5.6-fixes
timestamp: Tue 2014-05-13 12:09:33 +0300
message:
  Bug#18563480 CRASH WHEN SLAVE WORKER TRY TO EXECUTE A BIG STATEMENT THAT SHOULD FAIL
  
  The failure was caused by exceeding of capacity of the internal buffer
  by ultimate error reporting message text.
  
  It is fixed by submitting the error text to the size of the
  buffer. Any excess is simply cut off.
[6 Aug 2014 17:23] Laurynas Biveinis
$ bzr log -n0 -r 5934
------------------------------------------------------------
revno: 5934
committer: Andrei Elkin <andrei.elkin@oracle.com>
branch nick: 5.6-fixes
timestamp: Tue 2014-05-13 12:09:33 +0300
message:
  Bug#18563480 CRASH WHEN SLAVE WORKER TRY TO EXECUTE A BIG STATEMENT THAT SHOULD FAIL
  
  The failure was caused by exceeding of capacity of the internal buffer
  by ultimate error reporting message text.
  
  It is fixed by submitting the error text to the size of the
  buffer. Any excess is simply cut off.
[6 Aug 2014 17:23] Laurynas Biveinis
$ bzr log -n0 -r 5935
------------------------------------------------------------
revno: 5935
committer: Andrei Elkin <andrei.elkin@oracle.com>
branch nick: 5.6-fixes
timestamp: Tue 2014-05-13 14:35:58 +0300
message:
  bug18563480 post-push: compile on win is fixed.