高性能MySQL（二）：服務器性能剖析

文章目錄

前言

性能優化簡介

通過性能剖析進行優化

理解性能剖析

剖析Mysql查詢

慢查詢日志

pt-query-digest

優秀資料

慢SQL定位分析

前言

我準備開一個新的系列，這是我以前接觸不多的新領域，叫性能調優。

刷博客的時候，看到“性能調優”這個詞的時候，我整個人都愣住了，感覺時間停滯了。

我發現，我根本不知道我寫的項目代碼，性能屬于什么水平，就算是爛，也不知道到底有多爛。 我使用的中間件，也不知道它們的性能如何。

這樣不好。

本系列取材于《高性能Mysql》第三版，是我的學習筆記。

在

他們

的技術咨詢生涯中，最常碰到的三個性能相關的服務請求是：如何確認服務器是否達到了性能最佳的狀態、找出某條語句為什么執行不夠快，以及診斷被用戶描述成“停頓”、“堆積”或“卡死”的某些間歇性疑難雜癥。

首先我們要保持空杯精神（對我來說，我的杯子一直是空的），拋棄掉一些關于性能的常見的誤解。

性能優化簡介

性能：性能即相應時間，這是一個非常重要的原則。我們通過

任務和時間

而不是資源來測量性能。

數據庫服務器的目的是執行SQL語句，所以它關注的是查詢或者語句（查詢 == 發送給服務器的指令）。

優化：我們假設優化是服務器在一定的工作負載下盡可能的而減少響應時間。

這里就引申出第二個原則：無法測量就無法有效的優化，所以

第一步應該測量時間花在什么地方

。

有兩種情況會導致不合適的測量：

在錯誤的時間啟動和停止測量 測量的是聚合后的信息，而不是目標活動本身

1

2

完成一項任務所需要的時間可以分成兩部分：執行時間和等待時間。如果需要優化任務的執行時間，最好的辦法就是通過測量定位不同的子任務花費的時間，然后優化去掉一些子任務，降低子任務的執行頻率，或者提升子任務的效率。而優化任務的等待時間則相對要復雜一些。

那么如何確認哪些子任務是優化的目標呢？這個時候性能剖析就可以派上用場了。

通過性能剖析進行優化

性能剖析一般有兩個步驟：測量任務所花費的時間；然后對結果進行排序，將重要的任務排到前面。

我們將實際的討論兩種類型的性能剖析：基于執行時間的分析和基于等待的分析。

基于時間的分析研究的是什么任務的執行時間最長，而基于等待的分析則是判斷任務在什么地方被阻塞的時間最長。

（突然感覺有點郁悶，這一章一直看不通，外面都在說用explain，但是我總覺得還有更核心的問題。會是慢查詢日志嗎？）

后面會講一個性能測試工具：pt-qurey-digest，前面就先看著吧。

理解性能剖析

1、值的優化的查詢

性能剖析不會自動給出哪些查詢值得時間去優化。

對一個占總響應時間不超過5%的查詢進行優化，無論如何努力，收益也不會超過5%。第二，如果花費了1000美元去優化一個任務，但業務的收入沒有增加，那么可以說反而導致了業務的逆優化。如果優化的成本大于收益，就應該停止優化。

2、異常優化

某些任務即使沒有出現再性能剖析輸出的前面，也需要優化，比如某些任務執行的次數很少，但是每次執行都非常慢，嚴重影響用戶體驗。因為其執行頻率低，所以總的響應時間占比并不突出。

3、未知的未知

要知道，工具始終是有局限性的。

剖析MySQL查詢

在MySQL當前版本中，慢查詢日志是開銷最低、精度最高的測量查詢時間的工具。慢查詢日志帶來的I/O開銷可以忽略不計，更需要擔心的是日志可能消耗大量的磁盤空間。如果長期開啟慢查詢日志，要注意部署日志輪轉工具。或者不要長期開啟慢查詢日志，只在需要收集負載樣本的期間開啟即可。

慢查詢日志

MySQL 慢查詢日志是排查問題 SQL 語句，以及檢查當前 MySQL 性能的一個重要功能。

查看是否開啟慢查詢功能：

mysql> show variables like 'slow_query%'; +---------------------+-----------------------------------+ | Variable_name | Value | +---------------------+-----------------------------------+ | slow_query_log | OFF | | slow_query_log_file | /var/lib/mysql/localhost-slow.log | +---------------------+-----------------------------------+

1

2

3

4

5

6

7

