開發人員MySQL調優-實戰篇3-profile日誌和鎖

時間 2019-11-12

原文原文鏈接

profile日誌分析

經過使用explain命令查看執行計劃，並對SQL調優後，若是還想對SQL執行過程更詳細的瞭解，查找慢更底層的緣由，可使用profile分析。html

打開日誌記錄

先查看profile配置mysql

mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | OFF   |
+---------------+-------+
1 row in set

在當前會話中打開profile配置sql

mysql> set profiling=on;
Query OK, 0 rows affected

執行幾個SQL數據庫

select count(1) from tb_v_user;
select count(1) from tb_v_user;
select user_id,count(1) from tb_vote group by user_id;

看profile信息併發

mysql> show profiles;
+----------+------------+-------------------------------------------------------+
| Query_ID | Duration   | Query                                                 |
+----------+------------+-------------------------------------------------------+
|        1 |  0.2433095 | select count(1) from tb_v_user                        |
|        2 | 0.00085075 | unlock tables                                         |
|        3 |   0.114828 | select count(1) from tb_v_user                        |
|        4 |  0.1181025 | select count(1) from tb_v_user                        |
|        5 | 0.11777725 | select count(1) from tb_v_user                        |
|        6 |   4.482654 | select user_id,count(1) from tb_vote group by user_id |
+----------+------------+-------------------------------------------------------+
6 rows in set

Query_ID：收集到的執行SQL的序列號，後面指定要分析那一條SQL時候須要用到這個值高併發

Duration：執行SQL耗時oop

Query：SQL測試

分析日誌記錄

先使用以下命令參數。不知道爲何這個命令在navicat中不能識別，我是登陸到虛擬機中打開mysql客戶端執行的優化

mysql> ? show profile
Name: 'SHOW PROFILE'
Description:
Syntax:
SHOW PROFILE [type [, type] ... ]
    [FOR QUERY n]
    [LIMIT row_count [OFFSET offset]]

type:
    ALL
  | BLOCK IO
  | CONTEXT SWITCHES
  | CPU
  | IPC
  | MEMORY
  | PAGE FAULTS
  | SOURCE
  | SWAPS

type列出來了不少，但我通常就看看CPU和BLOCK IO，若是經過這兩項看不出什麼問題，能夠再挨個查看一下spa

若是你想看全部的信息，那麼能夠這樣寫

show profile all for query 1

查看上面日誌收集到的第一條sql的全部執行過程信息（步驟、耗時），返回的列會很是多，我就不貼出來了。

查看一下執行慢的SQL(ID=6)好比：

show profile CPU,BLOCK IO for query 6

mysql> show profile CPU,BLOCK IO for query 6;
+---------------------------+----------+----------+------------+--------------+---------------+
| Status                    | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+---------------------------+----------+----------+------------+--------------+---------------+
| starting                  | 0.000101 | NULL     | NULL       | NULL         | NULL          |
| checking permissions      | 6E-6     | NULL     | NULL       | NULL         | NULL          |
| Opening tables            | 0.004756 | NULL     | NULL       | NULL         | NULL          |
| init                      | 3.9E-5   | NULL     | NULL       | NULL         | NULL          |
| System lock               | 7E-6     | NULL     | NULL       | NULL         | NULL          |
| optimizing                | 3E-6     | NULL     | NULL       | NULL         | NULL          |
| statistics                | 4.7E-5   | NULL     | NULL       | NULL         | NULL          |
| preparing                 | 2.6E-5   | NULL     | NULL       | NULL         | NULL          |
| Creating tmp table        | 6.2E-5   | NULL     | NULL       | NULL         | NULL          |
| Sorting result            | 3E-6     | NULL     | NULL       | NULL         | NULL          |
| executing                 | 1E-6     | NULL     | NULL       | NULL         | NULL          |
| Sending data              | 0.797651 | NULL     | NULL       | NULL         | NULL          |
| converting HEAP to MyISAM | 0.762739 | NULL     | NULL       | NULL         | NULL          |
| Sending data              | 1.574018 | NULL     | NULL       | NULL         | NULL          |
| Creating sort index       | 1.333006 | NULL     | NULL       | NULL         | NULL          |
| end                       | 7E-6     | NULL     | NULL       | NULL         | NULL          |
| removing tmp table        | 0.009357 | NULL     | NULL       | NULL         | NULL          |
| end                       | 8E-6     | NULL     | NULL       | NULL         | NULL          |
| query end                 | 6E-6     | NULL     | NULL       | NULL         | NULL          |
| closing tables            | 1E-5     | NULL     | NULL       | NULL         | NULL          |
| freeing items             | 0.000784 | NULL     | NULL       | NULL         | NULL          |
| cleaning up               | 1.9E-5   | NULL     | NULL       | NULL         | NULL          |
+---------------------------+----------+----------+------------+--------------+---------------+
22 rows in set

