Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1.17
-
10.1.29, 10.1.30
Description
It seems MariaDB 10.x.y does not properly implement some part of performance_schema counters. I see that rows_examined, for example, are always zero, even though every instrument and consumer is enabled and statements obviously examined many rows.
Check the following simple test case:
openxs@ao756:~/dbs/maria10.1$ bin/mysql -uroot test
|
Reading table information for completion of table and column names
|
You can turn off this feature to get a quicker startup with -A
|
|
|
Welcome to the MariaDB monitor. Commands end with ; or \g.
|
Your MariaDB connection id is 2
|
Server version: 10.1.17-MariaDB MariaDB Server
|
|
|
Copyright (c) 2000, 2016, Oracle, MariaDB Corporation Ab and others.
|
|
|
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
|
|
|
MariaDB [test]> select @@performance_schema;
|
+----------------------+
|
| @@performance_schema |
|
+----------------------+
|
| 1 |
|
+----------------------+
|
1 row in set (0.00 sec)
|
|
|
MariaDB [test]> create table ttt(id int);
|
Query OK, 0 rows affected (0.28 sec)
|
|
|
MariaDB [test]> insert into ttt values(1);
|
Query OK, 1 row affected (0.06 sec)
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 1 row affected (0.05 sec)
|
Records: 1 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
\Query OK, 2 rows affected (0.03 sec)
|
Records: 2 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 4 rows affected (0.05 sec)
|
Records: 4 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 8 rows affected (0.05 sec)
|
Records: 8 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 16 rows affected (0.05 sec)
|
Records: 16 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 32 rows affected (0.05 sec)
|
Records: 32 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 64 rows affected (0.07 sec)
|
Records: 64 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 128 rows affected (0.06 sec)
|
Records: 128 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> select thread_id, sql_text, rows_examined from performance_schema.events_statements_history;
|
Empty set (0.00 sec)
|
|
|
MariaDB [test]> update performance_schema.setup_consumers set enabled='Yes';
|
Query OK, 8 rows affected (0.00 sec)
|
Rows matched: 12 Changed: 8 Warnings: 0
|
|
|
MariaDB [test]> update performance_schema.setup_instruments set enabled='Yes', timed='Yes';
|
Query OK, 430 rows affected (0.01 sec)
|
Rows matched: 660 Changed: 430 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 256 rows affected (0.13 sec)
|
Records: 256 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 512 rows affected (0.11 sec)
|
Records: 512 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 1024 rows affected (0.16 sec)
|
Records: 1024 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> insert into ttt select rand()*10000 from ttt;
|
Query OK, 2048 rows affected (0.24 sec)
|
Records: 2048 Duplicates: 0 Warnings: 0
|
|
|
MariaDB [test]> select thread_id, sql_text, rows_examined from performance_schema.events_statements_history;
|
+-----------+----------------------------------------------------------------------------+---------------+
|
| thread_id | sql_text | rows_examined |
|
+-----------+----------------------------------------------------------------------------+---------------+
|
| 24 | update performance_schema.setup_consumers set enabled='Yes' | 0 |
|
| 24 | update performance_schema.setup_instruments set enabled='Yes', timed='Yes' | 0 |
|
| 24 | insert into ttt select rand()*10000 from ttt | 0 |
|
| 24 | insert into ttt select rand()*10000 from ttt | 0 |
|
| 24 | insert into ttt select rand()*10000 from ttt | 0 |
|
| 24 | insert into ttt select rand()*10000 from ttt | 0 |
|
+-----------+----------------------------------------------------------------------------+---------------+
|
6 rows in set (0.00 sec)
|
With a similar test case on Percona Server 5.7.13-6 we get:
mysql> select thread_id, sql_text, rows_examined from performance_schema.events_statements_history;
|
+-----------+---------------------------------------------------------------------------------------------+---------------+
|
| thread_id | sql_text | rows_examined |
|
+-----------+---------------------------------------------------------------------------------------------+---------------+
|
| 30 | desc perfromance_schema.events_statements_history | 0 |
|
| 30 | desc performance_schema.events_statements_history | 41 |
|
| 30 | select thread_id, sql_text, rows_examined from perfromance_schema.events_statements_history | 0 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 32 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 64 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 128 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 256 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 512 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 1024 |
|
| 30 | insert into ttt select rand()*10000 from ttt | 2048 |
|
+-----------+---------------------------------------------------------------------------------------------+---------------+
|
10 rows in set (0.01 sec)
|
Please take a look at this fix since it moves the line blamed to youself
In fact the rows_examined is always 0 in Maria, not only in this bug's case.
http://lists.askmonty.org/pipermail/commits/2017-November/011612.html
It seems suspicious that insert ..select.. examines twice the number of inserted records. But that's how Maria handles this. We create the temporary table then read it again, so we examite every inserted record twice.