mysql> show variables like 'long_query_time'; +-----------------+-----------+ | Variable_name | Value | +-----------------+-----------+ | long_query_time | 10.000000 | +-----------------+-----------+

1

2

3

4

5

6

slow_query_log 慢查詢開啟狀態

slow_query_log_file 慢查詢日志存放的位置（這個目錄需要MySQL的運行帳號的可寫權限，一般設置為MySQL的數據存放目錄）

long_query_time 查詢超過多少秒才記錄

默認沒有開啟慢查詢日志記錄，通過命令臨時開啟：

set global slow_query_log='ON'; set global slow_query_log_file='/var/lib/mysql/instance-1-slow.log'; set global long_query_time=2;

1

2

3

永久配置：（自取，我就不永久了）

修改配置文件達到永久配置狀態： /etc/mysql/conf.d/mysql.cnf [mysqld] slow_query_log = ON slow_query_log_file = /var/lib/mysql/instance-1-slow.log long_query_time = 2 配置好后，重新啟動 MySQL 即可。 測試 通過運行下面的命令，達到問題 SQL 語句的執行： mysql> select sleep(2); +----------+ | sleep(2) | +----------+ | 0 | +----------+ 1 row in set (2.00 sec) 然后查看慢查詢日志內容： $ cat /var/lib/mysql/instance-1-slow.log

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

不要直接打開整個慢查詢日志進行分析，這樣只會浪費時間和金錢。

建議使用pt-query-digest生成一個剖析報告，如果必要，可以再查看日志中需要關注的部分。

pt-query-digest

pt-query-digest是用于分析mysql慢查詢的一個工具，它可以分析binlog、General log、slowlog，也可以通過SHOWPROCESSLIST或者通過tcpdump抓取的MySQL協議數據來進行分析。可以把分析結果輸出到文件中，分析過程是先對查詢語句的條件進行參數化，然后對參數化以后的查詢進行分組統計，統計出各查詢的執行時間、次數、占比等，可以借助分析結果找出問題進行優化。

下載：

wget https://www.percona.com/downloads/percona-toolkit/3.2.1/binary/redhat/7/x86_64/percona-toolkit-3.2.1-1.el7.x86_64.rpm

1

ls | grep percona-toolkit-3.2.1-1.el7.x86_64.rpm

1

PT 工具是使用 Perl 語言編寫和執行的，所以需要系統中有 Perl 環境。安裝相關的依賴包，

[root@xxx ~]# yum install perl-DBI.x86_64 [root@xxx ~]# yum install perl-DBD-MySQL.x86_64 [root@xxx ~]# yum install perl-IO-Socket-SSL.noarch [root@xxx ~]# yum install perl-Digest-MD5.x86_64 [root@xxx ~]# yum install perl-TermReadKey.x86_64

1

2

3

4

5

安裝 Percona Toolkit：

rpm -iv percona-toolkit-3.2.1-1.el7.x86_64.rpm

1

rpm -qa | grep percona

1

工具目錄安裝路徑：/usr/bin

下載的跟烏龜一樣慢，我就先拿些現成的來了。加速包又一直解析不出來。。

解析慢查詢日志：

pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log > slow_report.log

1

輸出結果分為3部分：

匯總信息

[root@VM_0_9_centos ~]# more slow_report.log # 230ms user time, 20ms system time, 26.35M rss, 220.76M vsz # CPU和內存使用信息 # Current date: Wed Aug 26 15:44:46 2020 # 當前時間 # Hostname: VM_0_9_centos # 主機名 # Files: /var/lib/mysql/VM_0_9_centos-slow.log # 輸入的慢日志路徑 ## 整個分析結果的匯總信息 # Overall: 258 total, 37 unique, 0.02 QPS, 0.00x concurrency _____________ # Time range: 2020-08-26T11:20:16 to 2020-08-26T15:44:11 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 7s 249us 5s 26ms 4ms 311ms 657us # Lock time 349ms 0 152ms 1ms 348us 12ms 194us # Rows sent 33.01k 0 9.77k 131.03 755.64 742.92 0.99 # Rows examine 93.32k 0 9.77k 370.38 874.75 775.00 54.21 # Query size 51.71k 15 7.23k 205.23 223.14 615.30 143.84

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