下圖是它的執行計劃（說明一下：這個SQL只是爲了測試慢，實際狀況下除非腦殼短路纔會對unique的列作group by ）

執行計劃告訴我：使用了臨時表和文件排序

那麼對於上面的profile都是些是什麼喃？他們就是下面截取這一段

| Creating tmp table        | 6.2E-5   | NULL     | NULL       | NULL         | NULL          |
| Sorting result            | 3E-6     | NULL     | NULL       | NULL         | NULL          |
| executing                 | 1E-6     | NULL     | NULL       | NULL         | NULL          |
| Sending data              | 0.797651 | NULL     | NULL       | NULL         | NULL          |
| converting HEAP to MyISAM | 0.762739 | NULL     | NULL       | NULL         | NULL          |
| Sending data              | 1.574018 | NULL     | NULL       | NULL         | NULL          |
| Creating sort index       | 1.333006 | NULL     | NULL       | NULL         | NULL          |
| end                       | 7E-6     | NULL     | NULL       | NULL         | NULL          |
| removing tmp table        | 0.009357 | NULL     | NULL       | NULL         | NULL          |

嘗試着對這不合常規的SQL作優化

create index idx_tb_vote_user_id on tb_vote(user_id);
mysql> explain select user_id,count(1) from tb_vote group by user_id;
+----+-------------+---------+-------+---------------------+---------------------+---------+------+--------+-------------+
| id | select_type | table   | type  | possible_keys       | key                 | key_len | ref  | rows   | Extra       |
+----+-------------+---------+-------+---------------------+---------------------+---------+------+--------+-------------+
|  1 | SIMPLE      | tb_vote | index | idx_tb_vote_user_id | idx_tb_vote_user_id | 62      | NULL | 398784 | Using index |
+----+-------------+---------+-------+---------------------+---------------------+---------+------+--------+-------------+
1 row in set

沒有再使用臨時表和文件排序，雖然依然取了398784行，但取的是索引的，而不是表的，IO次數會明顯減少，特別是那種列很是多的字段效果更明顯

鎖

表級鎖

先看看lock命令的語法，在主機後臺登陸mysql

[hadoop@hadoop00 /home/hadoop]$ mysql -u root -p
Enter password: 

mysql> ? lock
Name: 'LOCK'
Description:
Syntax:
LOCK TABLES
    tbl_name [[AS] alias] lock_type
    [, tbl_name [[AS] alias] lock_type] ...

lock_type:
    READ [LOCAL]
  | [LOW_PRIORITY] WRITE

經過命令能夠看出能夠在表上面添加讀鎖和寫鎖，下面分別對讀鎖和寫鎖作測試

更全面的信息能夠參考https://dev.mysql.com/doc/refman/5.6/en/lock-tables.html，視本身的MySQL版本選擇對應幫助文檔版本

讀鎖

在會話1給表添加讀鎖

lock table tb_v_s_user read;

建立兩個會話（打開兩個sql窗口），在會話1中對tb_v_s_user表加讀鎖

操做	會話1	會話2
select user_name from tb_v_s_user limit 1;	能夠	能夠
select user_id from tb_vote limit 1;	不能夠	能夠
update tb_v_s_user set user_name = '1F7sJ' where user_name = '1F7sJ';	不能夠，直接報錯	阻塞-得到鎖-執行
lock table tb_v_s_user read;	能夠，並且不管執行多少次，一個會話只能對一個表加一個讀鎖，證實它是可重入鎖	能夠，表上的讀鎖加1
unlock tables	釋放該會話全部的鎖	釋放該會話全部的鎖

寫鎖

