Percona Server moved to https://jira.percona.com/projects/PS

query_response_time_range_base is not read on startup

Bug #1453277 reported by John Cesario
22
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
Medium
Laurynas Biveinis
Percona Server moved to https://jira.percona.com/projects/PS 5.6.25-73.0
5.5
Fix Released
Medium
Laurynas Biveinis
Percona Server moved to https://jira.percona.com/projects/PS 5.5.44-37.3
5.6
Fix Released
Medium
Laurynas Biveinis
Percona Server moved to https://jira.percona.com/projects/PS 5.6.25-73.0

Bug Description

This is a duplicate/extension of https://bugs.launchpad.net/percona-server/+bug/1056855

This now effects 5.5 and 5.6

5.6
[vagrant@build ~]$ sudo /sbin/service mysql restart
Shutting down MySQL (Percona Server)... [ OK ]
Starting MySQL (Percona Server). [ OK ]
[vagrant@build ~]$ sudo mysql
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.24-72.2 Percona Server (GPL), Release 72.2, Revision 8d0f85b

Copyright (c) 2009-2015 Percona LLC and/or its affiliates
Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> SELECT VERSION();
+-------------+
| VERSION() |
+-------------+
| 5.6.24-72.2 |
+-------------+
1 row in set (0.00 sec)

mysql> SELECT * FROM information_schema.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| TIME | COUNT | TOTAL |
+----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000010 | 0 | 0.000000 |
| 0.000100 | 1 | 0.000081 |
| 0.001000 | 2 | 0.000327 |
| 0.010000 | 0 | 0.000000 |
| 0.100000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 10.000000 | 0 | 0.000000 |
| 100.000000 | 0 | 0.000000 |
| 1000.000000 | 0 | 0.000000 |
| 10000.000000 | 0 | 0.000000 |
| 100000.000000 | 0 | 0.000000 |
| 1000000.000000 | 0 | 0.000000 |
| TOO LONG | 0 | TOO LONG |
+----------------+-------+----------------+
14 rows in set (0.00 sec)

mysql> SHOW GLOBAL VARIABLES LIKE '%query_response_%';
+--------------------------------+-------+
| Variable_name | Value |
+--------------------------------+-------+
| query_response_time_flush | OFF |
| query_response_time_range_base | 2 |
| query_response_time_stats | ON |
+--------------------------------+-------+
3 rows in set (0.00 sec)

mysql> SHOW GLOBAL STATUS LIKE '%query_response_%';
Empty set (0.00 sec)

mysql> SET GLOBAL query_response_time_flush=1;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM information_schema.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| TIME | COUNT | TOTAL |
+----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000003 | 0 | 0.000000 |
| 0.000007 | 0 | 0.000000 |
| 0.000015 | 0 | 0.000000 |
| 0.000030 | 0 | 0.000000 |
| 0.000061 | 0 | 0.000000 |
| 0.000122 | 1 | 0.000089 |
| 0.000244 | 0 | 0.000000 |
| 0.000488 | 0 | 0.000000 |
| 0.000976 | 0 | 0.000000 |
| 0.001953 | 0 | 0.000000 |
| 0.003906 | 0 | 0.000000 |
| 0.007812 | 0 | 0.000000 |
| 0.015625 | 0 | 0.000000 |
| 0.031250 | 0 | 0.000000 |
| 0.062500 | 0 | 0.000000 |
| 0.125000 | 0 | 0.000000 |
| 0.250000 | 0 | 0.000000 |
| 0.500000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 2.000000 | 0 | 0.000000 |
| 4.000000 | 0 | 0.000000 |
| 8.000000 | 0 | 0.000000 |
| 16.000000 | 0 | 0.000000 |
| 32.000000 | 0 | 0.000000 |
| 64.000000 | 0 | 0.000000 |
| 128.000000 | 0 | 0.000000 |
| 256.000000 | 0 | 0.000000 |
| 512.000000 | 0 | 0.000000 |
| 1024.000000 | 0 | 0.000000 |
| 2048.000000 | 0 | 0.000000 |
| 4096.000000 | 0 | 0.000000 |
| 8192.000000 | 0 | 0.000000 |
| 16384.000000 | 0 | 0.000000 |
| 32768.000000 | 0 | 0.000000 |
| 65536.000000 | 0 | 0.000000 |
| 131072.000000 | 0 | 0.000000 |
| 262144.000000 | 0 | 0.000000 |
| 524288.000000 | 0 | 0.000000 |
| 1048576.000000 | 0 | 0.000000 |
| 2097152.000000 | 0 | 0.000000 |
| 4194304.000000 | 0 | 0.000000 |
| 8388608.000000 | 0 | 0.000000 |
| TOO LONG | 0 | TOO LONG |
+----------------+-------+----------------+
44 rows in set (0.00 sec)

