程序師世界是廣大編程愛好者互助、分享、學習的平台,程序師世界有你更精彩!
首頁
編程語言
C語言|JAVA編程
Python編程
網頁編程
ASP編程|PHP編程
JSP編程
數據庫知識
MYSQL數據庫|SqlServer數據庫
Oracle數據庫|DB2數據庫
 程式師世界 >> 數據庫知識 >> MYSQL數據庫 >> 關於MYSQL數據庫 >> MySQL程序剖析

MySQL程序剖析

編輯:關於MYSQL數據庫

我們將要詳細的講到MySQL的剖析(Profiling),因為它很少依賴於你的應用。應用和服務器級別的剖析有的時候都是有必要的。雖然應用級別的剖析可以給你整個應用性能的總攬。,但是對MySQL的剖析提供了信息是服務器級別所提供不了的。比如,對PHP代碼進行剖析不會顯示MySQL有多少行語句執行了。

與應用剖析一樣,目標是找出MySQL哪部分消耗過多的時間。我們不會剖析MySQL源碼的,雖然有的時候定制化MySQL安裝很有用,但是這是另一本書的主題了。所替代的是,我們將教你一些可以技術來獲取和分析不同種類的MySQL執行語句的信息。

你可以用在任意的顆粒級別以滿足你的需求:你可能對整個服務器進行剖析或者單獨檢查一個語句或者一組語句。下列信息你可以一點點的收集:

  • MySQL經常訪問的那些數據
  • MySQL經常執行語句的類型
  • MySQL線程大部分時間的狀態
  • MySQL經常執行語句的子系統
  • MySQL執行語句所訪問的數據類型
  • 不同活動的類型,比如掃描索引。
我們先從范圍最廣的剖析開始,那就是服務器剖析,將教你更多細節。記錄執行的語句

MySQL有兩種記錄語句的類型:general log和slow log。他們都是記錄執行語句,但是卻在語句執行進程的兩端。general log記錄了每個服務器收到的語句,因此它的語句可能包含了那些沒有執行導致錯誤的語句。general Log記錄了所有的語句,包括了一些非執行語句的事件,比如連接和斷開連接。你可以用一個指令來啟用它。

log = <file_name>

根據設計,general log不會包括執行時間和其他一些僅僅在語句執行完畢的信息。相比較而言,slow log記錄執行完畢的語句。尤其是,它記錄那些超過指定時間執行的語句。這兩種日志都對程序剖析很有用,但是slow log是獲取問題語句的主要工具。我們常常推薦把它開啟。

下面列出的配置會開啟這個日志。獲取所有執行時間超過2s的語句,以及記錄那些不使用索引的語句。它也會記錄一些執行慢的管理語句,比如OPTIMIZE TABLE:

log-slow-querIEs = <file_name>

long_query_time = 2

log-querIEs-not-using-indexes

log-slow-admin-statements

你可以自定義這些配置,然後把它們放到my.conf文件中。更多的服務器配置將在以後的章節詳細講述。

long_query_time的默認值是10s。這個設置太慢了,因此我們一般都設置它為2s。然而,對於許多應用,可能1s都非常慢了。我們在下一部分將講述如何獲得顆粒度更細的日志。

在MySQL5.1中,提供了運行時調整slow_query_log,slow_query_log_file參數來控制slow log.但是在MySQL5.0中,在不啟動MySQL的情況下,不能開閉slow log。對於MySQL5.0的變通方法是,可以動態的修改long_query_time變量。下面的語句雖然不是真正開啟slow log的方式,但是取得了同樣的效果。(如果有語句執行超過了10000s,那麼你需要優化了這些語句了)

MySQL> SET GLOBAL long_query_time = 10000;

相關配置變量,log_querIEs_not_using_indexes 使服務器記錄沒有使用索引的語句。而不管它們的執行時間。雖然開啟了slow log會增加一些時間的消耗,導致語句執行速度減慢,但是沒有使用索引的語句還是可以經常和非常快速的執行。(比如一些查詢一些數據量小的表)這樣會使降低服務器的速度,以及使用大量的硬盤空間保存日志。

