????? 在主庫上執行一條 SQL [insert... select... ] 語句,導致從庫延遲,以前執行都不會出現延遲的,肯定有蹊蹺。所以當時就在從上執行 [show slave status\G;] 查看在執行到主的哪個position被”卡“住。發現:
zjy@192.168.1.243 : (none) 02:13:11>show binlog events in 'mysql-bin_3306.000011' from 143808509 limit 10; +-----------------------+-----------+------------+-----------+-------------+-------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +-----------------------+-----------+------------+-----------+-------------+-------------------------------+ | mysql-bin_3306.000011 | 143808509 | Query | 3 | 143808577 | BEGIN | | mysql-bin_3306.000011 | 143808577 | Table_map | 3 | 143808719 | table_id: 204 (test.a_view) | | mysql-bin_3306.000011 | 143808719 | Write_rows | 3 | 143809744 | table_id: 204 | | mysql-bin_3306.000011 | 143809744 | Write_rows | 3 | 143810738 | table_id: 204 | | mysql-bin_3306.000011 | 143810738 | Write_rows | 3 | 143811587 | table_id: 204 | | mysql-bin_3306.000011 | 143811587 | Write_rows | 3 | 143812439 | table_id: 204 | | mysql-bin_3306.000011 | 143812439 | Write_rows | 3 | 143813325 | table_id: 204 | | mysql-bin_3306.000011 | 143813325 | Write_rows | 3 | 143814193 | table_id: 204 | | mysql-bin_3306.000011 | 143814193 | Write_rows | 3 | 143815048 | table_id: 204 | | mysql-bin_3306.000011 | 143815048 | Write_rows | 3 | 143815906 | table_id: 204 | +-----------------------+-----------+------------+-----------+-------------+-------------------------------+
MySQL insert、發現從被”卡“住的點143808509 開始,Event_type 都是Write_rows,原來在昨天把該數據庫的Binlog模式從mixed 改成了Row。mixed模式的二進制信息說明請見MySQL 二進制文件 (STATEMENT)淺談,對于Row模式下比較不同的是Event_type 列:
1) QUERY_EVENT:與STATEMENT模式處理相同,存儲的是SQL,主要是一些與數據無關的操作,eg: begin、drop table、truncate table 等;2) TABLE_MAP_EVENT:記錄了下一條事件所對應的表信息,在其中存儲了數據庫名和表名;(test.a_view)3) WRITE_ROWS_EVENT:操作類型為insert;(insert)4) UPDATE_ROWS_EVENT:操作類型為update;(update)5) DELETE_ROWS_EVENT:操作類型為delete;(delete)6) XID_EVENT, 用于標識事務提交。
對應:
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ | mysql-bin.000001 | 106 | Query | 1 | 174 | BEGIN | | mysql-bin.000001 | 174 | Table_map | 1 | 215 | table_id: 223 (test.t1) | | mysql-bin.000001 | 215 | Write_rows | 1 | 249 | table_id: 223 flags: STMT_END_F | | mysql-bin.000001 | 249 | Query | 1 | 318 | COMMIT | | mysql-bin.000001 | 619 | Query | 1 | 687 | BEGIN | | mysql-bin.000001 | 687 | Table_map | 1 | 728 | table_id: 223 (test.t1) | | mysql-bin.000001 | 728 | Delete_rows | 1 | 762 | table_id: 223 flags: STMT_END_F | | mysql-bin.000001 | 762 | Query | 1 | 831 | COMMIT | | mysql-bin.000001 | 831 | Query | 1 | 899 | BEGIN | | mysql-bin.000001 | 899 | Table_map | 1 | 940 | table_id: 223 (test.t1) | | mysql-bin.000001 | 940 | Update_rows | 1 | 980 | table_id: 223 flags: STMT_END_F | | mysql-bin.000001 | 980 | Query | 1 | 1049 | COMMIT | +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+
從上面看出,ROW模式和STATEMENT模式還有明顯的差別,而STATEMENT的效果如下:
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ | mysql-bin.000001 | 4 | Format_desc | 1 | 106 | Server ver: 5.1.69-0ubuntu0.11.10.1-log, Binlog ver: 4 | | mysql-bin.000001 | 106 | Query | 1 | 195 | use `test`; insert into t1 values(111) | | mysql-bin.000001 | 195 | Query | 1 | 293 | use `test`; update t1 set id=1111 where id =111 | | mysql-bin.000001 | 293 | Query | 1 | 385 | use `test`; delete from t1 where id =1111 | +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+
Event_type是query,包含了insert、delete、update,并且顯示相關的sql,而Row不能顯示sql。
好了,回到這次出現問題的地方。為什么會延遲呢?通過 show binlog events 得到的信息中,看到了大量的Write_rows 狀態(50萬+),說明剛執行了一個大量的插入操作。想知道是怎么樣的sql語句,Row模式不能通過 show binlog events 來看,只能通過mysqlbinlog 去看binlog日志:
mysqlbinlog -vv --start-position=143808509 mysql-bin_3306.000011 | more
發現是一個腳本在主上執行了一個 insert into tb select * from ta 的操作引發的。可能會有人問,為什么ROW下會出現這個情況,而STATEMENT下不會,這個問題請具體看:MySQL Binlog 【ROW】和【STATEMENT】選擇,里面有詳細說明。文章里也給出了建議:
set session binlog_format=mixed;
即在腳本里面添加:
#!/usr/bin/env python import MySQLdb conn = MySQLdb.connect(host='localhost',user='root',passwd='123456',db='test',port=3306,charset='utf8') query = 'insert into t1 select userid from tb_0513' cursor = conn.cursor() cursor.execute("set session binlog_format='mixed'") cursor.execute(query) print query
?
注意:
通過命令 show binlog events in '' from? pos limit x? 得出:
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ | mysql-bin.000001 | 385 | Query | 1 | 477 | use `test`; alter table t1 engine =innodb | | mysql-bin.000001 | 477 | Query | 1 | 545 | BEGIN | | mysql-bin.000001 | 545 | Table_map | 1 | 586 | table_id: 224 (test.t1) | | mysql-bin.000001 | 586 | Write_rows | 1 | 620 | table_id: 224 flags: STMT_END_F | | mysql-bin.000001 | 620 | Xid | 1 | 647 | COMMIT /* xid=47052 */ | | mysql-bin.000001 | 647 | Query | 1 | 715 | BEGIN | | mysql-bin.000001 | 715 | Table_map | 1 | 756 | table_id: 224 (test.t1) | | mysql-bin.000001 | 756 | Update_rows | 1 | 796 | table_id: 224 flags: STMT_END_F | | mysql-bin.000001 | 796 | Xid | 1 | 823 | COMMIT /* xid=47053 */ | | mysql-bin.000001 | 823 | Query | 1 | 891 | BEGIN | | mysql-bin.000001 | 891 | Table_map | 1 | 932 | table_id: 224 (test.t1) | | mysql-bin.000001 | 932 | Delete_rows | 1 | 966 | table_id: 224 flags: STMT_END_F | | mysql-bin.000001 | 966 | Xid | 1 | 993 | COMMIT /* xid=47054 */ | | mysql-bin.000001 | 993 | Query | 1 | 1085 | use `test`; alter table t1 engine =myisam | | mysql-bin.000001 | 1085 | Query | 1 | 1153 | BEGIN | | mysql-bin.000001 | 1153 | Table_map | 1 | 1194 | table_id: 225 (test.t1) | | mysql-bin.000001 | 1194 | Write_rows | 1 | 1228 | table_id: 225 flags: STMT_END_F | | mysql-bin.000001 | 1228 | Query | 1 | 1297 | COMMIT | | mysql-bin.000001 | 1297 | Query | 1 | 1365 | BEGIN | | mysql-bin.000001 | 1365 | Table_map | 1 | 1406 | table_id: 225 (test.t1) | | mysql-bin.000001 | 1406 | Update_rows | 1 | 1446 | table_id: 225 flags: STMT_END_F | | mysql-bin.000001 | 1446 | Query | 1 | 1515 | COMMIT | | mysql-bin.000001 | 1515 | Query | 1 | 1583 | BEGIN | | mysql-bin.000001 | 1583 | Table_map | 1 | 1624 | table_id: 225 (test.t1) | | mysql-bin.000001 | 1624 | Delete_rows | 1 | 1658 | table_id: 225 flags: STMT_END_F | | mysql-bin.000001 | 1658 | Query | 1 | 1727 | COMMIT | +------------------+------+-------------+-----------+-------------+--------------------------------------------------------+
Mysql對Binlog的處理是以事件為單位的,每一次DML操作可能會產生多次事件,例如對于innodb存儲引擎,會額外產生一條QUERY_EVENT(事務的begin語句)以及XID_EVENT(事務提交)。
在上面的結果中觀察得到一個現象:不管表是MyISAM還是Innodb(支持或則不支持事務),都執行了begin...commit的命令。所以通過events的信息中,要看是否是innodb表需要看 Event_type 是不是用Xid 去提交的,是則為innodb。
具體row的信息請看這里