欧美一区二区三区老妇人-欧美做爰猛烈大尺度电-99久久夜色精品国产亚洲a-亚洲福利视频一区二区

詳解MySQL慢日志（上）query_time\start_time\lock_time的坑


詳解MySQL慢日志（下） 選項(xiàng) 參數(shù)篇：
 http://blog.itpub.net/29773961/viewspace-2147352/


〇 long_query_time
場(chǎng)景：
如下圖，該圖為部分 binlog截取：
9：42：25 后，還有幾個(gè)6：35：30的event
詳解MySQL慢日志（上）query_time\start_time\lock_time 的坑

但是這些event如圖中最后一條。
exec_time為11216，但并未被記錄到slow log中。

long_query_time 為一個(gè)MySQL選項(xiàng)參數(shù)。
這個(gè)參數(shù)不用說(shuō)了，記錄超過(guò)執(zhí)行時(shí)間超過(guò)該值以上的SQL。
但這個(gè)坑在于：是按真正執(zhí)行的時(shí)間（real time），不包括等待鎖的時(shí)間。

舉個(gè)簡(jiǎn)單的例子：
如果long_query_time設(shè)置為1秒
一個(gè)insert被lock了10秒，執(zhí)行只耗了0.5秒，那么不會(huì)被記錄到慢日志。 測(cè)試，以下分為三個(gè)會(huì)話，分別被命名為 lock>， query>， slow_log>，下同：

目前創(chuàng)新互聯(lián)公司已為上千家的企業(yè)提供了網(wǎng)站建設(shè)、域名、雅安服務(wù)器托管、網(wǎng)站托管維護(hù)、企業(yè)網(wǎng)站設(shè)計(jì)、富順網(wǎng)站維護(hù)等服務(wù)，公司將堅(jiān)持客戶導(dǎo)向、應(yīng)用為本的策略，正道將秉承"和諧、參與、激情"的文化，與客戶和合作伙伴齊心協(xié)力一起成長(zhǎng)，共同發(fā)展。


  1. lock > FLUSH TABLE WITH READ LOCK ;
  2. Query OK , 0 rows affected ( 0 . 00 sec )

  4. query > SET profiling = 1 ,  SESSION long_query_time = 0 . 5 ;
  5. Query OK , 0 rows affected , 1 warning ( 0 . 00 sec )


  8. query > INSERT INTO t0 SELECT null , create_time , uuid FROM t1 LIMIT 1 ;
  9. { 此時(shí)hang住 }

  11. lock > UNLOCK TABLE ;

  13. query > { 返回 }
  14. Query OK , 1 row affected ( 9 . 42 sec )
  15. Records: 1  Duplicates: 0  Warnings: 0

此處看到，整條SQL花費(fèi)了9.42秒完成，其中包括長(zhǎng)時(shí)間的鎖等待。



再看一下具體的profile：

  1. query > SHOW PROFILES ;
  2. + - - - - - - - - - - + - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  3. | Query_ID | Duration    | Query                                                                     |
  4. + - - - - - - - - - - + - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  5. | 1          | 9 . 41687900 | INSERT INTO t0 SELECT null , create_time , uuid FROM t1 LIMIT 1 |
  6. + - - - - - - - - - - + - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  7. 1 row in set , 1 warning ( 0 . 00 sec )

  9. query > SHOW PROFILE FOR QUERY 1 ;
  10. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - +
  11. | Status                          | Duration |
  12. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - +
  13. | starting                          | 0 . 000101 |
  14. | checking permissions         | 0 . 000009 |
  15. | checking permissions            | 0 . 000005 |
  16. | Opening tables                 | 0 . 000016 |
  17. | Waiting for global read lock | 9 . 412835 |
  18. | Opening tables                 | 0 . 000540 |
  19. | init                             | 0 . 000033 |
  20. | System lock                    | 0 . 000014 |
  21. | optimizing                      | 0 . 000006 |
  22. | statistics                      | 0 . 000020 |
  23. | preparing                       | 0 . 000016 |
  24. | executing                        | 0 . 000004 |
  25. | Sending data                     | 0 . 000241 |
  26. | end                                   | 0 . 000006 |
  27. | query end                        | 0 . 002504 |
  28. | closing tables                 | 0 . 000012 |
  29. | freeing items                     | 0 . 000025 |
  30. | logging slow query            | 0 . 000009 |
  31. | Opening tables                     | 0 . 000113 |
  32. | System lock                     | 0 . 000362 |
  33. | cleaning up                         | 0 . 000011 |
  34. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - +
  35. 21 rows in set , 1 warning ( 0 . 00 sec )