5.5
mysql> SELECT * FROM information_schema.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| time | count | total |
+----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000010 | 0 | 0.000000 |
| 0.000100 | 0 | 0.000000 |
| 0.001000 | 0 | 0.000000 |
| 0.010000 | 0 | 0.000000 |
| 0.100000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 10.000000 | 0 | 0.000000 |
| 100.000000 | 0 | 0.000000 |
| 1000.000000 | 0 | 0.000000 |
| 10000.000000 | 0 | 0.000000 |
| 100000.000000 | 0 | 0.000000 |
| 1000000.000000 | 0 | 0.000000 |
| TOO LONG | 0 | TOO LONG |
+----------------+-------+----------------+
14 rows in set (0.00 sec)

mysql> SHOW GLOBAL VARIABLES LIKE '%query%';
+------------------------------------+-------------------------------+
| Variable_name | Value |
+------------------------------------+-------------------------------+
| ft_query_expansion_limit | 20 |
| have_query_cache | YES |
| long_query_time | 10.000000 |
| query_alloc_block_size | 8192 |
| query_cache_limit | 1048576 |
| query_cache_min_res_unit | 4096 |
| query_cache_size | 0 |
| query_cache_strip_comments | OFF |
| query_cache_type | ON |
| query_cache_wlock_invalidate | OFF |
| query_prealloc_size | 8192 |
| query_response_time_range_base | 2 |
| query_response_time_stats | OFF |
| slow_query_log | OFF |
| slow_query_log_always_write_time | 10.000000 |
| slow_query_log_file | /var/lib/mysql/build-slow.log |
| slow_query_log_timestamp_always | OFF |
| slow_query_log_timestamp_precision | second |
| slow_query_log_use_global_control | |
+------------------------------------+-------------------------------+
19 rows in set (0.00 sec)

mysql> FLUSH QUERY_RESPONSE_TIME;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM information_schema.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| time | count | total |
+----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000003 | 0 | 0.000000 |
| 0.000007 | 0 | 0.000000 |
| 0.000015 | 0 | 0.000000 |
| 0.000030 | 0 | 0.000000 |
| 0.000061 | 0 | 0.000000 |
| 0.000122 | 0 | 0.000000 |
| 0.000244 | 0 | 0.000000 |
| 0.000488 | 0 | 0.000000 |
| 0.000976 | 0 | 0.000000 |
| 0.001953 | 0 | 0.000000 |
| 0.003906 | 0 | 0.000000 |
| 0.007812 | 0 | 0.000000 |
| 0.015625 | 0 | 0.000000 |
| 0.031250 | 0 | 0.000000 |
| 0.062500 | 0 | 0.000000 |
| 0.125000 | 0 | 0.000000 |
| 0.250000 | 0 | 0.000000 |
| 0.500000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 2.000000 | 0 | 0.000000 |
| 4.000000 | 0 | 0.000000 |
| 8.000000 | 0 | 0.000000 |
| 16.000000 | 0 | 0.000000 |
| 32.000000 | 0 | 0.000000 |
| 64.000000 | 0 | 0.000000 |
| 128.000000 | 0 | 0.000000 |
| 256.000000 | 0 | 0.000000 |
| 512.000000 | 0 | 0.000000 |
| 1024.000000 | 0 | 0.000000 |
| 2048.000000 | 0 | 0.000000 |
| 4096.000000 | 0 | 0.000000 |
| 8192.000000 | 0 | 0.000000 |
| 16384.000000 | 0 | 0.000000 |
| 32768.000000 | 0 | 0.000000 |
| 65536.000000 | 0 | 0.000000 |
| 131072.000000 | 0 | 0.000000 |
| 262144.000000 | 0 | 0.000000 |
| 524288.000000 | 0 | 0.000000 |
| 1048576.000000 | 0 | 0.000000 |
| 2097152.000000 | 0 | 0.000000 |
| 4194304.000000 | 0 | 0.000000 |
| 8388608.000000 | 0 | 0.000000 |
| TOO LONG | 0 | TOO LONG |
+----------------+-------+----------------+
44 rows in set (0.00 sec)

