Description:
Hi team,
The bug https://bugs.mysql.com/bug.php?id=35396 where incorrect query_time is logged in the slow log when adjusting system time backward occurs again in MySQL 8.0. I'm able to reproduce it in the current latest version 8.0.43.
How to repeat:
- Install MySQL Community Server 8.0.43 and with debug symbol
# apt list --installed | grep "mysql-community-server"
mysql-community-server-core-dbgsym/unknown,now 8.0.43-1debian12 amd64 [installed]
mysql-community-server-core/unknown,now 8.0.43-1debian12 amd64 [installed,automatic]
mysql-community-server-debug-dbgsym/unknown,now 8.0.43-1debian12 amd64 [installed]
mysql-community-server-debug/unknown,now 8.0.43-1debian12 amd64 [installed,automatic]
mysql-community-server/unknown,now 8.0.43-1debian12 amd64 [installed]
- Start MySQL with slow query enabled:
[mysqld]
...
slow_query_log=1
long_query_time=0
- Attach gdb to the mysqld process
# gdb -p `pidof mysqld`
- Set breakpoint at log.cc:1306
(gdb) b log.cc:1306
Breakpoint 1 at 0x562b86d77c58: file ./sql/log.cc, line 1306.
(gdb) c
Continuing.
- In another session, execute a simple select query
mysql> select now();
+---------------------+
| now() |
+---------------------+
| 2025-10-02 03:26:11 |
+---------------------+
1 row in set (0.00 sec)
- GDB should hit the breakpoint:
Thread 38 "connection" hit Breakpoint 1, Query_logger::slow_log_write (this=0x562b89cdfc00 <query_logger>, thd=0x7fb4f80117a0, query=0x7fb4f8000ba0 "select now()", query_length=12, aggregate=<optimized out>,
lock_usec=0, exec_usec=<optimized out>) at ./sql/log.cc:1306
1306 in ./sql/log.cc
- Adjust the system time 1 minute backward
# sudo timedatectl set-time "2025-10-02 03:25:00"
- Continue in GDB:
(gdb) c
Continuing.
- The slow log now show incorrect/unusually large query_time
# Time: 2025-10-02T03:25:01.896124Z
# User@Host: root[root] @ localhost [] Id: 9
# Query_time: 18446744073639.753906 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 1
SET timestamp=1759375571;
select now();