可以看到，等待全局讀鎖花了9.412835s，總執(zhí)行時(shí)間約為9.42。

再在slow_log表中查一下……什么都沒(méi)有：

  1. slow_log > SELECT start_time , query_time , lock_time , sql_text FROM mysql . slow_log ;
  2. Empty set ( 0 . 00 sec )


  1. query > SELECT 9 . 41687900-9 . 412835 ;
  2. + - - - - - - - - - - - - - - - - - - - - - +
  3. | 9 . 41687900-9 . 412835 |
  4. + - - - - - - - - - - - - - - - - - - - - - +
  5. | 0 . 00404400           |
  6. + - - - - - - - - - - - - - - - - - - - - - +
  7. 1 row in set ( 0 . 00 sec )


tips：
此時(shí)SQL執(zhí)行時(shí)間為0.00404400s，故沒(méi)有被記錄到slow log中。
也可以解釋圖中，某些event執(zhí)行了3個(gè)小時(shí)，但又無(wú)法在slow log中查詢到。




〇 lock_time與query_time
為slow log中所記錄的兩個(gè)屬性：
lock_time：waiting for xxx lock的時(shí)間
query_time：real time + lock time的總時(shí)間

  1. query > SET SESSION long_query_time = 0 ;
  2. Query OK , 0 rows affected ( 0 . 00 sec )

  4. lock > LOCK TABLE test . t0 WRITE ;
  5. Query OK , 0 rows affected ( 0 . 00 sec )

  7. query > SELECT * FROM t0 LIMIT 1 ;
  8. { 此時(shí)hang住 }

  10. lock > LOCK TABLE test . t0 WRITE ;
  11. Query OK , 0 rows affected ( 0 . 00 sec )

  13. query > { 返回 }
  14. + - - - - + - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  15. | id | create_time          | uuid                                          |
  16. + - - - - + - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  17. | 2   | 2017-11-14 15:13:33 | 994e4592-93b4-11e7-bff9-525400b3819a |
  18. + - - - - + - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  19. 1 row in set ( 28 . 89 sec )

  21. slow_log > SELECT start_time , query_time , lock_time , sql_text FROM mysql . slow_log ;
  22. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  23. | start_time                   | query_time        | lock_time       | sql_text                                |
  24. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  25. | 2017-11-15 17:13:12 . 252836 | 00:00:28 . 894675 | 00:00:28 . 894516 | SELECT * FROM t0 LIMIT 1           |
  26. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +

可以看到做一個(gè)簡(jiǎn)單查詢，query_time也很長(zhǎng)：
實(shí)際上query_time記錄的是lock_time + real time。
query_time ≥ lock_time

〇 start_time
為slow log中所記錄的屬性：
start_time：看字面意思很容易會(huì)被誤認(rèn)為“sql開(kāi)始的時(shí)間”…
但實(shí)際上記錄的是sql結(jié)束的時(shí)間。 測(cè)試一下：

  1. query > SET SESSION long_query_time = 0 ;
  2. Query OK , 0 rows affected ( 0 . 00 sec )

  4. query > SELECT sysdate ( ) , sleep ( 8 ) , sysdate ( ) ;
  5. + - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - +
  6. | sysdate ( )           | sleep ( 8 ) | sysdate ( )               |
  7. + - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - +
  8. | 2017-11-15 17:05:15 | 0         | 2017-11-15 17:05:23 |
  9. + - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - +
  10. 1 row in set ( 8 . 00 sec )


