Skip to:

  1. Skip to Jira Navigation
  2. Skip to Side Navigation
  3. Skip to Main Content

Inaccurate Logging of Slow Query Rate in Percona MySQL 5.8

Description

When configuring the server with the following settings:

slow_query_log=ON long_query_time=0 log_slow_rate_limit=10 log_slow_rate_type=query slow_query_log_always_write_time=0.01

The server should log information regarding the slow query rate only for queries where the specified rate limit is exceeded. However, the server currently outputs the following message for every query execution in the slow log, irrespective of whether the rate limit is actually applied:

As this query has execution time over 10 msec it will be logged every time so “# Log_slow_rate_type: query Log_slow_rate_limit: 10“ is misleading as it suggests that the rate limit is being applied to all queries, even when it is not. This could potentially lead to confusion and misinterpretation of the slow query log data. Also it adds additional bloat to the slow log.

# Time: 2024-02-20T13:28:57.929847Z # User@Host: root[root] @ localhost [] Id: 11 # Schema: testdb Last_errno: 0 Killed: 0 # Query_time: 0.187914 Lock_time: 0.000008 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0 Bytes_sent: 62 # Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0 # InnoDB_trx_id: 0 # Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No # Filesort: No Filesort_on_disk: No Merge_passes: 0 # InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000 # InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 # InnoDB_pages_distinct: 7 # Log_slow_rate_type: query Log_slow_rate_limit: 10 SET timestamp=1708435737; select count(*) from test;

Expected Behavior:
The Log_slow_rate_type and Log_slow_rate_limit messages should only be logged for queries where the specified rate limit is exceeded. Queries that do not meet the rate limit criteria should not include these messages in the slow query log.

Environment

Percona Server 8.0.35-27

Activity

Show:

Aaditya Dubey February 25, 2024 at 3:01 PM

Hi

Thank you for the report.
Verified as described.

Executed on PS 8.0.35: mysql [localhost:8088] {msandbox} (test) > select version(); +-----------+ | version() | +-----------+ | 8.0.35-27 | +-----------+ 1 row in set (0.00 sec) # Time: 2024-02-25T14:57:51.695632Z # User@Host: msandbox[msandbox] @ localhost [] Id: 8 # Schema: test Last_errno: 0 Killed: 0 # Query_time: 0.000159 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 1 Rows_affected: 0 Bytes_sent: 65 # Log_slow_rate_type: query Log_slow_rate_limit: 10 SET timestamp=1708873071; select version(); Below config parameter used: slow_query_log=ON long_query_time=0 log_slow_rate_limit=10 log_slow_rate_type=query slow_query_log_always_write_time=0.01

sending the concern to engineering for further review and updates.

Details

Assignee

Reporter

Labels

Needs QA

Yes

Affects versions

Priority

Smart Checklist

Created February 20, 2024 at 1:42 PM
Updated March 6, 2024 at 9:24 AM

Flag notifications