SQL - MySQL Server 日常維護: Log 分析(mysqlsla)

Admin1 · 2007-06-23, 11:14 AM

MySQL Server 日常維護: Log 分析(mysqlsla)

在之前的文章中已有提過如何利用 mysqlreport 這套工具來掌握 MySQL 目前的運作狀況(MySQL 效能監控工具--mysqlreport)，它可以協助我們瞭解 MySQL Server 的健康狀況以及 MySQL Server 大部份時間在處理什麼類型的 Query，但還有一個關鍵的問題沒有回答，就是在那些特定類型的 Query 中，MySQL 實際上到底是把 CPU 運算時間花在哪些 Query 上？若想要回答這個問題就必須要分析 MySQL 的 Log 才能得知。

大致上來說，MySQL 提供三大類的 LOG：

Binary Log：記錄所有對於資料庫的修改操作
General Log：記錄所有 Client 發送到 Server 的 Query
Slow Log：記錄所有的 Slow Query

藉由分析 General Log，我們可以清楚的得知 MySQL Server 最常執行的 Query 有哪些；觀察 Slow Log 則可以讓我們得知到底是哪些 Query 造成 MySQL Server 效能低落。知道了這些資訊以後我們才有辦法對 MySQL Server 進行進一步的調整與最佳化，例如以適當的 Index 提高 MySQL 最常執行的 Query 的效率，或是去除造成 Slow Query 的成因(poor index, join...等)。視您的 MySQL Server 的忙錄狀態而定，您的 General Log(或 Slow Log) 有可能會非常的龐大，要以肉眼來分析是一項不可能的任務，比較實際的作法是自己撰寫 Scripts 去進行 Log 分析。若您不想花時間自行開發程式，不妨試試由 Daniel Nichter 所提供的 mysqlsla。

官方網站： http://hackmysql.com/
軟體下載： http://hackmysql.com/mysqlsla

Log 分析步驟：

開啟 MySQL Server 的 General Log 與 Slow Log
以 mysqlsla 分析 Log 檔案
解讀報表

MySQL Server Log 分析

一、開啟 MySQL Server 的 General Log 與 Slow Log

要分析 Log 檔案之前，你當然要先有可以分析的 Log 檔案。要開啟 MySQL Server 的 General Log 與 Slow Log，需要修改 MySQL Server 的系統設定檔並重新啟動 MySQL。

引用:

/etc/my.cnf：
[mysqld]
log=general-log
log-slow-queries=slow-log

重新啟動 MySQL Server 後，您應該會在 MySQL 的 Data Dir 裡面發現 general-log 與 slow-log 這二個檔案。請注意，MySQL Server 的 General Log 與 Slow Log 預設不會進行 Logrotate，因此您要記得自己處理這個部份，不然的話只要你的 Server 夠忙錄， General Log 可能會用光你所有的硬碟空間。例如在 Linux 系統中可以在 /etc/logrotate.d 中加上 mysqld 檔案，內容為：

引用:

/var/log/mysqld.log /var/lib/mysql/general-log /var/lib/mysql/slow-log {
missingok
notifempty
sharedscripts
postrotate
/usr/bin/mysqladmin flush-logs
endscript
}

二、以 mysqlsla 分析 Log 檔案

mysqlsla 其實是一支 Perl Scripts，使用方式很間單，語法如下：

A. 分析 General Log

引用:

mysqlsla -u root -p --flat --general general-log

--flat: 表示分析 Query 的時候把它們全部轉為小寫，也就是說大小寫的差異不列入考量

--general：表示要分析的是 General Log

general-log：這裡要填入 general-log 檔案名稱，若有多個 Log 檔案請使用逗號分隔，例如 log1,log2...

所產生的範例報表如下：（mysqlsla 預設只會列出 Top 10 Query）

PHP 語法:

