MySQL Bugs: #42674: Random crash of mysqld when "Statement is not safe to log in statement format"

Bug #42674	Random crash of mysqld when "Statement is not safe to log in statement format"
Submitted:	7 Feb 2009 22:16	Modified:	8 Feb 2009 2:11
Reporter:	Mark Plomer	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: General	Severity:	S1 (Critical)
Version:	5.1.30	OS:	Linux (Debian 4.0)
Assigned to:		CPU Architecture:	Any
Tags:	binlog, crash, error handler, insecure statement

Description:
Hello,
I just upgraded to MySQL 5.1.30 binary distribution (mysql-5.1.30-linux-x86_64-glibc23) and now I'm experiencing random crashes of the mysqld.

If I look at the error log, I get a lot of warnings for statements that are "not safe to log in statement format", which is ok. But sometimes the server crashes while executing such a query (If I look at "thd->query" in the crash dump, it is a similar query like the others that triggers the warning).

And it keeps crashing ... about 5-6 times the last week.

By looking at the stacktrace I think it has something to do with the error handler that triggers errors when binlog is active and UPDATE/DELETE statements have a LIMIT clause.

Here is the stack trace ... it seems to crash inside sql_print_warning (or deeper) called from binlog_query:

/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2e)[0x895f2e]
/usr/local/mysql/bin/mysqld(handle_segfault+0x322)[0x5d1e82]
/lib/libpthread.so.0[0x2b56ab421410]
/lib/libc.so.6(memmove+0x90)[0x2b56aba6f730]
/usr/local/mysql/bin/mysqld(my_vsnprintf+0x39f)[0x8b7daf]
/usr/local/mysql/bin/mysqld(_Z17vprint_msg_to_log8loglevelPKcP13__va_list_tag+0x23)[0x6656b3]
/usr/local/mysql/bin/mysqld(_ZN25Log_to_file_event_handler9log_errorE8loglevelPKcP13__va_list_tag+0x11)[0x6657b1]
/usr/local/mysql/bin/mysqld(_Z17sql_print_warningPKcz+0xad)[0x66995d]
/usr/local/mysql/bin/mysqld(_ZN3THD12binlog_queryENS_22enum_binlog_query_typeEPKcmbbNS_12killed_stateE+0x1b3)[0x5c15c3]
/usr/local/mysql/bin/mysqld(_Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_ordery15enum_duplicatesb+0xbcf)[0x65d85f]
/usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THD+0xf9e)[0x5e2dbe]
/usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDPKcjPS2_+0x357)[0x5e7647]
/usr/local/mysql/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xcf3)[0x5e8343]
/usr/local/mysql/bin/mysqld(_Z10do_commandP3THD+0xe6)[0x5e8d56]
/usr/local/mysql/bin/mysqld(handle_one_connection+0x236)[0x5dba26]
/lib/libpthread.so.0[0x2b56ab41af1a]
/lib/libc.so.6(__clone+0x72)[0x2b56abac55d2]
090207 11:04:16 - mysqld got signal 11 ;

And here is the corresponding original query (I leave it untouched, perhaps the string length is relevant):

thd->query at 0x165dcf0 = UPDATE `k1040_10_counter`.`chc_referrers`
                        SET anzahl = anzahl + 1, timestamp = 1234001056
                        WHERE
                                (
                                        ( typ = 'referrer' AND wert = 'http://www.google.de/search?sourceid=navclient&aq=h4&oq=&hl=de&ie=UTF-8&rlz=1T4MEDA_de
DE288DE290&q=einbauk%c3%bcchen' AND monat = 200902  )
                                        OR id = 1369
                                )
                                AND homepage_id = 1
                        LIMIT 2

How to repeat:
I still did not reproduce the crash reliably. If you need more tests and information, let me know.

Now I tracked things down ... here is the simple but important fix:

Have a look into "mysql-5.1.31/sql/sql_class.cc" in function "THD::binlog_query" at this part:

-------------
  /*
    If we are in statement mode and trying to log an unsafe statement,
    we should print a warning.
  */
  if (lex->is_stmt_unsafe() &&
      variables.binlog_format == BINLOG_FORMAT_STMT)
  {
    DBUG_ASSERT(this->query != NULL);
    push_warning(this, MYSQL_ERROR::WARN_LEVEL_WARN,
                 ER_BINLOG_UNSAFE_STATEMENT,
                 ER(ER_BINLOG_UNSAFE_STATEMENT));
    if (!(binlog_flags & BINLOG_FLAG_UNSAFE_STMT_PRINTED))
    {
      char warn_buf[MYSQL_ERRMSG_SIZE];
      my_snprintf(warn_buf, MYSQL_ERRMSG_SIZE, "%s Statement: %s",
                  ER(ER_BINLOG_UNSAFE_STATEMENT), this->query);
      sql_print_warning(warn_buf);
      binlog_flags|= BINLOG_FLAG_UNSAFE_STMT_PRINTED;
    }
  }
------------

I think line "sql_print_warning(warn_buf);" should be "sql_print_warning("%s", warn_buf);" or so, because sql_print_warning is defined as "void sql_print_warning(const char *format, ...)".

So when binlog-format is "statement" you can possibly crash every server with a simple unsafe query that contains for example "%c" or similar, which is the case in the query above. :-)

Duplicate of Bug#42634