不幸的是,在MySQL5.0中不能動態的開啟或關閉日志。你必須修改MySQL配置文件,然後重啟MySQL。當你想關閉日志而不想重啟服務器,可以把日志文件做一個/dev/null的指向。在確定了MySQL關閉了日志文件描述以及在/dev/null重新打開它,那麼你僅執行FLUSH LOGS就可以了。

相比較而言,MySQL5.1能實時更改日志以及能把日志記錄到表中。這是個很大的進步了。

細顆粒度的日志

MySQL5.0以及更早的版本的slow log 都有一定的限制,在一些用途下就沒用了。最首要的問題就是它的顆粒度僅僅是秒。以及long_query_time在MySQL5.0中最小單位就是1s。大部分交互的應用中,這個時間就比較長了。如果你正在開發一個高性能的WEB應用,你可能希望整個頁面生成小於1s.以及在開始生成的過程中記錄許多語句。這種情況下,一個語句執行了150ms,也會被認為是個很慢的語句。

另一個問題是,並不是所有的執行語句都記錄在slow log中(尤其是,子節點的線程語句不能被記錄)。general log記錄了所有的語句,但是是在這些語句解析之前記錄的,只要就不能記錄一些如執行時間,鎖時間,以及執行的行數的記錄了。只有slow log包含這些信息。

最終,如果你開啟了log_querIEs_not_using_indexes參數。可能slow log就被大量的實體,高效的語句所填滿。比如,如果你過你生成一個下拉菜單的數據,你可能執行SELECT * FROM STATES。這個語句就被記錄了,因為它是整張表的掃描。

當程序剖析的目標是性能優化,你應該查看讓MySQL服務器大量工作的語句。這並不是意味著總是執行慢的語句。所以記錄執行慢的語句可能也沒什麼用處了。一個例子,一個10ms的語句在一秒內執行了1000次對服務器的壓力高於10s語句每秒運行一次。為了發現這個問題,你必須記錄每條語句和分析結果。

一起查看執行慢的語句和導致服務器壓力過大的語句執行總量是非常有用的方法。這會讓你發現不同的問題。如一個語句導致了很差的用戶體驗。

我們已經開發了一個MySQL的補丁。基於Georg Richter工作之上而開發的。讓你指定slow log語句時間到毫秒級別,而不是原來的秒。通過設置long_query_time=0,它也能讓你記錄所有的語句。這個補丁的地址是http://www.mysqlperformanceblog.com/mysql-patches/。它的主要缺點就是你需要自己編譯MySQL。因為這個補丁在MySQL5.1之前並沒有包含在MySQL發行包中。

目前,MySQL5.1包含了這個補丁,但僅能修改時間的顆粒度。這個補丁的新版本,將不會包含在MySQL的發行包中。新版本將添加一些有用的功能。這些功能包含了語句執行的連接ID,也包含了語句執行的緩存,連接類型,臨時表,以及排序。也添加了InnoDB的統計,比如I/O行為以及鎖等待。

新版本的補丁可以記錄子節點所執行的語句。如果在子節點復制的過程中出現問題,這個功能就尤其有用。它也能讓你選擇一些會話的日志。這些功能對程序剖析來說已經足夠了,我們認為這就是最佳實踐了。

這個補丁是比較新的,因此如果你要應用,要小心的使用它。我們想它已經很安全了,但是它在其他的MySQL服務器還沒有經過足夠的考驗。如果你擔心這個還有補丁的MySQL服務器的穩定性,你不一定要一直運行它,你可以先運行它幾個小時記錄一些語句,然後在恢復你自己的MySQL版本。

當程序剖析的時候,把參數long_query_time=0記錄所有語句是個很好的方法。如果大部分的讀取來自於非常簡單的語句,你可能想知道這些情況。記錄所有語句會影響一些性能以及它要求更多的硬盤空間-這就是另一個不需要記錄所有語句的理由。幸運的是,你可以隨時修改long_query_time而不用去重新啟動服務器。因此很容易在一段時間內獲取所有語句。然後在恢復記錄那些執行比較慢的語句。

怎樣讀取slow log

這是一個slow log的例子

1 # Time: 030303 0:51:27

2 # User@Host: root[root] @ localhost []

