Bug #76100 | Changing performance_schema.setup_timers affects already collected data | ||
---|---|---|---|
Submitted: | 2 Mar 2015 14:46 | Modified: | 17 Mar 2015 16:51 |
Reporter: | Sergey Petrunya | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: Performance Schema | Severity: | S3 (Non-critical) |
Version: | 5.6.22, 5.6.25 | OS: | Any |
Assigned to: | Paul DuBois | CPU Architecture: | Any |
[2 Mar 2015 14:46]
Sergey Petrunya
[3 Mar 2015 6:47]
MySQL Verification Team
Hello Sergey, Thank you for the report and test case. Thanks, Umesh
[3 Mar 2015 6:48]
MySQL Verification Team
### 5.6.25 [umshastr@hod03]/export/umesh/mysql-5.6.25: bin/mysql -uroot -p -S /tmp/mysql_ushastry.sock Enter password: Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 36 Server version: 5.6.25-enterprise-commercial-advanced-debug MySQL Enterprise Server - Advanced Edition Debug (Commercial) .. . mysql> use test Database changed mysql> create table ten(a int); Query OK, 0 rows affected (0.01 sec) mysql> insert into ten values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9); Query OK, 10 rows affected (0.00 sec) Records: 10 Duplicates: 0 Warnings: 0 mysql> select * from ten; +------+ | a | +------+ | 0 | | 1 | | 2 | | 3 | | 4 | | 5 | | 6 | | 7 | | 8 | | 9 | +------+ 10 rows in set (0.00 sec) mysql> select * from performance_schema.table_io_waits_summary_by_table where OBJECT_NAME='ten'\G *************************** 1. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: test OBJECT_NAME: ten COUNT_STAR: 21 SUM_TIMER_WAIT: 5974027044 MIN_TIMER_WAIT: 12453904 AVG_TIMER_WAIT: 284477368 MAX_TIMER_WAIT: 3753185308 COUNT_READ: 11 SUM_TIMER_READ: 194103960 MIN_TIMER_READ: 12453904 AVG_TIMER_READ: 17645604 MAX_TIMER_READ: 59311216 COUNT_WRITE: 10 SUM_TIMER_WRITE: 5779923084 MIN_TIMER_WRITE: 75126408 AVG_TIMER_WRITE: 577992154 MAX_TIMER_WRITE: 3753185308 COUNT_FETCH: 11 SUM_TIMER_FETCH: 194103960 MIN_TIMER_FETCH: 12453904 AVG_TIMER_FETCH: 17645604 MAX_TIMER_FETCH: 59311216 COUNT_INSERT: 10 SUM_TIMER_INSERT: 5779923084 MIN_TIMER_INSERT: 75126408 AVG_TIMER_INSERT: 577992154 MAX_TIMER_INSERT: 3753185308 COUNT_UPDATE: 0 SUM_TIMER_UPDATE: 0 MIN_TIMER_UPDATE: 0 AVG_TIMER_UPDATE: 0 MAX_TIMER_UPDATE: 0 COUNT_DELETE: 0 SUM_TIMER_DELETE: 0 MIN_TIMER_DELETE: 0 AVG_TIMER_DELETE: 0 MAX_TIMER_DELETE: 0 1 row in set (0.01 sec) mysql> update performance_schema.setup_timers set timer_name='MICROSECOND' where name='wait'; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 mysql> select * from performance_schema.table_io_waits_summary_by_table where OBJECT_NAME='ten'\G *************************** 1. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: test OBJECT_NAME: ten COUNT_STAR: 21 SUM_TIMER_WAIT: 15476754000000 MIN_TIMER_WAIT: 32264000000 AVG_TIMER_WAIT: 736988000000 MAX_TIMER_WAIT: 9723278000000 COUNT_READ: 11 SUM_TIMER_READ: 502860000000 MIN_TIMER_READ: 32264000000 AVG_TIMER_READ: 45714000000 MAX_TIMER_READ: 153656000000 COUNT_WRITE: 10 SUM_TIMER_WRITE: 14973894000000 MIN_TIMER_WRITE: 194628000000 AVG_TIMER_WRITE: 1497389000000 MAX_TIMER_WRITE: 9723278000000 COUNT_FETCH: 11 SUM_TIMER_FETCH: 502860000000 MIN_TIMER_FETCH: 32264000000 AVG_TIMER_FETCH: 45714000000 MAX_TIMER_FETCH: 153656000000 COUNT_INSERT: 10 SUM_TIMER_INSERT: 14973894000000 MIN_TIMER_INSERT: 194628000000 AVG_TIMER_INSERT: 1497389000000 MAX_TIMER_INSERT: 9723278000000 COUNT_UPDATE: 0 SUM_TIMER_UPDATE: 0 MIN_TIMER_UPDATE: 0 AVG_TIMER_UPDATE: 0 MAX_TIMER_UPDATE: 0 COUNT_DELETE: 0 SUM_TIMER_DELETE: 0 MIN_TIMER_DELETE: 0 AVG_TIMER_DELETE: 0 MAX_TIMER_DELETE: 0 1 row in set (0.01 sec)
[3 Mar 2015 8:49]
Marc ALFF
Hi Sergey, Your observation is correct that: 1) Events started with an old timer and ended with a new timer produce incorrect values when measured, polluting statistics 2) Statistics for events already measured are stored in the old timer unit, and never converted to the new timer unit, causing incorrect values to be displayed when setup_timer changes. 1) is a known limitation, documented here: http://dev.mysql.com/doc/refman/5.7/en/setup-timers-table.html " Modifications to the setup_timers table affect monitoring immediately. Events already in progress may use the original timer for the begin time and the new timer for the end time, which may lead to unpredictable results. If you make timer changes, you may want to use TRUNCATE TABLE to reset Performance Schema statistics. " 2) actually used to work in very early releases, which converted timer values to picoseconds when -- collecting -- the data, and is now broken in the current implementation, which convert timer values when --displaying -- the data, possibly using the wrong unit. The change in 2) was done in 2010 for performance overhead reasons, as part of general improvements to the aggregation tables in the performance schema. What was missed here is to clarify the documentation, because TRUNCATE TABLE is also needed to reset statistics for events already collected, when setup_timer changes. Changing to a documentation bug. Thanks for the report.
[17 Mar 2015 16:51]
Paul DuBois
Thank you for your bug report. This issue has been addressed in the documentation. The updated documentation will appear on our website shortly. Updated text for http://dev.mysql.com/doc/refman/5.7/en/setup-timers-table.html Modifications to the setup_timers table affect monitoring immediately. Events already measured are stored using the original timer unit, and events in progress may use the original timer for the begin time and the new timer for the end time. To avoid unpredictable results if you make timer changes, use TRUNCATE TABLE to reset Performance Schema statistics.