Overall：總共有多少個查詢，該例總共有2.58k（2580）個查詢。 Time range：查詢執行的時間范圍。注意，MySQL5.7版本中的時間格式不同于之 前的版本。 Unique：唯一查詢數量，即對查詢條件進行參數化以后，總共有多少個不同的查 詢。該例為10個。 Attribute：如上述代碼段所示，表示Attribute列描述的Exec time、Lock time等屬性 名稱。 total：表示Attribute列描述的Exec time、Lock time等屬性的統計數值。 min：表示Attribute列描述的Exec time、Lock time等屬性的最小值。 max：表示Attribute列描述的Exec time、Lock time等屬性的最大值。 avg：表示Attribute列描述的Exec time、Lock time等屬性的平均值。 95%：表示Attribute列描述的Exec time、Lock time等屬性的所有值從小到大排 列，然后取位于95%位置的那個數值（需要重點關注這個值）。 stddev：標準偏差，用于數值的分布統計。 median：表示Attribute列描述的Exec time、Lock time等屬性的中位數，即把所有 值從小到大排列，取位于中間的那個數值

1

2

3

4

5

6

7

8

9

10

11

第二部分：

對查詢進行參數化并分組，然后對各類查詢的執行情況進行分析，結果按總執行時間從大到小排列

# Profile # Rank Query ID Response time Calls R/Call V/M It # ==== =============================== ============= ===== ====== ===== == # 1 0x59A74D08D407B5EDF9A57DD5A4... 5.0003 73.7% 1 5.0003 0.00 SELECT # 2 0x64EF0EA126730002088884A136... 0.9650 14.2% 2 0.4825 0.01 # 3 0x5E1B3DE19F673369DCF52FE6A5... 0.3174 4.7% 2 0.1587 0.00 INSERT data_million_a # 4 0x3992A499999D8F9E3ACC220E0F... 0.1334 2.0% 1 0.1334 0.00 ALTER TABLE dtb_table_size `dtb_table_size` # 5 0x66CAA645BA3ED5433EADC39CCA... 0.0991 1.5% 2 0.0495 0.08 SELECT data_million_a # MISC 0xMISC 0.2735 4.0% 250 0.0011 0.0 <32 ITEMS>

1

2

3

4

5

6

7

8

9

Rank：為查詢生成的數字編號，表示該分類語句在整個分析結果集中的排名。 Query ID：為查詢生成的隨機字符串ID（根據指紋語句生成的checksum隨機字符串）。 Response time：該查詢的總的響應時間和占所有查詢的總的響應時間的百分比。 Calls：該查詢的執行次數，即本次分析總共有多少條這種類型的查詢語句。 R/Call：該查詢平均每次執行的響應時間。 V/M：響應時間的方差與均值的比值。 Item：具體的查詢語句對象（標準化格式轉換的語句形式：去掉了具體的select字段和表名、where條件等）

1

2

3

4

5

6

7

第三部分：

按照語句執行的總時間，從大到小依次打印每條語句的相關統計信息

# Query 1: 0 QPS, 0x concurrency, ID 0x59A74D08D407B5EDF9A57DD5A41825CA at byte 0 # Scores: V/M = 0.00 # Time range: all events occurred at 2020-08-26T11:20:16 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 0 1 # Exec time 73 5s 5s 5s 5s 5s 0 5s # Lock time 0 0 0 0 0 0 0 0 # Rows sent 0 1 1 1 1 1 0 1 # Rows examine 0 0 0 0 0 0 0 0 # Query size 0 15 15 15 15 15 0 15 # String: # Hosts localhost # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # EXPLAIN /*!50100 PARTITIONS*/ select sleep(5)\G

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

Time range：查詢執行的時間范圍。注意，MySQL5.7版本中的時間格式不同于之 前的版本。 Attribute：如上述代碼段所示，表示Attribute列描述的Count、Exec time、Lock time等屬性名稱。 pct：表示該分組語句（這里指上述代碼段中“Query 1”代表的分組語句，具體的語 句樣本在EXPLAIN ...關鍵字下面有輸出。另外，在上述代碼段中，如total、min等計算值 都是針對該語句分組的，下文中不再贅述）的total值（該分組語句的統計值）與統計樣本 中總的所有語句統計值的占比。 total：表示Attribute列描述的Count、Exec time、Lock time等屬性的統計值。 min：表示Attribute列描述的Exec time、Lock time等屬性的最小值。 max：表示Attribute列描述的Exec time、Lock time等屬性的最大值。 avg：表示Attribute列描述的Exec time、Lock time等屬性的平均值。 95%：表示語句對應的Exec time、Lock time等屬性值從大到小排序之后，位于 95%位置的那個數值（需要重點關注這個值）。 stddev：標準偏差，用于數值的分布統計。 median：代表對應屬性值的中位數，將所有值從小到大排列，取位于中間的那個 數值。 Databases：庫名。 Users：各個用戶執行的次數（占比）。 Query_time distribution：查詢時間分布，由“#”字符表示的長短體現了語句執行時 間的占比區間。從上述代碼段中可以看到，執行時間在1s左右的查詢數量占絕大多數。 Tables：使用查詢語句中涉及的表生成的用于查詢表統計信息和表結構的SQL語 句文本。 EXPLAIN：表示查詢語句的樣本（方便復制出來查看執行計劃。注意，該語句不 是隨機生成的，而是分組語句中最差的查詢SQL語句）

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

