Mysql bug#64624:備庫開啟query cache后crash的分析
主庫：mysql-5.1.48
備庫：percona server 5.5.18（query cache on）
重現(xiàn)：
備庫在valgrind下啟動：
| valgrind –leak-check=full –trace-children=yes –log-file=$HOME/valgrind.1 ./bin/mysqld –defaults-file=my.s.s.cnf |
主庫上執(zhí)行：
| /*!40000 ALTER TABLE `t1` DISABLE KEYS */; |
出錯結(jié)果：
- 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導(dǎo)致數(shù)據(jù)變更了才會寫binlog，而select語句是不會被備庫復(fù)制執(zhí)行的，那為何備庫在do_apply_event時會訪問query cache?
因為mysql執(zhí)行sql的入口是mysql_parse，對于從主庫上復(fù)制過來的binlog，如果是SQL形式（DDL或者binlog format為statement），會進(jìn)入mysql_parse，而mysql_parse的邏輯是首先查看query cache，如果不能返回結(jié)果就執(zhí)行mysql_execute_command，并且對于select query，之后還會將結(jié)果寫到query cache.
在Query_cache::send_result_to_client函數(shù)中會對sql語句進(jìn)行檢查，如果不是SELECT語句會直接返回，檢查邏輯如下：
- if (!((i + 2 < query_length) &&
- ((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;
- }
因此，備庫復(fù)制執(zhí)行binlog時雖然會進(jìn)入到query cache，但是由于它們不是SELECT QUERY會直接返回，其實并沒有真正訪問query cache，然而上述判斷邏輯也有出現(xiàn)問題的時候，那就是類似這樣的SQL：
| /*!40000 ALTER TABLE `t1` DISABLE KEYS */; |
會和SELECT一樣繼續(xù)往下執(zhí)行…，直到：
- 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讀到的未初始化的數(shù)據(jù)！
在alloc_query中，querybuffer的內(nèi)存布局如下：
+———–+———–+—————————————-+———–+
| 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函數(shù)中，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函數(shù)中時，就導(dǎo)致了memecpy讀取未初始化的數(shù)據(jù)，從而使得條件不滿足而退出query cache，但是這并不會導(dǎo)致任何問題，因為備庫執(zhí)行binlog本該不訪問query cache，由于memcpy只是copy了未初始化的數(shù)據(jù)（后面還有空間）而并沒有訪問NULL pointer，因此不會出現(xiàn)問題，而這也是重現(xiàn)crash比較困難的原因！
但是，這里存在一個隱患，如果讀取的未初始化數(shù)據(jù)db_len正好和thd->db_length相同，那么Query_cache::send_result_to_client還將繼續(xù)執(zhí)行下去，直到…
| memcpy((uchar *)(sql + (tot_length – QUERY_CACHE_FLAGS_SIZE)), (uchar*) &flags, QUERY_CACHE_FLAGS_SIZE); |
悲劇發(fā)生了…tot_length是按照alloc_query中的內(nèi)存布局計算出來的，但是實際傳給send_result_to_client的query是缺少一個字段的，于是memcpy訪問越界，導(dǎo)致slave crash
mysql官方和percona都為此bug提供了patch，percona通過thd->alloc重新分配了一個query buffer，而mysql官方直接修改了bug的源頭，都放進(jìn)來。
patch：
http://bazaar.launchpad.net/~mysql/mysql-server/5.5/revision/3837
https://bugs.launchpad.net/percona-server/+bug/915814
