Bug #91541 "Flush status" statement adds twice to global values
Submitted: 3 Jul 2018 19:53 Modified: 30 Jan 2019 14:43
Reporter: Carlos Tutte Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Information schema Severity:S3 (Non-critical)
Version:5.7.22, 8.0.11 OS:Any
Assigned to: CPU Architecture:Any

[3 Jul 2018 19:53] Carlos Tutte
Description:
Description: A statement executed counts twice when adding to global status if "flush status" is executed from a different session.
The count is updated once when the statement is executed excuted, and once again when "flush status;" is executed.
This has been tested for parameters: 'slow_queries', 'questions', 'bytes_received', 'Bytes_sent'

How to repeat:
--pre requisites:
-- have long_query_time = 2

mysql [localhost] {msandbox} ((none)) > show global status like 'Slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 0     |
+---------------+-------+
1 row in set (0.00 sec)

-- Run a query to increase 'slow_queries' counter
mysql [localhost] {msandbox} ((none)) > select sleep (2);
+-----------+
| sleep (2) |
+-----------+
|         0 |
+-----------+
1 row in set (2.00 sec)

-- check slow_queries have increased
mysql [localhost] {msandbox} ((none)) > show global status like 'Slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 1     |
+---------------+-------+
1 row in set (0.00 sec)

mysql [localhost] {msandbox} ((none)) > exit
Bye
carlos.tutte@bm-support01:~/sandboxes/5.7.22$ ./use 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 9
Server version: 5.7.22 MySQL Community Server (GPL)

Copyright (c) 2000, 2018, 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 [localhost] {msandbox} ((none)) > show global status like 'Slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 1     |
+---------------+-------+
1 row in set (0.00 sec)

mysql [localhost] {msandbox} ((none)) > select * from performance_schema.status_by_user where variable_name in ('Slow_queries');
+----------+---------------+----------------+
| USER     | VARIABLE_NAME | VARIABLE_VALUE |
+----------+---------------+----------------+
| NULL     | Slow_queries  | 0              |
| msandbox | Slow_queries  | 1              |
+----------+---------------+----------------+
2 rows in set (0.00 sec)

mysql [localhost] {msandbox} ((none)) > flush status;
Query OK, 0 rows affected (0.00 sec)

mysql [localhost] {msandbox} ((none)) > select * from performance_schema.status_by_user where variable_name in ('Slow_queries');
+----------+---------------+----------------+
| USER     | VARIABLE_NAME | VARIABLE_VALUE |
+----------+---------------+----------------+
| NULL     | Slow_queries  | 0              |
| msandbox | Slow_queries  | 0              |
+----------+---------------+----------------+
2 rows in set (0.00 sec)

-- slow_queries have increased twice
mysql [localhost] {msandbox} ((none)) > show global status like 'Slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 2     |
+---------------+-------+
1 row in set (0.00 sec)

Suggested fix:
Check under which conditions "flush status" should add to global variables, as status variables are already added to global after every statement execution.
[4 Jul 2018 9:53] MySQL Verification Team
Hello Carlos,

Thank you for the report.

Thanks,
Umesh
[26 Jul 2018 11:44] Yura Sorokin
an MTR test case which simulates the problem

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug91541.test (application/octet-stream, text), 3.16 KiB.

[26 Jul 2018 11:47] Yura Sorokin
Here is a simplified scenario:
1. A new connection 'con1' is opened.
  "SHOW GLOBAL STATUS LIKE 'Slow_queries'" is executed and returns 0.
2. Another connection 'con2' is opened and a very slow query like
  "SELECT SLEEP(10)" is executed. After that both
  "SHOW GLOBAL STATUS LIKE 'Slow_queries'" and
  "SHOW SESSION STATUS LIKE 'Slow_queries'" (for 'con2') return 1.
3. 'con2' is closed.
4. In 'con1' "SHOW GLOBAL STATUS LIKE 'Slow_queries'" is executed and
   returns 1 as expected. Moreover "SHOW SESSION STATUS LIKE 'Slow_queries'"
   also returns expected value 0.
5. "FLUSH STATUS" is executed in 'con1' and
   "SHOW GLOBAL STATUS LIKE 'Slow_queries'" now returns 2.
[27 Jul 2018 12:54] Yura Sorokin
This happens because when a connection is closed 'THD::release_resources()'
method is called which in turn calls 
"add_to_status(&global_status_var, &status_var, false);".
The last parameter 'false' indicates that session values must not be reset
after aggregation to global ones. The comment in the code says that the
status values are not reset so that they can still be read by performance
schema.

On the other hand, when "FLUSH STATUS" is executed, 'refresh_status()'
function is called which in turn calls 'reset_pfs_status_stats()'.
This function propagates all PFS stats accumulated on different levels:
PFS_thread -> PFS_account -> PFS_user -> PFS_host -> Global status vars.
However, it does not take into account that some values have already been
added to global status vars when other connections were closed.

Fix:
'PFS_status_stats' class extended with additional set of counters
'm_stats_aggregated_in_global' that will be used similarly to 'm_stats'
to accumulate values that have already been added to global status vars.
'PFS_status_stats::aggregate_from()' method is extended with additional
boolean parameter 'already_aggregated' which determines to which array
('m_stats' or 'm_stats_aggregated_in_global') the passed values must be
accumulated. This method is now called with 'thd->status_var_aggregated'
passed as this boolean parameter.
On the other hand 'PFS_status_stats::aggregate_to()' methods is also
extended with additional boolean parameter 'include_aggregated' indicating
whether stats already aggregated in global status vars should be added to
the output object. This allows to eliminate double aggregation when this
methos is called for the global status vars
"xxx.aggregate_to(&global_status_var, false);". For other local calculations
it is called with 'true'
"xxx.aggregate_to(&yyy, true);".
[27 Jul 2018 12:55] Yura Sorokin
Suggested fix for the 5.7 branch

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug91541_5_7.diff (application/octet-stream, text), 10.31 KiB.

[27 Jul 2018 12:55] Yura Sorokin
Suggested fix for the 8.0 branch

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug91541_8_0.diff (application/octet-stream, text), 11.63 KiB.

[30 Jan 2019 14:43] Paul DuBois
Posted by developer:
 
Fixed in 5.7.26, 8.0.16.

During FLUSH STATUS execution, the Performance Schema unnecessarily
aggregated session status to global status, causing double counts for
some status variables.