在主库上执行一条 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 |
+-----------------------+-----------+------------+-----------+-------------+-------------------------------+
发现从被”卡“住的点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。
--转自
当前位置：
论坛首页 »
自由讨论区 »
MySQL, Oracle及数据库讨论区
»
发起投票
技术讨论
加好友
发消息
2014-11-11 9:32:07 |
赞(
操作