在操做以前先將兩個會話中的全部讀鎖釋放掉

unlock tables;

在會話1中添加寫鎖

show open tables where In_use > 0;

比較兩個會話在不一樣狀況下的結果

操做	會話1	會話2
select user_name from tb_v_s_user limit 1;	能夠	阻塞-得到鎖-執行
select user_id from tb_vote limit 1;	不能夠	能夠
update tb_v_s_user set user_name = '1F7sJ' where user_name = '1F7sJ';	能夠	阻塞-得到鎖-執行
lock table tb_v_s_user read;	能夠，一旦執行以前的寫鎖就變成了讀鎖，若是沒有別的會話在表上有鎖，仍是變回寫鎖	阻塞-得到鎖-執行
unlock tables	釋放該會話全部的鎖	釋放該會話全部的鎖

行級鎖

前面說表級鎖會致使吞吐量很低，鎖競爭嚴重，爲此出現了行級鎖，行級鎖高併發下鎖競爭小、吞吐量大。使用行級鎖能夠實現事務的ACID屬性，避免由於併發出現的數據更新丟失、髒讀、不可重複讀、幻讀的狀況。

擴展：

ACID即爲事務的原子性、一致性、隔離性、持久性：

原子性(Atomicity)：執行的SQL要麼所有成功，要麼所有失敗，不可被拆分

一致性(Consistent)：就是數據在事務開始以前的狀態會同一變爲事務結束後的狀態，不能部分被改變

隔離性(Isolation)：不一樣會話執行SQL對結果互不影響，好比會話1寫的數據在未提交以前是不能被會話2看到的

持久性(Durable)：數據一旦被提交，再被別的操做覆蓋以前永久被保存着

沒有行鎖支持的事務致使的併發問題：

更新丟失(Lost Update)：會話1中執行的更新操做未提交以前被會話2中執行的更新操做覆蓋

髒讀(Dirty Reads)：會話1中執行的更新操做未提交就被會話2看到了

不可重複讀(Non-Repeatable Reads)：會話1讀取的數據在未提交以前不能重複讀

幻讀(Phantom Reads)：會話1中執行的新增操做未提交就被會話2看到了

事務隔離級別：

使用命令查看默認隔離級別

mysql> show variables like 'tx_isolation';
+---------------+-----------------+
| Variable_name | Value           |
+---------------+-----------------+
| tx_isolation  | REPEATABLE-READ |
+---------------+-----------------+
1 row in set

比較兩個會話在不一樣狀況下的結果

測試以前先關閉掉每一個會話的自動提交功能

mysql> set autocommit=0;
Query OK, 0 rows affected

拿一條數據作測試，測試以前數據是這樣的：

mysql> select * from tb_v_user where user_name = '01Vo5';
+----------------------+-----------+-----+--------+
| user_id              | user_name | age | gendor |
+----------------------+-----------+-----+--------+
| 01Vo53QWYUqgSsuUWN0s | 01Vo5     |  45 |      2 |
+----------------------+-----------+-----+--------+
1 row in set

操做	會話1	會話2
會話1中：update tb_v_user set age = 44 where user_name = '01Vo5';	查詢結果：age=44	查詢結果：age=45
會話1中：作commit;	查詢結果：age=44	查詢結果：age=45（由於會話2尚未commit）
會話2中：作commit;	查詢結果：age=44	查詢結果：age=44
會話1中：update tb_v_user set age = 46 where user_name = '01Vo5';	查詢結果：age=46	執行一樣的update語句，會阻塞等待直到會話1的commit以後，拿到鎖纔會成功
會話1中：select * from tb_v_user where user_name = '01Vo5';	查詢結果：age=46	執行update tb_v_user set age = 47 where user_name = '01Vo5';
會話1\2中：select * from tb_v_user where user_name = '01Vo5';	查詢結果：age=46	查詢結果：age=47

行鎖(MySQL默認事務隔離級別：REPEATABLE-READ)特色總結一下：只要在行上作寫操做，行鎖就會排斥其餘寫操做，其餘讀是能夠繼續的，並且不會讀寫了未提交的數據

注：在會話中執行ddl(create table ,drop table,create index ,drop index等等)操做，會觸發commit操做

始料未及的表鎖災難

