Bug #95422 MY-010956 and MY-010957 are possible too noisy in error-log
Submitted: 20 May 2019 7:40 Modified: 22 May 2019 4:41
Reporter: Tsubasa Tanaka (OCA) Email Updates:
Status: Verified Impact on me:
Category:MySQL Server: Logging Severity:S4 (Feature request)
Version:8.0.15 OS:CentOS (7.4)
Assigned to: CPU Architecture:x86

[20 May 2019 7:40] Tsubasa Tanaka
This is feature request.

MY-010956(Logging when original_commit_timestamp > immediate_commit_timestamp) and MY-010957(Logging when backing to immediate_commit_timestamp <= original_commit_timestamp after MY-010956 occurred) are possible too noisy in error-log.

MYSQL_BIN_LOG::write_gtid compares micro-sec level timestamp "original_commit_timestamp" and "immediate_commit_timestamp" (https://github.com/mysql/mysql-server/blob/mysql-8.0.16/sql/binlog.cc#L1526-L1539)

But they can have difference between master's system-time and slave's system-time in micro-sec order in real world.

Example, in our production, both master and slave use NTP time-sync but they have system-time difference about 500us.

How to repeat:
Prepare 2 servers which have 500us system-time difference.

$ date "+%s.%N" ### at master

$ date "+%s.%N" ### at slave

Setting up replication environment and start slave, slave mysqld dumps too noisy logs in error-log.

2019-05-20T14:25:17.121864+09:00 5 [Warning] [MY-010956] [Server] Invalid replication timestamps: original commit timestamp is more recent than the immediate commit timestamp. This may be an issue if delayed replication is active. Make sure that servers have their clocks set to the correct time. No further message will be emitted until after timestamps become valid again.
2019-05-20T14:25:17.177804+09:00 5 [Warning] [MY-010957] [Server] The replication timestamps have returned to normal values.

Suggested fix:
Please add a margin of time for MY-010956.

Sample implement, following code adds a margin of "binlog_timestamp_warning_threshold" milli-seconds to logging.

diff -r mysql-8.0.16_orig/sql/binlog.cc mysql-8.0.16/sql/binlog.cc
<     if (original_commit_timestamp > immediate_commit_timestamp &&
>     if (original_commit_timestamp > immediate_commit_timestamp + thd->variables.binlog_timestamp_warning_threshold * 1000 &&
[20 May 2019 7:43] Tsubasa Tanaka
Or, tone down MY-010956 and MY-010957 to INFO-level log.
After that, I can filter them by setting log_error_verbosity :)
[22 May 2019 4:41] MySQL Verification Team
Hello Tanaka-San,

Thank you for the feature request!

[2 Mar 2021 9:51] MySQL Verification Team
Should be able to filter specific messages using


or throttle them with "dragnet"

[30 Mar 2021 9:29] Hanno Sirkel
After 2 years the rather simple issue is still present.
It's very annoying to have logs full of this because of nanosecond difference in clocks.
Could we please add a margin for difference or ability to turn this off / filter out?
[30 Mar 2021 10:52] Artjom Superov
Haven't seen it so frequently before MySQL 8.

Is there a possibility to turn this logging event off?