Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.4, 10.5, 10.6, 10.9, 10.10, 10.11, 11.0, 11.1
-
None
Description
When the current timestamp has microseconds below 100000, it loses leading zeros when written into the binary log. So, when the binlog is replayed, statements inserting into timestamp columns end up with wrong values.
It also causes further, more obvious, errors, for example if the mixed replication switches to row format, row events on such tables can no longer be executed, as they refer to rows which aren't in the table.
--source include/have_binlog_format_mixed.inc
|
|
|
reset master;
|
|
|
create table t (a int, b timestamp(6) default current_timestamp(6) on update current_timestamp(6)); |
set @@timestamp= 1689978980.012345; |
insert into t (a) values (1); |
select * from t; |
flush binary logs; |
set @@timestamp= 1689978980.567890; |
update t set a = 2 limit 1; |
flush binary logs; |
drop table t; |
|
|
--let $datadir= `select @@datadir`
|
--exec $MYSQL_BINLOG $datadir/master-bin.000001 | $MYSQL test
|
select * from t; |
--exec $MYSQL_BINLOG $datadir/master-bin.000002 | $MYSQL test
|
|
|
# Cleanup
|
drop table t; |
In the test case above, the first INSERT inserts a row with timestamp 1689978980.012345:
|
10.4 30f3db3c |
a b
|
1 2023-07-22 01:36:20.012345
|
However, in the binlog the query event looks like this:
#230722 1:36:20 server id 1 end_log_pos 677 CRC32 0xac4d9e3d Query thread_id=5 exec_time=1476 error_code=0
|
SET TIMESTAMP=1689978980.12345/*!*/;
|
insert into t (a) values (1)
|
/*!*/;
|
So, upon binlog replaying, the inserted value is
select * from t;
|
1 2023-07-22 01:36:20.123450
|
The test case also does UPDATE, to demonstrate the second point. Since it's update with limit without order by, it switches to row format. So, the row event in the log is
#230722 1:36:20 server id 1 end_log_pos 582 CRC32 0xc781f9ec Update_rows: table id 32 flags: STMT_END_F
|
### UPDATE `test`.`t`
|
### WHERE
|
### @1=1
|
### @2=1689978980.012345
|
### SET
|
### @1=2
|
### @2=1689978980.567890
|
# Number of rows: 1
|
But it cannot be executed, because there is no such value in the table, so at this point binlog replay fails with
ERROR 1032 (HY000) at line 36: Can't find record in 't'
|
2023-07-22 2:00:56 7 [ERROR] mysqld: Can't find record in 't'
|
2023-07-22 2:00:56 7 [ERROR] Slave SQL: Could not execute Update_rows_v1 event on table test.t; Can't find record in 't', Error_code: 1032; handler error HA_ERR_END_OF_FILE; the event's master log FIRST, end_log_pos 582, Internal MariaDB error code: 1032
|
Replication however works, at least in this case. I can only guess that the timestamp reading logic on the slave matches the timestamp writing on the master, so it ends up interpreting the value correctly.