先準備一點數據，將tb_v_user中的數據插入20份到tb_vv_user中。雖然裏面數據重複了，在索引的狀況下，根據索引字段更新仍是行級鎖

在tb_vv_user的user_name字段上添加索引

create index idx_tb_vv_user_un on tb_vv_user(user_name);

更新語句走全表掃描

1.有索引，可是更新時未走索引掃描

爲了測試這一點，我得先將user_name = '01Vo5'行的user_name更新爲全數字

update tb_vv_user set user_name = '12345' where user_name = '01Vo5';

測試步驟：

會話1中按照走索引方式更新數據

會話2中按照不走索引方式更新數據，同時會話2中執行其餘行的更新

會話1profiles:

會話2profiles:

能夠看出會話1按照不走索引方式更新時，致使了會話2的更新被阻塞

有興趣的同窗還能夠再深刻查看一下每一個sql的執行過程

show profile for query id

2.無索引

既然上面沒有走索引就會致使整張表被鎖，那若是表上面沒有索引，作更新是否是也會這樣喃？測試一下

#會話1
drop index idx_tb_vv_user_un on tb_vv_user;
update tb_vv_user set age = 13 where user_name = '12345';
#會話2
update tb_vv_user set age = 13 where user_name = '0343W'

update tb_vv_user set age = 13 where user_name = '0343W'

測試步驟：刪除表上的索引，在會話1中執行更新操做的同時，在會話2中執行更新操做。爲了驗證會話2的更新操做確實被會話1的更新阻塞，在前面的操做都執行完後再次在會話2中執行更新操做，經過比較時間來判斷。下面看看profiles

會話1：

會話2：

從執行耗時上看，是符合預期的。結論：沒有索引作更新時，會觸發表級鎖，我認爲更寬泛的說法應該是「只要DML操做走全表掃描都會觸發表鎖」。我認爲緣由是這樣的：由於全表掃描過程很慢，在當前會話還沒更新完數據的時候，其餘會話更新了數據就違反了事務的隔離性，因此必須加表級寫鎖

刪除語句走全表掃描

有了上面的理論，因此刪除確定也是表級寫鎖了

會話1：

會話2：

我在這裏只測試了無索引走全表掃描的狀況，結果符合預期，兩個會話同時執行的時候出現了阻塞

有興趣的同窗還能夠測試有索引，可是使用varchar的自動轉換作刪除是否會發生阻塞

建立索引

#會話1執行
create index idx_tb_vv_user_un on tb_vv_user(user_name);
#會話2執行
update tb_vv_user set age = 10 where user_name = '0343W';

查看profiles狀況

會話1：

建立索引耗時31秒

會話2：建立索引時執行的更新操做

更新耗時接近7秒，爲何這麼耗時？由於在建立索引的時候是表鎖，任何更新操做都會被阻塞

會話2：索引建立完後執行更新操做

更新耗時毫秒級

批量插入致使索引重建

我就不測試了，和上面的區別是手工建立索引與人工建立索引

間隙鎖

會話1執行的DML操做是範圍掃描，而會話2執行的DML操做又在會話1的範圍內，那麼會話2的DML操做就會被阻塞，好比：

會話1在UPDATE條件爲ID>1 AND ID<5，那麼會話2在會話1還未提交時對ID在1到5之間的數據作DML操做就會阻塞

總結一下：

從開發人員角度出發，須要從如下幾點去避免問題和優化SQL

1.開發時在測試環境多使用explain和profile檢查本身寫的SQL，好比有沒有走索引，索引使用是否恰當，用小表驅動大表，避免大表的全表掃描

2.上線後跟蹤系統運行狀況，好比打開慢日誌查詢，跟蹤優化SQL，不斷的迭代

3.數據批量操做時避免出現表鎖和間隙鎖，使用show open tables 查看錶上鎖的狀況。好比插入與刪除數據、重建索引等

4.開發時如何關閉了自動提交功能，要時刻注意手動提交與關閉鏈接或者回收鏈接

5.不要寫超長的SQL

6.批量操做盡可能放在系統負載低的時候去作

7.對需求發佈時的數據庫腳本作認真的驗證，作好數據備份以備發佈失敗回退

相關標籤/搜索

每日一句

每一个你不满意的现在，都有一个你没有努力的曾经。