mysql initlized_Mysql bug#64624:备库开启query cache后crash的分析

主库：mysql-5.1.48

备库：percona server 5.5.18(query cache on)

重现：

备库在valgrind下启动：

valgrind –leak-check=full –trace-children=yes –log-file=$HOME/valgrind.1 ./bin/mysqld –defaults-file=my.s.s.cnf

主库上执行：

/*!40000 ALTER TABLE `t1` DISABLE KEYS */;

出错结果：

Thread 21:

Conditional jump or move depends on uninitialised value(s)

at 0x***6743: Query_cache::send_result_to_client(THD*, char*, unsigned int) (sql_cache.cc:2051)

by 0x5EDE27: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:5756)

by 0x800B79: Query_log_event::do_apply_event(Relay_log_info const*, char const*, unsigned int) (log_event.cc:3398)

by 0×800157: Query_log_event::do_apply_event(Relay_log_info const*) (log_event.cc:3166)

by 0×572005: Log_event::apply_event(Relay_log_info const*) (log_event.h:1135)

by 0x56B1A9: apply_event_and_update_pos(Log_event*, THD*, Relay_log_info*) (slave.cc:2351)

by 0x56B6E9: exec_relay_log_event(THD*, Relay_log_info*) (slave.cc:2511)

by 0x56D8F6: handle_slave_sql (slave.cc:3329)

by 0x3A01806D63: start_thread (pthread_create.c:308)

原因分析：

理论上讲，只有SQL导致数据变更了才会写binlog，而select语句是不会被备库复制执行的，那为何备库在do_apply_event时会访问query cache?

因为mysql执行sql的入口是mysql_parse，对于从主库上复制过来的binlog，如果是SQL形式(DDL或者binlog format为statement)，会进入mysql_parse，而mysql_parse的逻辑是首先查看query cache，如果不能返回结果就执行mysql_execute_command，并且对于select query，之后还会将结果写到query cache.

在Query_cache::send_result_to_client函数中会对sql语句进行检查，如果不是SELECT语句会直接返回，检查逻辑如下：

if (!((i + 2

((my_toupper(system_charset_info, sql[i])     == ‘S’ &&

my_toupper(system_charset_info, sql[i + 1]) == ‘E’ &&

my_toupper(system_charset_info, sql[i + 2]) == ‘L’) ||

sql[i] == ‘/’)))

{

DBUG_PRINT(“qcache”, (“The statement is not a SELECT; Not cached”));

goto err;

}

因此，备库复制执行binlog时虽然会进入到query cache，但是由于它们不是SELECT QUERY会直接返回，其实并没有真正访问query cache，然而上述判断逻辑也有出现问题的时候，那就是类似这样的SQL：

/*!40000 ALTER TABLE `t1` DISABLE KEYS */;

会和SELECT一样继续往下执行…，直到：

size_t db_len;

memcpy((char *) &db_len, (sql + query_length + 1), sizeof(size_t));

if (thd->db_length != db_len)

{

…

DBUG_PRINT(“qcache”, (“Current database has changed since start of query”));

goto err;

}

这是因为memcpy读到的未初始化的数据！

在alloc_query中，querybuffer的内存布局如下：

+———–+———–+—————————————-+———–+

| Query  |db len  |       db_name                    | FLAGS |

+———–+———–+—————————————-+———–+

其中db len类型为size_t，保存db_name的长度

send_result_to_client中的计算tot_length的方式可以说明：

tot_length= query_length + 1 + sizeof(size_t) + thd->db_length + QUERY_CACHE_FLAGS_SIZE;

而在Query_log_event::Query_log_event函数中，data buffer如下：(下面的接在上面之后)：

+———-+—————–+——-+————-+————-+—-+

| catlog | time_zone | user|   host    |db name | \0 |

+———-+—————–+——-+————-+————-+—-+

+———-+———————————————————+———-+

| Query | uninitiatlized space of size of db len | FLAGS |

+———-+———————————————————+———-+

其中为query buffer分配的空间从Query开始，比较可知，相对于alloc_query中的缺少了db len部分(sizeof(size_t))

在将其传入到send_result_to_client函数中时，就导致了memecpy读取未初始化的数据，从而使得条件不满足而退出query cache，但是这并不会导致任何问题，因为备库执行binlog本该不访问query cache，由于memcpy只是copy了未初始化的数据(后面还有空间)而并没有访问NULL pointer，因此不会出现问题，而这也是重现crash比较困难的原因！

但是，这里存在一个隐患，如果读取的未初始化数据db_len正好和thd->db_length相同，那么Query_cache::send_result_to_client还将继续执行下去，直到…

memcpy((uchar *)(sql + (tot_length – QUERY_CACHE_FLAGS_SIZE)),

(uchar*) &flags, QUERY_CACHE_FLAGS_SIZE);

悲剧发生了…tot_length是按照alloc_query中的内存布局计算出来的，但是实际传给send_result_to_client的query是缺少一个字段的，于是memcpy访问越界，导致slave crash

mysql官方和percona都为此bug提供了patch，percona通过thd->alloc重新分配了一个query buffer，而mysql官方直接修改了bug的源头，都放进来。

patch：

http://bazaar.launchpad.net/~mysql/mysql-server/5.5/revision/3837

https://bugs.launchpad.net/percona-server/+bug/915814

【编辑推荐】

【责任编辑：黄丹 TEL：(010)68476606】

点赞 0