3 # Query_time: 25 Lock_time: 0 Rows_sent: 3949 Rows_examined: 378036

4 SELECT ...

第一行顯示了日志記錄的時間,第二行顯示誰執行了這些語句。第三行顯示這語句執行的時間,在MySQL服務器級別等待表鎖的時間,執行語句返回的行數,以及語句檢索的行數。這些語句都是被注視掉的。因此如果你把日志提供給MySQL ClIEnt,他們也不會執行。最後一行就是執行的語句。

這個例子是MySQL5.1版本的

1 # Time: 070518 9:47:00

2 # User@Host: root[root] @ localhost []

3 # Query_time: 0.000652 Lock_time: 0.000109 Rows_sent: 1 Rows_examined: 1

4 SELECT ...

和上個日志基本相同,除了第三行,精度變得更高了。上一部分我們提到的補丁提供了更全面的信息

1 # Time: 071031 20:03:16

2 # User@Host: root[root] @ localhost []

3 # Thread_id: 4

4 # Query_time: 0.503016 Lock_time: 0.000048 Rows_sent: 56 Rows_examined: 1113

5 # QC_Hit: No Full_scan: No Full_join: No Tmp_table: Yes Disk_tmp_table: No

6 # Filesort: Yes Disk_filesort: No Merge_passes: 0

7 # InnoDB_IO_r_ops: 19 InnoDB_IO_r_bytes: 311296 InnoDB_IO_r_wait: 0.382176

8 # InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.067538

9 # InnoDB_pages_distinct: 20

10 SELECT ...

第五行顯示了這個語句是否使用了緩存,是否檢索了整張表,是否沒有用索引進行表連接,是否是否臨時表,以及臨時表是否創建在硬盤上。第六行給出了是否進行了文件排序以及,如果是,是否保存到硬盤上以及有多少合並排序通過它執行的。

如果語句執行在InnoDB上,第7,8,9行就會顯示。第7行顯示了在執行語句的時候,InnoDB計劃讀取的頁數,與它一起的是byte數值。第7行最後的一個值是InnoDB從硬盤讀取數據的時間。第8行顯示了語句等待行鎖以及用了多少時間等待進入InnoDB內核。

第9行顯示了語句訪問唯一InnoDB大約的頁面數。這個數值越大,准確度貌似就越低了。這個信息的一種用處就是估計在頁面中語句的工作集。這個就是InnoDB緩沖池緩存數據的方式。它也能顯示你的集群索引是非常的有用。如果這個語句的行很好的集群索引了,它們會填充更少的頁面。以後會講到集群索引。

使用slow log去解決慢語句並不總是很簡單。雖然log包含了很多有用的信息,但是一個非常重要的信息卻丟失了:那就是語句執行為什麼會這麼慢的一個想法。有的時候,這是顯而易見的。如果log得出了12,000,000行被檢查以及1,200,000被發送到了客戶端,你知道為什麼這麼慢的原因了--這是個很大的執行語句。然而,這是很難的的清晰。

要注意的是,不要給slow log添加過多的含義。如果你看到一條語句在log中出現多次,那就發現了這語句很慢以及需要優化。但是僅僅因為一個語句在log出現的頻率並不意味著它是個糟糕的語句或者甚至並不是緩慢的。你可能找到了一個很慢的語句,運行它,以及發現它執行的時間只是一眨眼的時間。出現在日志中只能說明在過去的那個時候這個語句執行時間很長,並不意味著現在或以後它會執行很長時間。一個語句有的時候很慢,在另外的時間卻很快,這種情況原因是很多的:

  • 一個表可能被鎖定了,導致了語句必須去等待。Lock_time指明了這個語句等待鎖釋放的時間。
  • 數據或者索引沒有被緩存。在MySQL剛啟動的時候或還沒有調整好的情況下,這種問題很常見。
  • 可能是備份正在執行,導致了硬盤I/O很慢。
  • 這個服務器同時還運行著其他語句,導致了這個語句很慢。
