From ab9182470dd4f0ddeb28ae7dfa11979e83f9abe3 Mon Sep 17 00:00:00 2001 From: Alexander Barkov Date: Wed, 20 Nov 2024 13:46:43 +0400 Subject: [PATCH] MDEV-31366 Assertion `thd->start_time' failed in bool LOGGER::slow_log_print(THD*, const char*, size_t, ulonglong) Fixing a wrong DBUG_ASSERT. thd->start_time and thd->start_time_sec_part cannot be 0 at the same time. But thd->start_time can be 0 when thd->start_time_sec_part is not 0, e.g. after: SET timestamp=0.99; --- mysql-test/main/log_slow.result | 17 +++++++++++++++++ mysql-test/main/log_slow.test | 15 +++++++++++++++ sql/log.cc | 2 +- 3 files changed, 33 insertions(+), 1 deletion(-) diff --git a/mysql-test/main/log_slow.result b/mysql-test/main/log_slow.result index 81ef7f9af72..131542075a1 100644 --- a/mysql-test/main/log_slow.result +++ b/mysql-test/main/log_slow.result @@ -207,4 +207,21 @@ use `a b`; SET timestamp=1234567890; select count(*) from mysql.global_priv where length(priv)>2 +# +# MDEV-31366 Assertion `thd->start_time' failed in bool LOGGER::slow_log_print(THD*, const char*, size_t, ulonglong) +# +TRUNCATE mysql.slow_log; +SET global log_output='TABLE'; +SET timestamp=0.99; +SET long_query_time=0.00001; +SELECT SLEEP(0.1); +SLEEP(0.1) +0 +SELECT COUNT(*)>0 AS c1 FROM mysql.slow_log; +c1 +1 +SET global log_output=default; +SET timestamp=default; +SET long_query_time=default; +TRUNCATE mysql.slow_log; # End of 10.5 tests diff --git a/mysql-test/main/log_slow.test b/mysql-test/main/log_slow.test index 1f33cff9f25..8fb7fd1826b 100644 --- a/mysql-test/main/log_slow.test +++ b/mysql-test/main/log_slow.test @@ -221,4 +221,19 @@ let SEARCH_PATTERN= use \`a\n.*2; let SEARCH_OUTPUT=matches; source include/search_pattern_in_file.inc; +--echo # +--echo # MDEV-31366 Assertion `thd->start_time' failed in bool LOGGER::slow_log_print(THD*, const char*, size_t, ulonglong) +--echo # + +TRUNCATE mysql.slow_log; +SET global log_output='TABLE'; +SET timestamp=0.99; +SET long_query_time=0.00001; +SELECT SLEEP(0.1); +SELECT COUNT(*)>0 AS c1 FROM mysql.slow_log; +SET global log_output=default; +SET timestamp=default; +SET long_query_time=default; +TRUNCATE mysql.slow_log; + --echo # End of 10.5 tests diff --git a/sql/log.cc b/sql/log.cc index a0f865dc7e0..32a1436f9a6 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -1330,7 +1330,7 @@ bool LOGGER::slow_log_print(THD *thd, const char *query, size_t query_length, user_host_buff); DBUG_ASSERT(thd->start_utime); - DBUG_ASSERT(thd->start_time); + DBUG_ASSERT(thd->start_time || thd->start_time_sec_part); query_utime= (current_utime - thd->start_utime); lock_utime= (thd->utime_after_lock - thd->start_utime); my_hrtime_t current_time= { hrtime_from_time(thd->start_time) +