Reading general log 'general-log'. 1926707 total queries, 4085 unique. Sorting by 'c'. __ 001 _______________________________________________________________________ Count : 291423 (15%) Database : example Query 1..... __ 002 _______________________________________________________________________ Count : 271380 (14%) Database : example Query 2..... __ 003 _______________________________________________________________________ Count : 193304 (10%) Database : example Query 3..... __ 004 _______________________________________________________________________ Count : 172429 (9%) Database : example Query 4..... __ 005 _______________________________________________________________________ Count : 132067 (7%) Database : example Query 5..... __ 006 _______________________________________________________________________ Count : 112499 (6%) Database : example Query 6..... __ 007 _______________________________________________________________________ Count : 84409 (4%) Database : example Query 7..... __ 008 _______________________________________________________________________ Count : 65973 (3%) Database : example Query 8..... __ 009 _______________________________________________________________________ Count : 40396 (2%) Database : example Query 9..... __ 010 _______________________________________________________________________ Count : 38702 (2%) Database : example Query 10.....

然後您就可以大致上瞭解 Server 都在處理些什麼東西。

B. 分析 Slow Log

引用:

mysqlsla -u root -p --flat --slow --ex --db 資料庫名稱 slow-log

引用:

--flat: 表示分析 Query 的時候把它們全部轉為小寫，也就是說大小寫的差異不列入考量

--slow：表示要分析的是 Slow Log

--ex：使用 EXPLAIN 分析 Query

--db 資料庫名稱：Slow Log 不一定會記錄 Query 所屬的 Database，這樣一來當 Server 要進行 EXPLAIN 時會有問題，因此在這裡我們自己指定所使用的 Database。

slow-log：這裡要填入 slow-log 檔案名稱，若有多個 Log 檔案請使用逗號分隔，例如 log1,log2...。

所產生的範例報表如下：（mysqlsla 預設只會列出 Top 10 Query）

PHP 語法:

