Description:
Inside a single invocation of a stored program, every nested statement records the invocation's cumulative ROWS_EXAMINED instead of the rows that statement examined. events_statements_summary_by_program.SUM_ROWS_EXAMINED then sums those running totals, so the per-program figure counts the same rows repeatedly — once more for each statement that follows the one that read them and showing total count wrongly.
How to repeat:
mysql> DROP DATABASE IF EXISTS psbug;
Query OK, 0 rows affected, 1 warning (0.01 sec)
mysql> CREATE DATABASE psbug;
Query OK, 1 row affected (0.01 sec)
mysql> CREATE TABLE psbug.t (n INT NOT NULL PRIMARY KEY);
INSERT INTO psbug.t (n) VALUES (1),(2),(3),(4),(5),(6),(7),(8),(9),(10);Query OK, 0 rows affected (0.02 sec)
mysql> INSERT INTO psbug.t (n) VALUES (1),(2),(3),(4),(5),(6),(7),(8),(9),(10);
Query OK, 10 rows affected (0.01 sec)
Records: 10 Duplicates: 0 Warnings: 0
mysql> DELIMITER $$
mysql> CREATE PROCEDURE psbug.p()
-> BEGIN
-> SELECT COUNT(*) INTO @sink FROM (SELECT n FROM psbug.t LIMIT 10) x;
-> SELECT 1 INTO @sink;
-> SELECT 2 INTO @sink;
-> SELECT 3 INTO @sink;
-> END$$
DELIMITER ;Query OK, 0 rows affected (0.03 sec)
mysql> DELIMITER ;
mysql> UPDATE performance_schema.setup_consumers SET enabled = 'YES' WHERE name = 'events_statements_history_long';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
mysql> TRUNCATE performance_schema.events_statements_history_long;
Query OK, 0 rows affected (0.01 sec)
mysql> TRUNCATE performance_schema.events_statements_summary_by_program;
Query OK, 0 rows affected (0.00 sec)
mysql> SELECT nesting_event_level AS lvl, rows_examined, sql_text
-> FROM performance_schema.events_statements_history_long
-> WHERE object_schema = 'psbug' OR sql_text LIKE 'CALL psbug%'
-> ORDER BY event_id;
Empty set (0.00 sec)
mysql> SELECT object_name, count_star, sum_rows_examined
-> FROM performance_schema.events_statements_summary_by_program
-> WHERE object_schema = 'psbug';
Empty set (0.00 sec)
mysql> CALL psbug.p();
Query OK, 1 row affected (0.00 sec)
mysql> SELECT nesting_event_level AS lvl, rows_examined, sql_text
-> FROM performance_schema.events_statements_history_long
-> WHERE object_schema = 'psbug' OR sql_text LIKE 'CALL psbug%'
-> ORDER BY event_id;
+------+---------------+--------------------------------------------------------------------+
| lvl | rows_examined | sql_text |
+------+---------------+--------------------------------------------------------------------+
| 0 | 0 | CALL psbug.p() |
| 1 | 10 | SELECT COUNT(*) INTO @sink FROM (SELECT n FROM psbug.t LIMIT 10) x |
| 1 | 11 | SELECT 1 INTO @sink |
| 1 | 12 | SELECT 2 INTO @sink |
| 1 | 13 | SELECT 3 INTO @sink |
+------+---------------+--------------------------------------------------------------------+
5 rows in set (0.00 sec)
mysql> SELECT object_name, count_star, sum_rows_examined
-> FROM performance_schema.events_statements_summary_by_program
-> WHERE object_schema = 'psbug';
+-------------+------------+-------------------+
| object_name | count_star | sum_rows_examined |
+-------------+------------+-------------------+
| p | 1 | 46 |
+-------------+------------+-------------------+
1 row in set (0.00 sec)
Suggested fix:
It should record monitoring stats properly.
Description: Inside a single invocation of a stored program, every nested statement records the invocation's cumulative ROWS_EXAMINED instead of the rows that statement examined. events_statements_summary_by_program.SUM_ROWS_EXAMINED then sums those running totals, so the per-program figure counts the same rows repeatedly — once more for each statement that follows the one that read them and showing total count wrongly. How to repeat: mysql> DROP DATABASE IF EXISTS psbug; Query OK, 0 rows affected, 1 warning (0.01 sec) mysql> CREATE DATABASE psbug; Query OK, 1 row affected (0.01 sec) mysql> CREATE TABLE psbug.t (n INT NOT NULL PRIMARY KEY); INSERT INTO psbug.t (n) VALUES (1),(2),(3),(4),(5),(6),(7),(8),(9),(10);Query OK, 0 rows affected (0.02 sec) mysql> INSERT INTO psbug.t (n) VALUES (1),(2),(3),(4),(5),(6),(7),(8),(9),(10); Query OK, 10 rows affected (0.01 sec) Records: 10 Duplicates: 0 Warnings: 0 mysql> DELIMITER $$ mysql> CREATE PROCEDURE psbug.p() -> BEGIN -> SELECT COUNT(*) INTO @sink FROM (SELECT n FROM psbug.t LIMIT 10) x; -> SELECT 1 INTO @sink; -> SELECT 2 INTO @sink; -> SELECT 3 INTO @sink; -> END$$ DELIMITER ;Query OK, 0 rows affected (0.03 sec) mysql> DELIMITER ; mysql> UPDATE performance_schema.setup_consumers SET enabled = 'YES' WHERE name = 'events_statements_history_long'; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 mysql> TRUNCATE performance_schema.events_statements_history_long; Query OK, 0 rows affected (0.01 sec) mysql> TRUNCATE performance_schema.events_statements_summary_by_program; Query OK, 0 rows affected (0.00 sec) mysql> SELECT nesting_event_level AS lvl, rows_examined, sql_text -> FROM performance_schema.events_statements_history_long -> WHERE object_schema = 'psbug' OR sql_text LIKE 'CALL psbug%' -> ORDER BY event_id; Empty set (0.00 sec) mysql> SELECT object_name, count_star, sum_rows_examined -> FROM performance_schema.events_statements_summary_by_program -> WHERE object_schema = 'psbug'; Empty set (0.00 sec) mysql> CALL psbug.p(); Query OK, 1 row affected (0.00 sec) mysql> SELECT nesting_event_level AS lvl, rows_examined, sql_text -> FROM performance_schema.events_statements_history_long -> WHERE object_schema = 'psbug' OR sql_text LIKE 'CALL psbug%' -> ORDER BY event_id; +------+---------------+--------------------------------------------------------------------+ | lvl | rows_examined | sql_text | +------+---------------+--------------------------------------------------------------------+ | 0 | 0 | CALL psbug.p() | | 1 | 10 | SELECT COUNT(*) INTO @sink FROM (SELECT n FROM psbug.t LIMIT 10) x | | 1 | 11 | SELECT 1 INTO @sink | | 1 | 12 | SELECT 2 INTO @sink | | 1 | 13 | SELECT 3 INTO @sink | +------+---------------+--------------------------------------------------------------------+ 5 rows in set (0.00 sec) mysql> SELECT object_name, count_star, sum_rows_examined -> FROM performance_schema.events_statements_summary_by_program -> WHERE object_schema = 'psbug'; +-------------+------------+-------------------+ | object_name | count_star | sum_rows_examined | +-------------+------------+-------------------+ | p | 1 | 46 | +-------------+------------+-------------------+ 1 row in set (0.00 sec) Suggested fix: It should record monitoring stats properly.