優秀資料

參考資料來源：Mysql性能瓶頸深度定位分析

我們在性能測試過程中，經常會遇到Mysql出現性能瓶頸的情況，對于數據庫來說，所謂的性能瓶頸無非是慢SQL、CPU高、IO高、內存高，其中前三個舉實際例子來進行性能分析，最后內存高只是方法性說明（實際測試項目中沒遇到過）：

首先我們要保證沒有數據庫配置方面的性能問題，畢竟在性能測試前，對一些基本配置要擼一遍，避免犯低級錯誤。

慢SQL定位分析

首先業務系統慢，肯定是體現在響應時間上，所以在性能測試中，如果發現慢我們就從響應時間上進行拆分，最后拆到mysql，那就是分析慢SQL，同樣如果在高并發時發現mysql進程占CPU很高，也是優先分析是否存在慢SQL，而且判斷慢SQL還是比較簡單的，對于Mysql就是看慢日志查詢。

獲取到慢SQL，當然是要實際驗證一下有多慢，是否索引配置了，拿一條實際測試項目的SQL語句來分析：

explain SELECT count(c.id) FROM administrative_check_content c LEFT JOIN administrative_check_report_enforcers e ON c.report_id=e.report_id LEFT JOIN administrative_check_report r ON c.report_id = r.id WHERE e.enforcer_id= 'ec66d95c8c6d437b9e3a460f93f1a592';

1

2

3

4

5

可以分析出這條語句，86%的時間是花在了Sending data（所謂的“Sending data”并不是單純的發送數據，而是包括“收集 [檢索] + 發送數據”）：

用show profile進行sql分析：

開啟分析也很簡單，使用臨時開啟執行set profiling=1即可（這個功能會緩存最近查詢的分析語句，默認15條，最多100條，適合在壓測結束后開展sql分析，用完后再設成0關閉），如下：

#顯示是否開啟Profiling，以及最多存儲多少條 show variables like '%profil%'; #開啟Profiling set profiling=1; #執行你的SQL #在這里我們主要是執行前面所找到的慢SQL #查看分析 show profiles;

1

2

3

4

5

6

7

8

9

10

11

通過show profiles我們可以看到我們上面執行的那條SQL（Query_ID=18，為了確保監視最新的數據，Query_ID最好取25）

執行：show profile cpu,memory,block io for query 18;

可以看出也是Sending data總共消耗0.39秒，其中CPU_user時間占比較高（簡單的一條SQL語句消耗這些時間就算很高了），另外還能看到這條SQL的IO開銷（因為查詢，都是ops out塊輸出）

也可以通過SQL查表來查看以上記錄：

select QUERY_ID,SEQ,STATE,DURATION,CPU_USER,CPU_SYSTEM,BLOCK_OPS_IN,BLOCK_OPS_OUT from information_schema.PROFILING where QUERY_ID = 18

1

另外說明一下這個show profile語句：

show profile cpu, block io, memory,swaps,context switches,source for query [Query_ID]; # Show profile后面的一些參數： # - All：顯示所有的開銷信息 # - Cpu：顯示cpu相關開銷 # - Block io：顯示塊IO相關開銷 # - Context switches： 上下文切換相關開銷 # - Memory：顯示內存相關開銷 # - Source：顯示和source_function,source_file,source_line相關的開銷信息

1

2

3

4

5

6

7

8

9

哎，水了水了。

MySQL SQL

版權聲明：本文內容由網絡用戶投稿，版權歸原作者所有，本站不擁有其著作權，亦不承擔相應法律責任。如果您發現本站中有涉嫌抄襲或描述失實的內容，請聯系我們jiasou666@gmail.com 處理，核實后本網站將在24小時內刪除侵權內容。

版權聲明：本文內容由網絡用戶投稿，版權歸原作者所有，本站不擁有其著作權，亦不承擔相應法律責任。如果您發現本站中有涉嫌抄襲或描述失實的內容，請聯系我們jiasou666@gmail.com 處理，核實后本網站將在24小時內刪除侵權內容。