最近線上頻繁的出現slave延時的情況,經排查發現為用戶在刪除數據的時候,由於表主鍵的主鍵的缺少,同時刪除條件沒有索引,或或者刪除的條件過濾性極差,導致slave出現hang住,嚴重的影響了生產環境的穩定性,也希望通過這篇博客,來加深主鍵在innodb引擎中的重要性,希望用戶在使用RDS,設計自己的表的時候,一定要為表加上主鍵,主鍵可以認為是innodb存儲引擎的生命,下面我們就來分析一下這個案例(本案例的生產環境的binlog為row模式,對於myisam存儲引擎也有同樣的問題):
(1).現象slave:
mysql> show slave status\G; *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: xxx.xx.xx.xx Master_User: replicator Master_Port: 3006 Connect_Retry: 60 Master_Log_File: mysql-bin.000006 Read_Master_Log_Pos: 47465657 Relay_Log_File: slave-relay.100383 Relay_Log_Pos: 251 Relay_Master_Log_File: mysql-bin.000006 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 18057461 Relay_Log_Space: 29409335 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 1339 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error:
slave的Seconds_Behind_Master一直在增加,slave出現hang住。
(2).解析當前slave執行到的位置的binlog:
mysqlbinlog -vvv /home/mysql/data3006/mysql/mysql-bin.000006 –start-position=18057461 >/tmp/2.log ### UPDATE qianyi.dmpush_message_temp ### WHERE ### @1='fb5c72c9-0ac2-4800-93b2-b94dc9e1dd54′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */ ### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */ ### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */ ### @4='0′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
(3)分析:
模擬場景:
1.表中無主鍵,全表進行更新:
master:
表結構:
CREATE TABLE `dmpush_message_temp` (
`clientid` varchar(36) DEFAULT NULL,
`infoid` bigint(10) DEFAULT NULL,
`endtime` varchar(14) DEFAULT NULL,
`stat` varchar(8) DEFAULT NULL
) ENGINE=innodb DEFAULT CHARSET=utf8;
mysql> update dmpush_message_temp set stat=1 ;
Query OK, 226651 rows affected (1.69 sec)
Rows matched: 226651 Changed: 226651 Warnings: 0
a.binlog中第一個出現的update事務日志:
mysqlbinlog -vvv /home/mysql/data3006/mysql/mysql-bin.000007 >/tmp/test.log
2281772 ### UPDATE qianyi.dmpush_message_temp
2281773 ### WHERE
2281774 ### @1='fb5c72c9-0ac2-4800-93b2-b94dc9e1dd54′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */
2281775 ### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */
2281776 ### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */
2281777 ### @4='0′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
2281778 ### SET
2281779 ### @1='fb5c72c9-0ac2-4800-93b2-b94dc9e1dd54′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */
2281780 ### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */
2281781 ### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */
2281782 ### @4='1′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
b.binlog中最後出現的update事務日志:
5313201 ### UPDATE qianyi.dmpush_message_temp
5313202 ### WHERE
5313203 ### @1='fffff4fc-0b72-4ba2-9749-0189658af6d5′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */
5313204 ### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */
5313205 ### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */
5313206 ### @4='0′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
5313207 ### SET
5313208 ### @1='fffff4fc-0b72-4ba2-9749-0189658af6d5′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */
5313209 ### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */
5313210 ### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */
5313211 ### @4='1′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
注意這裡由於表中沒有主鍵,所以導致了每一個事務條目的更新都是全表掃描,如果表中很很多的數據,則備庫執行該更新的事務條目的時候,就會出現很多的全表掃描更新;
c.計算有多少事務條目:
root@xxxxxxxxx # cat /tmp/test.log|grep ‘UPDATE qianyi.dmpush_message_temp' -A 10 |wc -l
2521492
mysql> select 2521492/11;—-11為一個update事務條目占用的行數
+————-+
| 2521492/11 |
+————-+
| 229226.5455 |
+————-+
mysql> use qianyi
Database changed
mysql> select count(*) from dmpush_message_temp;
+———-+
| count(*) |
+———-+
| 226651 |
+———-+
可以看到,binlog的條目數和該表的數據量查不多是一致,也就是在全表更新的時候(在row模式下)更新多少行,就有多少事務的事務條目;
2.為dmpush_message_temp表添加主鍵:
mysql> alter table dmpush_message_temp add column id int not null auto_increment,add PRIMARY Key(id);
Query OK, 226651 rows affected (1.09 sec)
Records: 226651 Duplicates: 0 Warnings: 0
mysql> update dmpush_message_temp set stat=0 ;
Query OK, 226651 rows affected (1.69 sec)
Rows matched: 226651 Changed: 226651 Warnings: 0
解析binlog中的事務條目:
root@xxxxxxxxx # mysqlbinlog -vvv /home/mysql/data3006/mysql/mysql-bin.000008 >/tmp/test1.log
### UPDATE qianyi.dmpush_message_temp
### WHERE
### @1='fb5c72c9-0ac2-4800-93b2-b94dc9e1dd54′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */
### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */
### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */
### @4='1′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
### @5=1 /* INT meta=0 nullable=0 is_null=0 */
### UPDATE qianyi.dmpush_message_temp
### WHERE
### @1='fb5bdc4f-da8a-4f03-aa5e-27677d7c8ac3′ /* VARSTRING(108) meta=108 nullable=1 is_null=0 */
### @2=133 /* LONGINT meta=0 nullable=1 is_null=0 */
### @3='20121012220000′ /* VARSTRING(42) meta=42 nullable=1 is_null=0 */
### @4='1′ /* VARSTRING(24) meta=24 nullable=1 is_null=0 */
### @5=2 /* INT meta=0 nullable=0 is_null=0 */
可以看到這裡的事務條目中由於已經有了主鍵,也就是@5(第一個事務條目更新和第二個事務條目更新的@5是遞增的,即主鍵),這樣事務日志就會根據主鍵來更新,備庫執行則不會卡住;
解決:
問題的原因已經找到了,由於表中沒有主鍵,ROW模式下,每刪一條數據都會做全表掃,也就是說一條delete,如果刪了10條,會做10次全表掃。。。。所以slave一直卡住;
1.slave:停止slave;
mysql> stop slave;
Ctrl-C — sending “KILL QUERY 59028” to server …
Ctrl-C — query aborted.
Ctrl-C — sending “KILL 59028” to server …
Ctrl-C — query aborted.
Ctrl-C — exit!
Aborted
2.這個時候,發現slave已經卡住,無法進行任何操作,這個時候只有強行kill掉mysql進程
[email protected] # ps -ef|grep 3006
root 4456 1 0 Oct11 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe –defaults-file=/etc/my3006.cnf
mysql 6828 4456 0 Oct11 ? 00:39:27 /usr/sbin/mysqld –defaults-file=/etc/my3006.cnf –basedir=/ –datadir=/home/mysql/data3006/dbs3006 –user=mysql –log-error=/home/mysql/data3006/mysql/master-error.log –open-files-limit=8192 –pid-file=/home/mysql/data3006/dbs3006/xxxxxxxx.com.pid –socket=/home/mysql/data3006/tmp/mysql.sock –port=3006
kill -9 4456 6828
由於我們的slave復制是在mysqld啟動的時候自動啟動,所以這裡我們需要將其關閉:
vi /etc/my3006.cnf中加入:skip-slave-start,在用mysqld_safe啟動;
2.由於主庫的binlog已經傳入備庫,這個時候,slave執行沒有主鍵更新的事務日志就會hang住,這個時候可以采取一種巧妙的方法來避過,就是將備庫中的這張表進行數據清空,slave在執行realy log的時候,就會報1032錯誤,我們寫一個腳本進行skip掉這些錯誤,當備庫追趕上主庫後,我們在把主庫的表通過mysqldump,或者insert select 還原到備庫,這樣就可以讓slave正常的運行起來,然後在通知客戶進行主鍵的改造;
a。slave上執行以下命令:
slave:清空備庫上有問題的表
set sql_log_bin=off;
truncate table qianyi.dmpush_message_temp;
start slave;
跳過該表上的錯誤:
sh /tmp/skip.sh 3006 dmpush_message_temp
b.等備庫追上主庫後,執行以下命令:
master:
lock tables qianyi.dmpush_message_temp read;
create table a2 like qianyi.dmpush_message_temp ;
lock tables a2 write, qianyi.dmpush_message_temp read;
insert into a2 select * from qianyi.dmpush_message_temp ;
slave:
set sql_log_bin=off;
drop table qianyi.dmpush_message_temp;
create table qianyi.dmpush_message_temp like a2;
insert into qianyi.dmpush_message_temp select * from a2;
c.最後讓應用改造,添加上主鍵:
mysql> alter table dmpush_message_temp add column id int not null auto_increment,add PRIMARY Key(id);
3.當slave卡住的時候,可以通過解析binlog來看看,slave到底卡住在那裡,是那個事務,下面是一個簡單的方法,來看當前salve打開的表:
mysql> show open tables;
+———-+———————+——–+————-+
| Database | Table | In_use | Name_locked |
+———-+———————+——–+————-+
| qianyi | dmpush_message_temp | 1 | 0 |
| qianyi | test | 0 | 0 |
| qianyi | anson | 0 | 0 |
| mysql | db | 0 | 0 |
| mysql | slow_log | 0 | 0 |
| mysql | event | 0 | 0 |
+———-+———————+——–+————-+
可以看到這裡dmpush_message_temp一直處於打開狀態,這裡就可以直接定位問題的根源了;
總結:主鍵對於innodb來說,是非常重要的,每張表的設計的時候,都應該把主鍵默認的加上,不管你需不需要他,而且主鍵的設計最好選擇自增型的主鍵,這裡也可以略提一下自增主鍵的好處:
a.自增型主鍵以利於插入性能的提高;
b.自增型主鍵設計(int,bigint)可以降低二級索引的空間,提升二級索引的內存命中率;
c.自增型的主鍵可以減小page的碎片,提升空間和內存的使用。