binlog在并发状态下的记录
前两天看binlog发现个奇怪的地方:对于position靠后的记录,timestamp却比之前的记录还要小。当时觉得大概和并发有关系
后来做了个实验
开两个session
对于session1:
begin;
insert into t1 values(1);
insert into t1 values(3);
insert into t1 values(5);
此时在session2:
begin;
insert into t1 values(2);
insert into t1 values(4);
。。。
commit;
然后再在session1:
insert into t1 values(7);
。。。
commit;
观察binlog
# at 22101158
#150702 20:31:27 server id 1 end_log_pos 22101230 Query thread_id=1234 exec_time=0 error_code=0
SET TIMESTAMP=1435894287/*!*/;
BEGIN
/*!*/;
# at 22101230
#150702 20:31:13 server id 1 end_log_pos 22101316 Query thread_id=1234 exec_time=0 error_code=0
SET TIMESTAMP=1435894273/*!*/;
insert t1 values(2)
/*!*/;
# at 22101316
#150702 20:31:14 server id 1 end_log_pos 22101402 Query thread_id=1234 exec_time=0 error_code=0
SET TIMESTAMP=1435894274/*!*/;
insert t1 values(4)
/*!*/;
# at 22101402
#150702 20:31:24 server id 1 end_log_pos 22101488 Query thread_id=1234 exec_time=0 error_code=0
SET TIMESTAMP=1435894284/*!*/;
insert t1 values(6)
/*!*/;
# at 22101488
#150702 20:31:27 server id 1 end_log_pos 22101515 Xid = 480617
COMMIT/*!*/;
# at 22101515
#150702 20:31:32 server id 1 end_log_pos 22101587 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894292/*!*/;
BEGIN
/*!*/;
# at 22101587
#150702 20:30:52 server id 1 end_log_pos 22101673 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894252/*!*/;
insert t1 values(1)
/*!*/;
# at 22101673
#150702 20:30:55 server id 1 end_log_pos 22101759 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894255/*!*/;
insert t1 values(3)
/*!*/;
# at 22101759
#150702 20:30:56 server id 1 end_log_pos 22101845 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894256/*!*/;
insert t1 values(5)
/*!*/;
# at 22101845
#150702 20:31:18 server id 1 end_log_pos 22101931 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894278/*!*/;
insert t1 values(7)
/*!*/;
# at 22101931
#150702 20:31:20 server id 1 end_log_pos 22102017 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894280/*!*/;
insert t1 values(9)
/*!*/;
# at 22102017
#150702 20:31:30 server id 1 end_log_pos 22102104 Query thread_id=1232 exec_time=0 error_code=0
SET TIMESTAMP=1435894290/*!*/;
insert t1 values(11)
/*!*/;
# at 22102104
#150702 20:31:32 server id 1 end_log_pos 22102131 Xid = 480613
COMMIT/*!*/;
可以看到session2的事务因为更早提交,所以position更靠前,但是因为请求时间比较晚,所以timestamp落后于session1所提交的事务