Laurynas Biveinis (laurynas-biveinis)
tags: added: contribution low-hanging-fruit query-response-time
Muhammad Irfan (muhammad-irfan)
Changed in percona-server:
assignee: nobody → Muhammad Irfan (muhammad-irfan)
Muhammad Irfan (muhammad-irfan)
Changed in percona-server:
assignee: Muhammad Irfan (muhammad-irfan) → nobody
Revision history for this message
John Cesario (cesario) wrote :

The bug is triaged here: https://github.com/percona/percona-server/pull/72

Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (3.6 KiB)

Confirmed with PS 5.6.22

mysql> SELECT VERSION();
+-----------------+
| VERSION() |
 +-----------------+
| 5.6.24-72.2-log |
 +-----------------+
1 row in set (0.00 sec)

mysql> SELECT * from INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| TIME | COUNT | TOTAL |
 +----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000010 | 0 | 0.000000 |
| 0.000100 | 2 | 0.000126 |
| 0.001000 | 0 | 0.000000 |
| 0.010000 | 0 | 0.000000 |
| 0.100000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 10.000000 | 0 | 0.000000 |
| 100.000000 | 0 | 0.000000 |
| 1000.000000 | 0 | 0.000000 |
| 10000.000000 | 0 | 0.000000 |
| 100000.000000 | 0 | 0.000000 |
| 1000000.000000 | 0 | 0.000000 |
| TOO LONG | 0 | TOO LONG |
 +----------------+-------+----------------+
14 rows in set (0.00 sec)

mysql> SHOW GLOBAL VARIABLES LIKE '%query_response_%';
+--------------------------------+-------+
| Variable_name | Value |
 +--------------------------------+-------+
| query_response_time_flush | OFF |
| query_response_time_range_base | 2 |
| query_response_time_stats | ON |
 +--------------------------------+-------+
3 rows in set (0.00 sec)

mysql> SET GLOBAL query_response_time_flush=1;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM information_schema.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| TIME | COUNT | TOTAL |
 +----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000003 | 0 | 0.000000 |
| 0.000007 | 0 | 0.000000 |
| 0.000015 | 0 | 0.000000 |
| 0.000030 | 0 | 0.000000 |
| 0.000061 | 1 | 0.000049 |
| 0.000122 | 0 | 0.000000 |
| 0.000244 | 0 | 0.000000 |
| 0.000488 | 0 | 0.000000 |
| 0.000976 | 0 | 0.000000 |
| 0.001953 | 0 | 0.000000 |
| 0.003906 | 0 | 0.000000 |
| 0.007812 | 0 | 0.000000 |
| 0.015625 | 0 | 0.000000 |
| 0.031250 | 0 | 0.000000 |
| 0.062500 | 0 | 0.000000 |
| 0.125000 | 0 | 0.000000 |
| 0.250000 | 0 | 0.000000 |
| 0.500000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 2.000000 | 0 | 0.000000 |
| 4.000000 | 0 | 0.000000 |
| 8.000000 | 0 | 0.000000 |
| 16.000000 | 0 | 0.000000 |
| 32.000000 | 0 | 0.000000 |
| 64.000000 | 0 | 0.000000 |
| 128.000000 | 0 | 0.000000 |
| 256.000000 | 0 | 0.000000 |
| 512.000000 | 0 | 0.000000 |
| 1024.000000 | 0 | 0.000000 |
| 2048.000000 | 0 | 0.000000 |
| 4096.000000 | 0 | 0.000000 |
| 8192.000000 | 0 | 0.000000 |
| 16384.000000 | 0 | ...

