一次mysql order by desc 慢的排查

前幾天幫同事排查了一個sql慢的緣由, 以爲有點意思, 這裏記錄一下html

問題描述

有這麼一個表:mysql

備註: 表是我直接複製過來的,但表中的innodb的主鍵是UUID,實際上是不合理的,innodb通常要求主鍵是單調遞增,不然在頻繁插入的時候, innodb的B+樹會頻繁地進行分裂,很是影響性能.算法

CREATE TABLE `spider_record` (
  `id` varchar(32) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL,
  `platform_id` int(11) DEFAULT NULL COMMENT '平臺推文id',
  `titile` varchar(200) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin DEFAULT NULL COMMENT '標題',
  `description` varchar(800) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin DEFAULT NULL COMMENT '描述',
  `updated_at` datetime DEFAULT NULL COMMENT '更新日期',
  `news_url` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin DEFAULT NULL COMMENT '原文連接',
  `published_at` datetime DEFAULT NULL COMMENT '推送日期',
  `create_by` varchar(32) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin DEFAULT NULL,
  `create_time` datetime DEFAULT NULL,
  `update_by` varchar(32) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin DEFAULT NULL,
  `update_time` datetime DEFAULT NULL,
  `is_analyze` tinyint(2) DEFAULT '0' COMMENT '是否分析 0否 1是',
  KEY `platform_id_idx` (`platform_id`),
  KEY `create_tm_idx` (`create_time`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
複製代碼

表中的數據只有14萬(算很小的表了), mysql的版本是5.7, 環境是本身開發的電腦, 中高配(8G內存+SSD硬盤)sql

有如下一個sql(sql1), 剛開始執行的時候還比較快, 但當同一個執行了上千次之後, 單次sql的執行時間變得很是的慢, 最慢的能夠達到30多秒.數據庫

SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time desc LIMIT  10; // sql1
複製代碼

而後若是把order by 後面的desc去掉的話,也就是如下的sql2, 執行時間變成幾十毫秒windows

SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time  LIMIT  10; // sql2
複製代碼

因此問題就是:緩存

爲何14萬數據會查詢這麼慢, 就算全表掃描也不至於這麼慢?
爲何把desc去掉後, 就不慢啦?

到網上查找一些相似的問題, 有幾種說法:bash

mysql沒有開啓緩存. 可是查看本地( show variables like '%query_cache%'; )的配置是開了的.
order by沒有走索引. 可是就算沒有走索引,也不該該是這麼慢.(實際上咱們的sql是走索引了的, 參見下面的explain)

因此網上的解決方案並不適用於咱們這裏, 只能本身解決服務器

問題排查

explain

首先看到sql執行慢, 第一反應確定是查看執行計劃:markdown

mysql>  EXPLAIN 
SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time desc LIMIT  10;
+----+-------------+---------------+------------+-------+---------------+---------------+---------+------+------+----------+-------------+
| id | select_type | table         | partitions | type  | possible_keys | key           | key_len | ref  | rows | filtered | Extra       |
+----+-------------+---------------+------------+-------+---------------+---------------+---------+------+------+----------+-------------+
|  1 | SIMPLE      | spider_record | NULL       | index | NULL          | create_tm_idx | 6       | NULL |   10 |    10.00 | Using where |
+----+-------------+---------------+------------+-------+---------------+---------------+---------+------+------+----------+-------------+
1 row in set (0.05 sec)

mysql>  EXPLAIN 
SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time LIMIT  10;
+----+-------------+---------------+------------+-------+---------------+---------------+---------+------+------+----------+-------------+
| id | select_type | table         | partitions | type  | possible_keys | key           | key_len | ref  | rows | filtered | Extra       |
+----+-------------+---------------+------------+-------+---------------+---------------+---------+------+------+----------+-------------+
|  1 | SIMPLE      | spider_record | NULL       | index | NULL          | create_tm_idx | 6       | NULL |   10 |    10.00 | Using where |
+----+-------------+---------------+------------+-------+---------------+---------------+---------+------+------+----------+-------------+
1 row in set (0.04 sec)
複製代碼

然而, 兩個sql的執行計劃都是如出一轍的, type都是"index"說明是掃描了索引樹,key是"create_tm_idx"說明是掃描了"create_tm_idx"的索引樹去查找數據. 總之從執行計劃來看, sql層面沒有什麼問題,也不至於這麼慢.

show profiles

既然經過執行計劃沒看出什麼異常, 那麼咱們就來第二招, show profiles

先執行一下sql, 能夠看到整個sql是耗時了10秒多的

mysql> SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time desc LIMIT  10;
+----------------------------------+--------------------------------------------+---------------------+
| id                               | titile                                     | published_at        |
+----------------------------------+--------------------------------------------+---------------------+
| 980a0aee8ca0eab8c9d7e830ae8dad89 | AT&T明年或收購沃達豐：中移動捲入交易傳聞   | 2013-11-01 09:02:05 |
| 95412ea5c82f4c7878ed9ce59f6ec496 | 58同城上市首日上漲41.88%                   | 2013-11-01 07:59:28 |
| 93142044d8cfe8ab3ed5c21be2a538b3 | 騰訊聯席CTO熊明華離職                      | 2013-11-01 17:02:55 |
| 896fe75c842ef2c6e28ed9f6a7884873 | 阿里小微金融公佈股權架構：馬雲持股不超7.3% | 2013-11-01 09:23:14 |
| 851c98dbddc1883d8733b713ea682325 | 手機預裝軟件今日起「被規範」 誰將受到衝擊？  | 2013-11-01 14:22:52 |
| 85172df9b1c6ee02cb1afcd6ffe2ae66 | 消息稱搜狐總編輯劉春將離職                 | 2013-10-14 16:24:28 |
| 7c3334c97abd81a8631adc69d95b3a25 | 網易籌備遊戲海外戰略部                     | 2013-11-01 12:24:31 |
| 63e7dd5a6374052661cf7bb97638e905 | Nexus 5萬聖夜低調上線                      | 2013-11-01 07:59:06 |
| 60f7b46485af71dc375bfd3ae38fd776 | 傳Google Hangouts 將整合短信               | 2013-10-09 07:58:55 |
| 5b0f87cf90c27ed9161693c88951afeb | 黑莓或被Facebook收購：雙方高管展開接觸     | 2013-10-30 10:12:26 |
+----------------------------------+--------------------------------------------+---------------------+
10 rows in set (10.67 sec)
複製代碼

再show profiles. profiles中已經有了幾條sql,其中最後一條纔是我剛剛執行的

mysql> show profiles;
+----------+------------+---------------------------------------------------------------------------------------------------------+
| Query_ID | Duration   | Query                                                                                                   |
+----------+------------+---------------------------------------------------------------------------------------------------------+
|        1 | 10.62811400 | SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time desc LIMIT  10 |
|        2 | 10.78871825 | SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time desc LIMIT  10 |
|        3 | 0.05494200 | SHOW FULL TABLES WHERE Table_type != 'VIEW'                                                             |
|        4 | 0.01013250 | SHOW TABLE STATUS                                                                                       |
|        5 | 0.00034200 | SET profiling = 1                                                                                       |
|        6 | 10.65613175 | SELECT id,titile,published_at from spider_record where is_analyze=0 ORDER BY create_time desc LIMIT  10 |
+----------+------------+---------------------------------------------------------------------------------------------------------+
6 rows in set (0.07 sec)
複製代碼

3.再來看看第6條sql的具體執行狀況,執行

mysql> show profile for query 6;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000215 |
| checking permissions | 0.000017 |
| Opening tables       | 0.000085 |
| init                 | 0.000013 |
| System lock          | 0.000020 |
| optimizing           | 0.000020 |
| statistics           | 0.000049 |
| preparing            | 0.000034 |
| Sorting result       | 0.000010 |
| executing            | 0.000007 |
| Sending data         | 10.655393 |
| end                  | 0.000036 |
| query end            | 0.000030 |
| closing tables       | 0.000023 |
| freeing items        | 0.000151 |
| cleaning up          | 0.000033 |
+----------------------+----------+
16 rows in set (0.07 sec)
複製代碼

經過上面的profiles能夠知道, 整個sql最耗時的就是中間的sending data這個階段了.

因此咱們來看一下官方文檔是怎麼描述這個狀態的:

The thread is reading and processing rows for a SELECT statement, and sending data to the client. 
Because operations occurring during this state tend to perform large amounts of disk access (reads), 
it is often the longest-running state over the lifetime of a given query.

當前線程正在讀取和處理一個select語句涉及到的行記錄, 併發送到客戶端. 
出現這個狀態時通常是因爲當前線程正在頻繁地訪問磁盤(讀磁盤),
因此這個狀態通常會佔據整個查詢的生命週期的大部分時間
複製代碼

也就是說,通常的select語句都是這個sending data佔據大部分時間的(雖說也不該該佔10秒). 因此經過profiles, 咱們仍是不知道, 爲啥這個sql會這麼慢.

innodb_buffer_pool_size

在explain和show profile都沒有找到緣由以後, 我極度懷疑sql自己是沒有問題的. 把注意力放在mysql實例的身上. 首先排查的就是innodb_buffer_pool_size這個參數

mysql> show variables like 'innodb_buffer_pool%';
+-------------------------------------+----------------+
| Variable_name                       | Value          |
+-------------------------------------+----------------+
| innodb_buffer_pool_chunk_size       | 8388608        |
| innodb_buffer_pool_dump_at_shutdown | ON             |
| innodb_buffer_pool_dump_now         | OFF            |
| innodb_buffer_pool_dump_pct         | 25             |
| innodb_buffer_pool_filename         | ib_buffer_pool |
| innodb_buffer_pool_instances        | 1              |
| innodb_buffer_pool_load_abort       | OFF            |
| innodb_buffer_pool_load_at_startup  | ON             |
| innodb_buffer_pool_load_now         | OFF            |
| innodb_buffer_pool_size             | 8388608        |
+-------------------------------------+----------------+
10 rows in set (0.09 sec)
複製代碼

查出來一看, innodb_buffer_pool_size才8M左右? 怎麼都說不過去吧.

因而趕忙再看看mysql官方文檔

A larger buffer pool requires less disk I/O to access the same table data more than once. On a dedicated database server, you might set the buffer pool size to 80% of the machine's physical memory size. 設置更大的buffer pool能夠避免屢次重複地從硬盤讀取同一個表的數據, 因此能夠減小磁盤I\O. 在專業的數據庫服務器中, 你能夠把buffer_pool_size的大小設置爲物理內存的80% 複製代碼

官網都建議說innodb_buffer_pool_size應該取物理內存的80%了, 那麼這裏一個8G內存的服務器才設置8m, 那確定是不合適的.

因此後來咱們把innodb_buffer_pool_size設置爲1G大小, 再執行一樣的sql, 執行時間就都降到幾十毫秒了.

問題解決.

問題分析

先回顧一下咱們的問題, 其實有兩個:

爲何innodb_buffer_pool_size會致使sql執行慢
爲何innodb_buffer_pool_size隻影響到了降序排序的sql

爲了回答這個問題, 先來看看mysql innodb引擎的幾個術語

buffer

buffer 通常是用於臨時存儲的一塊磁盤空間或內存空間.

數據緩衝在內存中能夠提升寫的性能, 由於相對於屢次寫小塊數據而言, 大塊數據的寫入能夠減小磁盤的I/O次數.
數據緩衝在硬盤中更加可靠, 由於在某些極端狀況下,系統崩潰的時候,數據還能夠從硬盤中恢復過來.

innodb中用到的buffer主要有幾種, buffer pool, doublewrite buffer, change buffer

buffer pool

buffer pool是innodb存放緩存數據的內存區域, 這些緩存數據包括innodb的表和索引.

爲了提升併發讀的性能, buffer pool會被劃分爲一個個的page, 其中每個page能夠存放若干行的數據.
爲了方便進行緩存管理, buffer pool被設計成爲一個以page爲節點的鏈表.所以一些不多用到的數據,就能夠根據LRU算法進行淘汰.
在一些內存比較大的系統中, 若是buffer pool比較大, 還能夠把buffer pool劃分爲多個 buffer pool instance 來提升併發度.

由於buffer pool的數據位於內存中, 因此當mysql實例關閉的時候, buffer pool中的數據也會丟失.

當mysql實例重啓後, 又須要一段漫長的時間從新把數據預熱到buffer pool中去(mysql官網稱之爲warm up).

從mysql 5.6開始, 能夠經過配置一些系統參數, 在mysql關閉的時候, 把buffer pool的狀態保存下來.而在mysql重啓之後, 再把buffer pool恢復過來. 經過這兩個動做, 能夠極大地減小warm up的時間.

在mysql5.7之後, buffer pool的自動保存和加載已經成爲默認配置

innodb_buffer_pool_size

innodb_buffer_pool_size 就是buffer pool的大小了. 通常來講默認值是128M. 在32位系統中,最大值爲2的32次方減1字節. 在64位系統中,最大值爲2的64次方減1字節.

由於buffer pool做爲是innodb的數據和索引的緩存, 在物理內存無限大的狀況下, buffer pool的也是越大越好. 可是mysql只是建議你最多用到物理內存的80%, 主要是出於如下幾點考慮:

跟操做系統競爭內存, 有可能會致使操做系統的頻繁缺頁, 致使整個機器的性能降低
mysql會爲它的一些其它數據結構保留部份內存, 因此實際佔用內存會比buffer pool多個10%左右
buffer pool 通常須要分配連續內存, 不然在windows操做系統中會有一些問題
buffer pool的初始化時間是跟它的大小成正比的

clustered index 和 secondary index

clustered index就是彙集索引. 通常是指主鍵的索引; secondary index輔助索引就是指普通的索引.

彙集索引和輔助索引都是一顆B+樹.並且非葉節點都不存儲實際數據. 數據都存在葉節點中.並且每個葉節點都有一個指針指向下一個葉節點和前一個葉節點. 也就是說全部的葉節點會組成一個雙向鏈表,能夠用於範圍查詢

彙集索引是以主鍵(也多是惟一鍵)做爲索引, 葉節點存儲了這個主鍵對應的行的全部數據.因此能夠經過主鍵直接查到這行的任何一列數據

輔助索引是以索引的列做爲索引, 葉節點存儲了索引列的數據和對應的主鍵. 因此若是select中的列就是索引中的一列的話, 直接在葉節點中就能查到數據. 這就是"索引覆蓋". 可是若是select語句中的列不是索引中的一列的話, 就必須在葉節點中查到主鍵, 再用主鍵去查到對應列的數據, 這就是"回表"

在mysql8.0以前, innodb的全部的索引樹都是升序的, 雖然建立索引的時候能夠指定是asc仍是desc, 可是實際建立索引的時候, 都是asc的. 直到mysql8.0中, 索引才支持desc

好了, 說了這一大堆以後, 開始來回答一下開始的兩個問題

爲何innodb_buffer_pool_size會致使sql執行慢

這個是很明顯的, 當buffer pool不夠用的時候, 大多數的數據請求都會落到磁盤數, 磁盤IO性能會比內存讀取高出不少個數量級
爲何innodb_buffer_pool_size隻影響到了降序排序的sql

這個問題其實我也沒有很確切的答案. 只能利用現有的條件作一下推測.

首先咱們知道create_time_idx是一顆升序的B+樹, 數據都存放在葉節點中, 其中create_time較小的通常集中於樹的左邊, create_time較大的通常集中於樹的右邊.

當sql根據升序排序時, mysql須要找到這顆B+樹的最左葉節點, 而後利用葉節點的雙向鏈表直接遍歷10條符合條件(is_analyze=0)的便可.

當sql根據降序排序時, mysql須要找到這顆B+樹的最右葉節點, 而後利用葉節點的雙鏈表直接遍歷10條符合條件(is_analyze=0)的數據便可.

另外,因爲B+樹的內部節點通常都有成千上萬個指針, 找最右葉節點時通常都要遍歷大部分這些內部節點的指針, 而找最左葉節點時相對遍歷的指針會比較少一點. 因此找到最右葉節點會比找到最左葉節點相對耗時一點

找到最左最右葉節點後, 接下來就是要遍歷出10條符合條件(is_analyze=0)的數據了, 這個時候就要看目標數據主要分佈在哪了. 若是數據分佈在左邊, 那麼倒序排序(從最右葉節點開始遍歷)就須要遍歷更多的葉節點,致使buffer pool不夠用, 最終須要進行磁盤IO, 致使性能降低. 而若是數據分佈在右邊的話, 查詢性能就會好不少.

純文字描述會比較亂,也很差理解能夠參考一下這篇文章的兩張圖. 圖中目標的數據就是分佈在"右邊", 因此反向掃描的話, 能夠很快就能掃描到
1. 正向掃描
2. 反向掃描

下面來證實一下個人推測.

首先來看一下這個表中的create_time的分佈都是怎麼樣. 能夠看到create_time只有四天的數據, 其中主要都是在前兩天(b+樹的左邊)

mysql> SELECT date(create_time) , count(0) from spider_record GROUP BY date(create_time);
+-------------------+----------+
| date(create_time) | count(0) |
+-------------------+----------+
| 2019-06-17        |       52 |
| 2019-06-18        |   141042 |
| 2019-06-19        |      100 |
| 2019-06-20        |       55 |
+-------------------+----------+
4 rows in set (0.18 sec)
複製代碼

再看看is_analyze=0的數據分佈, 也的確是都分佈在b+樹"左邊"

mysql> SELECT date(create_time) , count(0) from spider_record where is_analyze=0 GROUP BY date(create_time);
+-------------------+----------+
| date(create_time) | count(0) |
+-------------------+----------+
| 2019-06-18        |   141042 |
| 2019-06-20        |       55 |
+-------------------+----------+
2 rows in set (0.18 sec)
複製代碼

而後, 咱們把6月18日的數據的create_time都增長兩天

update spider_record set create_time = create_time + INTERVAL 2 day where date(create_time) = '2019-06-18';

複製代碼

最後查看數據分佈, 如今無論是全部數據, 仍是is_analyze=0的數據, 都是大部分分佈在"右邊"了

mysql> SELECT date(create_time) , count(0) from spider_record GROUP BY date(create_time);
+-------------------+----------+
| date(create_time) | count(0) |
+-------------------+----------+
| 2019-06-17        |       52 |
| 2019-06-19        |      100 |
| 2019-06-20        |   141097 |
+-------------------+----------+
3 rows in set (0.28 sec)

mysql> SELECT date(create_time) , count(0) from spider_record where is_analyze=0 GROUP BY date(create_time);
+-------------------+----------+
| date(create_time) | count(0) |
+-------------------+----------+
| 2019-06-20        |   140683 |
| 2019-06-17        |       52 |
+-------------------+----------+
2 rows in set (0.92 sec)
複製代碼

最後再來看看這個sql的執行耗時(我在navicat裏面連續執行1000屢次), 如圖. 時間都在幾毫秒內了...

考慮到有多是mysql的狀態變了, 或其餘緩存的緣由形成的查詢變快了, 我又把create_time爲6月20日的數據改爲6月18, 即執行下面sql

update spider_record set create_time = create_time - INTERVAL 2 day where date(create_time) = '2019-06-20'
複製代碼

而後再來看看那個sql的執行耗時(也是在navicat裏面連續執行1000屢次), 結果如圖, 果真是慢了不少...

總結

其實這個問題共性應該不是很大, 由於通常生產環境的innodb_buffer_pool_size是絕對不會配置成8M的.

另外上面提到的數據分佈在"左邊"和"右邊"的說法, 其實有點牽強, 由於B+樹畢竟是一顆平衡樹, 都不存在什麼偏向左邊偏向右邊的說法.(然而實驗結果支持了這個說法, 我也很絕望~~)

可是, 從這一次問題排查中, 咱們至少能夠很肯定地認識到了2點:

innodb_buffer_pool_size的參數必定不要配置得過小,不然會極大地影響mysql的性能.
必定要注意order by desc. 雖然在mysql 8.0已經支持了降序索引. 可是若是你的索引是升序的而order by又指定desc的話. mysql查詢計劃的extra中仍是會給你指出這個sql會進行"Backward index scan"(以下圖), 讓你注意到它用了反向掃描.

說明反向掃描仍是會比正向掃描相對耗時.因此若是sql中能避免反向掃描的話, 最好仍是避免反向掃描