Bug #80138 sprintf undefined behaviour in MYSQL_BIN_LOG::handle_binlog_flush_or_sync_error

• Submitted: 25 Jan 2016 11:30
• Modified: 27 Jan 2016 6:53
• Reporter: Vlad Lesin
• Status: Duplicate
• Category: MySQL Server: Replication
• Severity: S3 (Non-critical)
• Version: 5.6.28
• OS: Any
• CPU Architecture: Any

[25 Jan 2016 11:30] Vlad Lesin

Description:
MYSQL_BIN_LOG::handle_binlog_flush_or_sync_error contains the following code:

void MYSQL_BIN_LOG::handle_binlog_flush_or_sync_error(THD *thd,
                                                      bool need_lock_log)
{
  char errmsg[MYSQL_ERRMSG_SIZE];
  sprintf(errmsg, "An error occurred during %s stage of the commit. "
          "'binlog_error_action' is set to '%s'.",
          thd->commit_error== THD::CE_FLUSH_ERROR ? "flush" : "sync",
          binlog_error_action == ABORT_SERVER ? "ABORT_SERVER" : "IGNORE_ERROR");
  if (binlog_error_action == ABORT_SERVER)
  {
    sprintf(errmsg, "%s Hence aborting the server.", errmsg);
    exec_binlog_error_action_abort(errmsg);
  }
...
}

sprintf manual page contains the following description:

"C99 and POSIX.1-2001 specify that the results are undefined if a call to sprintf(), snprintf(), vsprintf(), or vsnprintf()  would  cause
copying  to  take  place between objects that overlap (e.g., if the target string array and one of the supplied input arguments refer to
the same buffer).  See NOTES."

So this string:

sprintf(errmsg, "%s Hence aborting the server.", errmsg);

leads to undefined behaviour.

See also https://bugs.launchpad.net/percona-server/+bug/1537710 .

How to repeat:
binlog_error_action mtr test fails from time to time because of this error.

Suggested fix:
1) I would not use sprintf() at all as it is potentially dangerous, I would use snprintf() instead.
2) I would add one more buffer to form error message.

Here is my fix for that chunk of code:

void MYSQL_BIN_LOG::handle_binlog_flush_or_sync_error(THD *thd,
                                                      bool need_lock_log)
{
  char errmsg[MYSQL_ERRMSG_SIZE];
  snprintf(errmsg, sizeof(errmsg), "An error occurred during %s stage of the commit. "
          "'binlog_error_action' is set to '%s'.",
          thd->commit_error== THD::CE_FLUSH_ERROR ? "flush" : "sync",
          binlog_error_action == ABORT_SERVER ? "ABORT_SERVER" : "IGNORE_ERROR");
  if (binlog_error_action == ABORT_SERVER)
  {
    char errmsg_for_abort[MYSQL_ERRMSG_SIZE];
    snprintf(errmsg_for_abort, sizeof(errmsg_for_abort), "%s Hence aborting the server.", errmsg);
    exec_binlog_error_action_abort(errmsg_for_abort);
  }
...
}

[27 Jan 2016 6:47] MySQL Verification Team

Hello Vlad,

Thank you for the report.

Thanks,
Umesh

[27 Jan 2016 6:52] MySQL Verification Team

## Per internal discussion with dev's, this is fixed and handled as part of Bug#21276561/Bug#77393

// 5.6.29

6963 void MYSQL_BIN_LOG::handle_binlog_flush_or_sync_error(THD *thd,
6964                                                       bool need_lock_log)
6965 {
6966   char errmsg[MYSQL_ERRMSG_SIZE];
6967   sprintf(errmsg, "An error occurred during %s stage of the commit. "
6968           "'binlog_error_action' is set to '%s'.",
6969           thd->commit_error== THD::CE_FLUSH_ERROR ? "flush" : "sync",
6970           binlog_error_action == ABORT_SERVER ? "ABORT_SERVER" : "IGNORE_ERROR");
6971   if (binlog_error_action == ABORT_SERVER)
6972   {
6973     char err_buff[MYSQL_ERRMSG_SIZE];
6974     sprintf(err_buff, "%s Hence aborting the server.", errmsg);
6975     exec_binlog_error_action_abort(err_buff);
6976   }

[27 Jan 2016 6:53] MySQL Verification Team

marking as duplicate of Bug #77393