MySQL · 答疑解惑 · 索引過濾性太差引起CPU飆高分析 · 數據庫內核月報

## 前言在操作數據庫系統的時候，有個常識就是在建表的時候一定要建索引。為什么要建索引呢？這里以MySQL的InnoDB存儲引擎為例，因為InnoDB會以索引的排序為基準建立B+樹，這樣在檢索數據的時候就可以通過B+樹來查找，查找算法的時間復雜度是O(logn)級別的，避免全表掃描帶來的性能下降和額外資源損耗。理論上一個表所有的字段都可以建索引，那么給哪些字段建索引效果好呢？一個想法是給頻繁在SQL的where條件中出現的字段建立索引，這樣可以保證通過索引來查找數據。有一點是經常被忽略的，那就是索引的過濾性。比如我們給一個整型字段加索引，而這個字段在幾乎所有的記錄上的值都是1（過濾性很差），那么我們通過這個索引來查找數據就會遍歷大部分無關記錄，造成浪費。我們知道update語句也是通過索引來查找待更新的數據的，而且update會給索引查找的記錄加上X鎖，因此索引過濾性不好不但造成性能下降，還有可能造成鎖爭奪和鎖等待的損耗。下面給出一個具體的因為索引過濾性太差引起CPU飆高的case，在RDS的線上實例曾出現過類似的case。 ## 場景構造在MySQL里我們建立這樣一個表： ~~~ CREATE TABLE `sbtest1` ( `id` int(10) unsigned NOT NULL, `k` int(10) unsigned NOT NULL DEFAULT '0', `n` int(10) unsigned NOT NULL DEFAULT '0', `c` char(120) NOT NULL DEFAULT '', `pad` char(60) NOT NULL DEFAULT '', PRIMARY KEY (`id`), KEY `k_1` (`k`) ) ENGINE=InnoDB; ~~~ 然后我們給sbtest1加點數據，并且讓索引k_1(k)的過濾性不好，表內一共10000000條數據，索引k只有2個值50,51，如下所示： ~~~ mysql> select count(*) from sbtest1; +----------+ | count(*) | +----------+ | 10000000 | +----------+ 1 row in set (1.80 sec) mysql> select distinct k from sbtest1; +----+ | k | +----+ | 50 | | 51 | +----+ 2 rows in set (2.22 sec) ~~~ 然后我們用sysbench開32個并發的update，update語句如下： ~~~ UPDATE sbtest1 SET c='隨機字符串' WHERE k=50或51 and n=隨機值 ~~~ 執行show full processlist\G，可以看到這些update的狀態大多處于”Searching rows for update”的狀態。 ~~~ mysql> show full processlist\G *************************** 1\. row *************************** Id: 2 User: root Host: db: test Command: Sleep Time: 6 State: Info: NULL Memory_used: 1146520 Memory_used_by_query: 8208 Logical_read: 53 Physical_sync_read: 2 Physical_async_read: 0 Temp_user_table_size: 0 Temp_sort_table_size: 0 Temp_sort_file_size: 0 *************************** 2\. row *************************** Id: 6 User: root Host: db: sbtest Command: Query Time: 21 State: Searching rows for update Info: UPDATE sbtest1 SET c='96372750646-31206582030-89561475094-70112992370-09982266420-13264143120-70453817624-14068123856-50060327807-36562985632' WHERE k=50 and n=4951641 Memory_used: 119840 Memory_used_by_query: 232 Logical_read: 4935 Physical_sync_read: 0 Physical_async_read: 0 Temp_user_table_size: 0 Temp_sort_table_size: 0 Temp_sort_file_size: 0 *************************** 3\. row *************************** Id: 7 User: root Host: db: sbtest Command: Query Time: 21 State: Searching rows for update Info: UPDATE sbtest1 SET c='28921237680-50951214786-47793625883-44090170070-31354117142-11520543175-97262835853-83486109785-32721666363-10671483869' WHERE k=51 and n=5033717 Memory_used: 119840 Memory_used_by_query: 232 Logical_read: 4949 Physical_sync_read: 5 Physical_async_read: 0 Temp_user_table_size: 0 Temp_sort_table_size: 0 Temp_sort_file_size: 0 ... ~~~ “Searching rows for update”即MySQL正在尋找待更新的記錄的狀態，正常情況這個狀態是非常快就結束的，但是這里卻長時間處于這個狀態，為什么呢？由于表的索引過濾性太差，每個線程在查找的時候會遇到很多沖突的記錄。 InnoDB在通過索引拿到記錄后，會給這些記錄上X鎖，同時也會請求全局的`lock_sys->mutex`和`trx_sys->mutex`，所以這里我們判斷每個線程都堵在鎖等待這里。（ps: 關于InnoDB加鎖的邏輯，可以查看[這篇博文](http://hedengcheng.com/?p=771)）這時候對系統用一下top命令，可以發現這個MySQL實例CPU飚的很高，我們再用perf工具看一下CPU飆高的MySQL調用堆棧是怎么樣的，如下所示： ~~~ 83.77% mysqld mysqld [.] _Z8ut_delaym | --- _Z8ut_delaym | |--99.99%-- _Z15mutex_spin_waitP10ib_mutex_tPKcm | | | |--88.88%-- _ZL20pfs_mutex_enter_funcP10ib_mutex_tPKcm.constprop.68 | | | | | |--54.05%-- _ZL29lock_rec_convert_impl_to_explPK11buf_block_tPKhP12dict_index_tPKm | | | _Z34lock_clust_rec_read_check_and_lockmPK11buf_block_tPKhP12dict_index_tPKm9lock_modemP9que_thr_t | | | _ZL16sel_set_rec_lockPK11buf_block_tPKhP12dict_index_tPKmmmP9que_thr_t | | | _Z20row_search_for_mysqlPhmP14row_prebuilt_tmm | | | _ZN11ha_innobase10index_nextEPh | | | _ZN7handler13ha_index_nextEPh | | | _ZL8rr_indexP11READ_RECORD | | | _Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_ordery15enum_duplicatesbPySB_ | | | _Z21mysql_execute_commandP3THD | | | _Z11mysql_parseP3THDPcjP12Parser_state | | | _Z16dispatch_command19enum_server_commandP3THDPcj | | | _Z26threadpool_process_requestP3THD | | | _ZL11worker_mainPv | | | start_thread | | | | | --45.95%-- _Z15lock_rec_unlockP5trx_tPK11buf_block_tPKh9lock_mode | | _Z20row_unlock_for_mysqlP14row_prebuilt_tm | | _Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_ordery15enum_duplicatesbPySB_ | | _Z21mysql_execute_commandP3THD | | _Z11mysql_parseP3THDPcjP12Parser_state | | _Z16dispatch_command19enum_server_commandP3THDPcj | | _Z26threadpool_process_requestP3THD | | _ZL11worker_mainPv | | start_thread ~~~ 我們看到耗CPU最高的調用函數棧是…`mutex_spin_wait`->`ut_delay`，屬于鎖等待的邏輯。InnoDB在這里用的是自旋鎖，鎖等待是通過調用ut_delay做空循環實現的，會消耗CPU。這里證明了上面的判斷是對的。在這個case里涉及到的鎖有記錄鎖、`lock_sys->mutex`和`trx_sys->mutex`，究竟是哪個鎖等待時間最長呢？我們可以用下面的方法確認一下： ~~~ mysql> SELECT COUNT_STAR, SUM_TIMER_WAIT, AVG_TIMER_WAIT, EVENT_NAME FROM performance_schema.events_waits_summary_global_by_event_name where COUNT_STAR > 0 and EVENT_NAME like 'wait/synch/%' order by SUM_TIMER_WAIT desc limit 10; +------------+------------------+----------------+--------------------------------------------+ | COUNT_STAR | SUM_TIMER_WAIT | AVG_TIMER_WAIT | EVENT_NAME | +------------+------------------+----------------+--------------------------------------------+ | 36847781 | 1052968694795446 | 28575867 | wait/synch/mutex/innodb/lock_mutex | | 8096 | 81663413514785 | 10086883818 | wait/synch/cond/threadpool/timer_cond | | 19 | 3219754571347 | 169460766775 | wait/synch/cond/threadpool/worker_cond | | 12318491 | 1928008466219 | 156446 | wait/synch/mutex/innodb/trx_sys_mutex | | 36481800 | 1294486175099 | 35397 | wait/synch/mutex/innodb/trx_mutex | | 14792965 | 459532479943 | 31027 | wait/synch/mutex/innodb/os_mutex | | 2457971 | 62564589052 | 25346 | wait/synch/mutex/innodb/mutex_list_mutex | | 2457939 | 62188866940 | 24909 | wait/synch/mutex/innodb/rw_lock_list_mutex | | 201370 | 32882813144 | 163001 | wait/synch/rwlock/innodb/hash_table_locks | | 1555 | 15321632528 | 9853039 | wait/synch/mutex/innodb/dict_sys_mutex | +------------+------------------+----------------+--------------------------------------------+ 10 rows in set (0.01 sec) ~~~ 從上面的表可以確認，lock_mutex（在MySQL源碼里對應的是`lock_sys->mutex`）的鎖等待累積時間最長（SUM_TIMER_WAIT）。lock_sys表示全局的InnoDB鎖系統，在源碼里看到InnoDB加/解某個記錄鎖的時候（這個case里是X鎖），同時需要維護lock_sys，這時會請求lock_sys->mutex。在這個case里，因為在Searching rows for update的階段頻繁地加/解X鎖，就會頻繁請求`lock_sys->mutex`，導致`lock_sys->mutex`鎖總等待時間過長，同時在等待的時候消耗了大量CPU。當我們將索引改成過濾性好的（比如字段n），再做上述實驗，就看不到那么多線程堵在”Searching rows for update”的階段，而且實例的CPU消耗也降了很多。 ## 結語通過以上實驗，我們看到索引過濾性不好可能帶來災難性的結果：語句hang住以及主機CPU耗盡。因此我們在設計表的時候，應該對業務上的數據有充分的估計，選擇過濾性好的字段作為索引。