Read more...

Changed in percona-server:
status: New → Confirmed
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (3.4 KiB)

Confirmed with PS 5.5.40

mysql> SHOW GLOBAL VARIABLES LIKE '%query_response_%';
+--------------------------------+-------+
| Variable_name | Value |
 +--------------------------------+-------+
| query_response_time_range_base | 2 |
| query_response_time_stats | ON |
 +--------------------------------+-------+
2 rows in set (0.00 sec)

mysql> SELECT * from INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| time | count | total |
 +----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000010 | 0 | 0.000000 |
| 0.000100 | 0 | 0.000000 |
| 0.001000 | 1 | 0.000225 |
| 0.010000 | 1 | 0.005754 |
| 0.100000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 10.000000 | 0 | 0.000000 |
| 100.000000 | 0 | 0.000000 |
| 1000.000000 | 0 | 0.000000 |
| 10000.000000 | 0 | 0.000000 |
| 100000.000000 | 0 | 0.000000 |
| 1000000.000000 | 0 | 0.000000 |
| TOO LONG | 0 | TOO LONG |
 +----------------+-------+----------------+
14 rows in set (0.00 sec)

mysql> FLUSH QUERY_RESPONSE_TIME;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * from INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+----------------+-------+----------------+
| time | count | total |
 +----------------+-------+----------------+
| 0.000001 | 0 | 0.000000 |
| 0.000003 | 0 | 0.000000 |
| 0.000007 | 0 | 0.000000 |
| 0.000015 | 0 | 0.000000 |
| 0.000030 | 0 | 0.000000 |
| 0.000061 | 1 | 0.000031 |
| 0.000122 | 0 | 0.000000 |
| 0.000244 | 0 | 0.000000 |
| 0.000488 | 0 | 0.000000 |
| 0.000976 | 0 | 0.000000 |
| 0.001953 | 0 | 0.000000 |
| 0.003906 | 0 | 0.000000 |
| 0.007812 | 0 | 0.000000 |
| 0.015625 | 0 | 0.000000 |
| 0.031250 | 0 | 0.000000 |
| 0.062500 | 0 | 0.000000 |
| 0.125000 | 0 | 0.000000 |
| 0.250000 | 0 | 0.000000 |
| 0.500000 | 0 | 0.000000 |
| 1.000000 | 0 | 0.000000 |
| 2.000000 | 0 | 0.000000 |
| 4.000000 | 0 | 0.000000 |
| 8.000000 | 0 | 0.000000 |
| 16.000000 | 0 | 0.000000 |
| 32.000000 | 0 | 0.000000 |
| 64.000000 | 0 | 0.000000 |
| 128.000000 | 0 | 0.000000 |
| 256.000000 | 0 | 0.000000 |
| 512.000000 | 0 | 0.000000 |
| 1024.000000 | 0 | 0.000000 |
| 2048.000000 | 0 | 0.000000 |
| 4096.000000 | 0 | 0.000000 |
| 8192.000000 | 0 | 0.000000 |
| 16384.000000 | 0 | 0.000000 |
| 32768.000000 | 0 | 0.000000 |
| 65536.000000 | 0 | 0.000000 |
| 131072.000000 | 0 | 0.000000 |
| 262144.000000 | 0 | 0.000000 |
| 524288.000000 |...

Read more...

Revision history for this message
John Cesario (cesario) wrote :

What was the triage ?

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

The patch at
   https://github.com/percona/percona-server/pull/72
was merged in
https://github.com/percona/percona-server/pull/85 and https://github.com/percona/percona-server/pull/86.

(John, sorry for missing your triage question.)

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1625

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.