[MDEV-31731] invalid value at query_time in the slow query logs Created: 2023-07-18  Updated: 2023-07-18

Status: Open
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.4.24
Fix Version/s: None

Type: Bug Priority: Major
Reporter: suresh ramagiri Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Reported by one of our customers that, getting invalid value at the query_time in the slow query logs, same is not matching with the value getting in the mysql.slow_log table.

slow_log table entry:

MariaDB [mysql]> SELECT db,`start_time`,`user_host`,`query_time`,`rows_sent`,`rows_examined`,`sql_text` FROM slow_log WHERE
 
    -> `sql_text` LIKE "SELECT xxxxxxxxxx%"\G
 
*************************** 1. row ***************************
 
           db: yds
 
   start_time: 2023-07-13 11:48:07.379140
 
    user_host: user2[user2] @  [10.xx.xx.xx]
 
   query_time: 838:59:59.325276
 
    rows_sent: 288081
 
rows_examined: 535868

Same query entry at the slow query log:

cat node1-from_slow.log.file_old  | grep -i '18446744073709.324219' |head -n 5
 
# Time: 230713 11:48:07
 
# User@Host:user2[user2] @  [10.xx.xx.xx]
 
# Thread_id: 10917139  Schema: yds  QC_hit: No
 
# Query_time: 18446744073709.324219  Lock_time: 0.119901  Rows_sent: 288081  Rows_examined: 535868
 
# Rows_affected: 0  Bytes_sent: 67299080
 
SET timestamp=1689274087;
 
SELECT `xxxxxxxxxxxx`

We are not clear how to reproduce this case, but it happening very frequently when one or the other queries in their workload.

One such jira ticket for this similar issue is - https://jira.mariadb.org/browse/MDEV-11552, but is old fixed already.
Generated at Thu Feb 08 10:26:03 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.