Reading slow log 'slow-log'. 160 total queries, 21 unique. Databases for Unknown: example Sorting by 't'. __ 001 _______________________________________________________________________ Count : 75 (46%) Time (seconds): 1449 total, 19.32 avg, 12 to 26 max 95% of Time : 1348 total, 18.99 avg, 12 to 25 max Lock (seconds): 445 total, 5.93 avg, 0 to 13 max Rows sent : 247 avg, 92 to 250 max Rows examined : 39787 avg, 27136 to 53228 max User : example[example]@localhost/ (76%) Database : example Rows (EXPLAIN): 24494 produced, 24494 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ref possible_keys: SAMPLE key: SAMPLE key_len: 4 ref: const,const rows: 24494 Extra: Using where; Using filesort Query1 .......... __ 002 _______________________________________________________________________ Count : 4 (2%) Time (seconds): 659 total, 164 avg, 164 to 166 max 95% of Time : 493 total, 164 avg, 164 to 165 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 53871729 avg, 53792839 to 53954842 max Rows examined : 53871729 avg, 53792839 to 53954842 max User : example[example]@localhost/ (23%) Database : example Rows (EXPLAIN): 54003520 produced, 54003520 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ALL possible_keys: key: key_len: ref: rows: 54003520 Extra: Query2 .......... __ 003 _______________________________________________________________________ Count : 30 (18%) Time (seconds): 412 total, 13.73 avg, 6 to 29 max 95% of Time : 355 total, 12.68 avg, 6 to 28 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 20475 avg, 3889 to 77241 max Rows examined : 20475 avg, 3889 to 77241 max User : example[example]@localhost/ (76%) Database : example Rows (EXPLAIN): 27060 produced, 27060 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ref possible_keys: SAMPLE key: SAMPLE key_len: 3 ref: const rows: 27060 Extra: Query3 .......... __ 004 _______________________________________________________________________ Count : 20 (12%) Time (seconds): 219 total, 10.95 avg, 10 to 12 max 95% of Time : 207 total, 10.89 avg, 10 to 12 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 0 avg, 0 to 1 max Rows examined : 1077422 avg, 1076385 to 1078557 max User : example[example]@localhost/ (23%) Database : example Rows (EXPLAIN): 1078830 produced, 3236490 read EXPLAIN : id: 1 select_type: PRIMARY table: SAMPLE type: index possible_keys: SAMPLE key: SAMPLE key_len: 8 ref: rows: 1078830 Extra: Using where; Using index; Using temporary; Using filesort id: 3 select_type: DEPENDENT SUBQUERY table: SAMPLE type: ref possible_keys: SAMPLE key: SAMPLE key_len: 2 ref: const rows: 1 Extra: Using where id: 2 select_type: DEPENDENT SUBQUERY table: SAMPLE type: unique_subquery possible_keys: PRIMARY,forumid key: PRIMARY key_len: 4 ref: func rows: 1 Extra: Using index; Using where Query4 .......... __ 005 _______________________________________________________________________ Count : 4 (2%) Time (seconds): 75 total, 18.75 avg, 16 to 22 max 95% of Time : 53 total, 17.67 avg, 16 to 19 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 1077174 avg, 1076128 to 1078321 max Rows examined : 1077174 avg, 1076128 to 1078321 max User : example[example]@localhost/ (23%) Database : example Rows (EXPLAIN): 1078830 produced, 1078830 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ALL possible_keys: key: key_len: ref: rows: 1078830 Extra: Query5 .......... __ 006 _______________________________________________________________________ Count : 4 (2%) Time (seconds): 40 total, 10 avg, 10 to 10 max 95% of Time : 30 total, 10.00 avg, 10 to 10 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 2207544 avg, 2205402 to 2209884 max Rows examined : 2207544 avg, 2205402 to 2209884 max User : example[example]@localhost/ (23%) Database : example Rows (EXPLAIN): 2211096 produced, 2211096 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ALL possible_keys: key: key_len: ref: rows: 2211096 Extra: Query6 .......... __ 007 _______________________________________________________________________ Count : 4 (2%) Time (seconds): 36 total, 9 avg, 9 to 9 max 95% of Time : 27 total, 9.00 avg, 9 to 9 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 0 avg, 0 to 0 max Rows examined : 1827 avg, 1826 to 1828 max User : example[example]@localhost/ (23%) Database : example Rows (EXPLAIN): 3656396 produced, 3658344 read EXPLAIN : id: 1 select_type: PRIMARY table: SAMPLE type: ref possible_keys: SAMPLE key: SAMPLE key_len: 2 ref: const rows: 1948 Extra: Using where id: 2 select_type: DEPENDENT SUBQUERY table: SAMPLE type: ref possible_keys: SAMPLE key: award_id key_len: 2 ref: const rows: 1877 Extra: Using where Query7 .......... __ 008 _______________________________________________________________________ Count : 2 (1%) Time (seconds): 36 total, 18 avg, 13 to 23 max 95% of Time : 13 total, 13.00 avg, 13 to 13 max Lock (seconds): 6 total, 3 avg, 1 to 5 max Rows sent : 250 avg, 250 to 250 max Rows examined : 45386 avg, 40636 to 50136 max User : example[example]@localhost/ (76%) Database : example Rows (EXPLAIN): 24494 produced, 24494 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ref possible_keys: SAMPLE key: SAMPLE key_len: 4 ref: const,const rows: 24494 Extra: Using where; Using filesort Query8 .......... __ 009 _______________________________________________________________________ Count : 3 (1%) Time (seconds): 30 total, 10 avg, 6 to 12 max 95% of Time : 18 total, 9.00 avg, 6 to 12 max Lock (seconds): 1 total, 0.33 avg, 0 to 1 max Rows sent : 0 avg, 0 to 0 max Rows examined : 0 avg, 0 to 0 max User : example[example]@localhost/ (76%) Database : Unknown Rows (EXPLAIN): EXPLAIN error: Not a SELECT statement. EXPLAIN : EXPLAIN error: Not a SELECT statement. Query9 .......... __ 010 _______________________________________________________________________ Count : 3 (1%) Time (seconds): 21 total, 7 avg, 6 to 8 max 95% of Time : 13 total, 6.50 avg, 6 to 7 max Lock (seconds): 0 total, 0 avg, 0 to 0 max Rows sent : 143522 avg, 121334 to 187844 max Rows examined : 143522 avg, 121334 to 187844 max User : example[example]@localhost/ (76%) Database : example Rows (EXPLAIN): 141085 produced, 141085 read EXPLAIN : id: 1 select_type: SIMPLE table: SAMPLE type: ref possible_keys: SAMPLE key: SAMPLE key_len: 3 ref: const rows: 141085 Extra: Using index Query10 ..........

有了這些資訊後，下一步就是要進行 Query 的最佳化，與 Server 系統參數的調校。

Google 提供的廣告