可以看到，該sql開(kāi)始時(shí)間是17:05:15，結(jié)束時(shí)間是17:05:23
那么記錄在slow log中，實(shí)際上是：

  1. slow_log > SELECT start_time , query_time , lock_time , sql_text FROM mysql . slow_log ;
  2. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  3. | start_time                  | query_time       | lock_time        | sql_text                               |
  4. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  5. | 2017-11-15 17:05:23 . 633771 | 00:00:08 . 000359 | 00:00:00 . 000000 | SELECT sysdate ( ) , sleep ( 8 ) , sysdate ( )   |
  6. + - - - - - - - - - - - - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
  7. 1 row in set ( 0 . 00 sec )


可以看到，start_time實(shí)際上是sql執(zhí)行完成的時(shí)間。
真正的開(kāi)始時(shí)間計(jì)算的方法也很簡(jiǎn)單：
start_time - query_time 即為sql真正開(kāi)始的時(shí)間。


tips：
一般OLTP場(chǎng)景下，大部分query_time都會(huì)很短。
但在某些糟糕的場(chǎng)景下，如某一條OLAP語(yǔ)句執(zhí)行時(shí)間很長(zhǎng)，如30分鐘。
如果需要確認(rèn)在某個(gè)時(shí)段的sql，在查詢slow log時(shí)指定錯(cuò)誤的start_time，可能就無(wú)法找到合適的sql了。
作者微信公眾號(hào)（持續(xù)更新）
詳解MySQL慢日志（上）query_time\start_time\lock_time 的坑

文章名稱：詳解MySQL慢日志（上）query_time\start_time\lock_time的坑
轉(zhuǎn)載注明：http://chinadenli.net/article30/jgggso.html

成都網(wǎng)站建設(shè)公司_創(chuàng)新互聯(lián)，為您提供全網(wǎng)營(yíng)銷推廣、網(wǎng)站導(dǎo)航、移動(dòng)網(wǎng)站建設(shè)、標(biāo)簽優(yōu)化、、定制開(kāi)發(fā)

廣告

聲明：本網(wǎng)站發(fā)布的內(nèi)容（圖片、視頻和文字）以用戶投稿、用戶轉(zhuǎn)載內(nèi)容為主，如果涉及侵權(quán)請(qǐng)盡快告知，我們將會(huì)在第一時(shí)間刪除。文章觀點(diǎn)不代表本網(wǎng)站立場(chǎng)，如需處理請(qǐng)聯(lián)系客服。電話：028-86922220；郵箱：631063699@qq.com。內(nèi)容未經(jīng)允許不得轉(zhuǎn)載，或轉(zhuǎn)載時(shí)需注明來(lái)源： 創(chuàng)新互聯(lián)

成都做網(wǎng)站
日韩视频在线观看成人| 在线免费国产一区二区| 视频在线播放你懂的一区| 清纯少妇被捅到高潮免费观看| 中文字幕在线区中文色 | 国产又粗又猛又爽色噜噜| 欧美人妻免费一区二区三区| 亚洲熟妇中文字幕五十路| 久久这里只有精品中文字幕| 国内精品美女福利av在线| 国产日本欧美韩国在线| 久久老熟女一区二区三区福利| 熟妇久久人妻中文字幕| 国产精品香蕉在线的人| 黑人巨大精品欧美一区二区区| 国产精品午夜福利免费在线| 婷婷色网视频在线播放| 99久久精品免费精品国产| 欧美一区二区三区不卡高清视| 成人午夜视频精品一区| 美国女大兵激情豪放视频播放 | 日韩欧美精品一区二区三区| 国产真人无遮挡免费视频一区| 欧美性高清一区二区三区视频 | 精品国产亚洲区久久露脸| 国产自拍欧美日韩在线观看| 成人精品日韩专区在线观看| 国产免费黄片一区二区| 在线九月婷婷丁香伊人| 不卡中文字幕在线免费看| 二区久久久国产av色| 日本加勒比系列在线播放| 中文字幕欧美视频二区| 黄片免费在线观看日韩| 91麻豆视频国产一区二区| 久久福利视频视频一区二区| 日韩高清中文字幕亚洲| 久久热中文字幕在线视频| 欧美日韩一区二区三区色拉拉| 人妻偷人精品一区二区三区不卡| 成人午夜激情在线免费观看|