因此,你查看slow log應該把它作為部分數據來看。你可以使用它創建一個可疑語句的列表,但是你需要更深層次的分析每一項。 slow log補丁的出現幫助你理解為什麼語句執行會很慢。尤其在你使用InnoDB的時候,InnoDB統計信息能帶給我們更多的信息:你可以查看語句執行是否在等待硬盤的I/O,InnoDB隊列中它是否在花費大量的時間去等待,以及等等其他的信息。日志分析工具

現在你已經記錄了一些執行的語句了。是時候分析結果了。一般的策略是找出對服務器影響最大的語句,用Explain檢查它們執行計劃進行必要的調整。在調整之後不斷地重復這個過程。因為你的修改可能會影響其他語句的執行。比較常見的就是索引可以提高SELECT的速度但是會降低INSERT或UPDATE語句。

一般來說你應該在日志中查找如下的執行語句:

  • Long querIEs(運行時間長的語句):固定時間的批量任務使語句執行緩慢,但是正常的語句不應該執行的很慢。
  • High-impact querIEs(影響大的語句):找出那些占用服務器執行大部分時間的語句。還記得上一部分說過的執行時間短的語句占用了很多時間。
  • new querIEs(新出現的語句):找出那些昨天還沒有在前100個,但是今天卻出現的語句。這些語句可能是新出現的也可能是被很快的運行以及正在變得糟糕。可能因為不同的索引或者其他別的什麼改變。如果的slow log記錄的數據很少,那麼可以去手工去處理,但是你如果記錄了所有的執行語句(這是我們所推薦的),那麼你就需要一個工具去幫助你了。下列的工具你能用的上。 mysqldumpslow:這是MySQL本身提供的mysqldumpslow。這個是個Perl腳本能總結slow log以及每個執行語句在log中出現的次數。有這個方法你就不會浪費時間優化一個一天,才執行一次的30s慢語句。而去優化那些看起來很快的語句,但是每天卻執行了上千次。mysqldumpslow的優勢是它是默認安裝的,缺點是相對於其他工具靈活性不足。它的文檔也不是很全,以及它也不能分析我們以前介紹過得那個low log補丁生成的log。 mysql_slow_log_filter:下載地址http://www.mysqlperformanceblog.com/files/utils/mysql_slow_log_filter,這個工具可以解析精確度為ms的log.你可以提取那些執行時間高於指定時間的語句或者檢查給定的行數。這個工具是對slow log補丁的很好補充。你可以設置一個高的臨界值去優化語句,直到這個語句效率提高。然後在改變參數獲得更多的執行語句繼續調整。以下命令的意思就是,顯示那些執行超過0.5s以及檢查超過1000行的語句。 $ tail -f mysql-slow.log | MySQL_slow_log_filter -T 0.5 -R 1000 MySQL_slow_log_parser: 這是另一個工具,地址為:http://www.mysqlperformanceblog.com/files/utils/MySQL_slow_log_parser,這款工具可以聚合slow log信息。除了聚合和報表,它也顯示了執行時間和分析的行數的最大和最小值。打印一個“標准化”的執行語句,以及打印一個你可以EXPAIN的語句。下面是個簡單輸出 ### 3579 QuerIEs ### Total time: 3.348823, Average time: 0.000935686784017883 ### Taking 0.000269 to 0.130820 seconds to complete ### Rows analyzed 1 - 1 SELECT id FROM forum WHERE id=XXX; SELECT id FROM forum WHERE id=12345; MySQLsla: MySQL Statement Log Analyzer.地址如下:http://hackmysql.com/ 它不僅僅能分析slow log也能分析general log和"raw" log(這個log是把SQL語句用分隔符分開的log).想MySQL_slow_log_parser一樣。它能標准化和進行匯總。它也能EXPLAIN語句(它對許多非查詢語句進行了重寫)以及生成復雜的報表。你可以使用slow log的統計信息去預測下你將會降低多少服務器系統資源的消耗。假設你抽樣執行語句1個小時。發現總和的語句執行時間是10000s(總的時間是超過時鐘時間的,因為語句執行是並行的)。如果日志分析一個最差的語句執行了3000s,你會知道它占了整個讀取的30%。現在你就知道通過優化這個語句你可以降低服務器多少資源消耗了。
    1. 上一頁:
    2. 下一頁:
    Copyright © 程式師世界 All Rights Reserved