Bug #76428 pre filtering is not working as it should in MySQL 5.7.6
Submitted: 22 Mar 2015 16:07 Modified: 31 Mar 2015 12:22
Reporter: Marco Tusa Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Performance Schema Severity:S2 (Serious)
Version:5.7.6-m16-log MySQL Community Server (GP OS:Any
Assigned to: Marc ALFF CPU Architecture:Any
Tags: filtering, monitor, performance_schema

[22 Mar 2015 16:07] Marco Tusa
Description:
Using ROOT user, and just selecting information from the events_statements_history table will cause the Performance schema to trace the action ALSO if the user AND the schema should be excluded.

How to repeat:
(root@localhost) [performance_schema]>select * from setup_objects;
+-------------+--------------------+-------------+---------+-------+
| OBJECT_TYPE | OBJECT_SCHEMA      | OBJECT_NAME | ENABLED | TIMED |
+-------------+--------------------+-------------+---------+-------+
| EVENT       | mysql              | %           | NO      | NO    |
| EVENT       | performance_schema | %           | NO      | NO    |<--- Excluded
| EVENT       | information_schema | %           | NO      | NO    |
| EVENT       | %                  | %           | YES     | YES   |
| FUNCTION    | mysql              | %           | NO      | NO    |
| FUNCTION    | performance_schema | %           | NO      | NO    |<--- Excluded
| FUNCTION    | information_schema | %           | NO      | NO    |
| FUNCTION    | %                  | %           | YES     | YES   |
| PROCEDURE   | mysql              | %           | NO      | NO    |
| PROCEDURE   | performance_schema | %           | NO      | NO    |<--- Excluded
| PROCEDURE   | information_schema | %           | NO      | NO    |
| PROCEDURE   | %                  | %           | YES     | YES   |
| TABLE       | mysql              | %           | NO      | NO    |
| TABLE       | performance_schema | %           | NO      | NO    |<--- Excluded
| TABLE       | information_schema | %           | NO      | NO    |
| TABLE       | %                  | %           | YES     | YES   |
| TRIGGER     | mysql              | %           | NO      | NO    |
| TRIGGER     | performance_schema | %           | NO      | NO    |<--- Excluded
| TRIGGER     | information_schema | %           | NO      | NO    |
| TRIGGER     | %                  | %           | YES     | YES   |
+-------------+--------------------+-------------+---------+-------+
20 rows in set (0.00 sec)

(root@localhost) [performance_schema]>select * from setup_actors;
+------+--------+------+---------+
| HOST | USER   | ROLE | ENABLED |
+------+--------+------+---------+
| %    | %      | %    | NO      |
| %    | stress | %    | YES     | <--- Only USER stress should be catch
+------+--------+------+---------+

+----------------------------------+---------+
| NAME                             | ENABLED |
+----------------------------------+---------+
| events_stages_current            | NO      |
| events_stages_history            | NO      |
| events_stages_history_long       | NO      |
| events_statements_current        | YES     |
| events_statements_history        | YES     | <---- History is activated
| events_statements_history_long   | NO      |
| events_transactions_current      | YES     |
| events_transactions_history      | NO      |
| events_transactions_history_long | NO      |
| events_waits_current             | NO      |
| events_waits_history             | NO      |
| events_waits_history_long        | NO      |
| global_instrumentation           | YES     |
| thread_instrumentation           | YES     |
| statements_digest                | YES     |
+----------------------------------+---------+

Using ROOT user, and just selecting information from the events_statements_history table will cause the Performance schema to trace the action ALSO if the user AND the schema should be excluded.

(root@localhost) [performance_schema]>truncate table events_statements_history;
Query OK, 0 rows affected (0.00 sec)

(root@localhost) [performance_schema]>

FIRST SELECT will report empty given the TRUNCATE;

(root@localhost) [performance_schema]>select TH.PROCESSLIST_USER,ISPL.HOST,ISPL.DB,ISPL.User, TH.PROCESSLIST_ID, ESH.* from information_schema.processlist ISPL JOIN threads TH on ISPL.ID=TH.PROCESSLIST_ID JOIN events_statements_history ESH ON TH.THREAD_ID=ESH.THREAD_ID  Where (EVENT_NAME like '%select%' OR EVENT_NAME like '%insert%'  OR EVENT_NAME like '%update%'  OR EVENT_NAME like '%delete%')\G
Empty set (0.00 sec)

Query again ...

(root@localhost) [performance_schema]>select TH.PROCESSLIST_USER,ISPL.HOST,ISPL.DB,ISPL.User, TH.PROCESSLIST_ID, ESH.* from information_schema.processlist ISPL JOIN threads TH on ISPL.ID=TH.PROCESSLIST_ID JOIN events_statements_history ESH ON TH.THREAD_ID=ESH.THREAD_ID  Where (EVENT_NAME like '%select%' OR EVENT_NAME like '%insert%'  OR EVENT_NAME like '%update%'  OR EVENT_NAME like '%delete%')\G
*************************** 1. row ***************************
       PROCESSLIST_USER: root                <---------- ROOT should NOT be included
                   HOST: localhost
                     DB: performance_schema  <---------- Performance Schema should NOT be included 
                   User: root
         PROCESSLIST_ID: 7
              THREAD_ID: 38
               EVENT_ID: 393636
           END_EVENT_ID: 393636
             EVENT_NAME: statement/sql/select
                 SOURCE: socket_connection.cc:98
            TIMER_START: 5050240377023000
              TIMER_END: 5050241480813000
             TIMER_WAIT: 1103790000
              LOCK_TIME: 523000000
               SQL_TEXT: select TH.PROCESSLIST_USER,ISPL.HOST,ISPL.DB,ISPL.User, TH.PROCESSLIST_ID, ESH.* from information_schema.processlist ISPL JOIN threads TH on ISPL.ID=TH.PROCESSLIST_ID JOIN events_statements_history ESH ON TH.THREAD_ID=ESH.THREAD_ID  Where (EVENT_NAME like '%select%' OR EVENT_NAME like '%insert%'  OR EVENT_NAME like '%update%'  OR EVENT_NAME like '%delete%')
                 DIGEST: 40d8cfb76de3242d83aed5ffa241d1e7
            DIGEST_TEXT: SELECT `TH` . `PROCESSLIST_USER` , `ISPL` . `HOST` , `ISPL` . `DB` , `ISPL` . `User` , `TH` . `PROCESSLIST_ID` , `ESH` . * FROM `information_schema` . `processlist` `ISPL` JOIN `threads` `TH` ON `ISPL` . `ID` = `TH` . `PROCESSLIST_ID` JOIN `events_statements_history` `ESH` ON `TH` . `THREAD_ID` = `ESH` . `THREAD_ID` WHERE ( `EVENT_NAME` LIKE ? OR `EVENT_NAME` LIKE ? OR `EVENT_NAME` LIKE ? OR `EVENT_NAME` LIKE ? ) 
         CURRENT_SCHEMA: performance_schema <---------- Performance Schema should NOT be included 
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 0
          ROWS_EXAMINED: 38
CREATED_TMP_DISK_TABLES: 1
     CREATED_TMP_TABLES: 1
       SELECT_FULL_JOIN: 2
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 0
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 1
      SORT_MERGE_PASSES: 0
             SORT_RANGE: 0
              SORT_ROWS: 0
              SORT_SCAN: 0
          NO_INDEX_USED: 1
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: NULL
     NESTING_EVENT_TYPE: NULL
    NESTING_EVENT_LEVEL: 0
1 row in set (0.00 sec)

As such only way to filter is post filtering like:
select TH.PROCESSLIST_USER,ISPL.HOST,ISPL.DB,ISPL.User, TH.PROCESSLIST_ID, ESH.* from information_schema.processlist ISPL JOIN threads TH on ISPL.ID=TH.PROCESSLIST_ID JOIN events_statements_history ESH ON TH.THREAD_ID=ESH.THREAD_ID  Where  ISPL.User='stress' AND (EVENT_NAME like '%select%' OR EVENT_NAME like '%insert%'  OR EVENT_NAME like '%update%'  OR EVENT_NAME like '%delete%')\G

For more information the EXPLAIN as well:
root@localhost) [performance_schema]>explain FORMAT=JSON select TH.PROCESSLIST_USER,ISPL.HOST,ISPL.DB,ISPL.User, TH.PROCESSLIST_ID, ESH.* from information_schema.processlist ISPL JOIN threads TH on ISPL.ID=TH.PROCESSLIST_ID JOIN events_statements_history ESH ON TH.THREAD_ID=ESH.THREAD_ID  Where (EVENT_NAME like '%select%' OR EVENT_NAME like '%insert%'  OR EVENT_NAME like '%update%'  OR EVENT_NAME like '%delete%')\G
*************************** 1. row ***************************
EXPLAIN: {
  "query_block": {
    "select_id": 1,
    "cost_info": {
      "query_cost": "10281.52"
    },
    "nested_loop": [
      {
        "table": {
          "table_name": "ISPL",
          "access_type": "ALL",
          "used_columns": [
            "ID",
            "USER",
            "HOST",
            "DB",
            "COMMAND",
            "TIME",
            "STATE",
            "INFO"
          ]
        }
      },
      {
        "table": {
          "table_name": "TH",
          "access_type": "ALL",
          "rows_examined_per_scan": 256,
          "rows_produced_per_join": 51,
          "filtered": "10.00",
          "using_join_buffer": "Block Nested Loop",
          "cost_info": {
            "read_cost": "1.00",
            "eval_cost": "10.24",
            "prefix_cost": "104.80",
            "data_read_per_join": "66K"
          },
          "used_columns": [
            "THREAD_ID",
            "PROCESSLIST_ID",
            "PROCESSLIST_USER"
          ],
          "attached_condition": "(`performance_schema`.`TH`.`PROCESSLIST_ID` = `ISPL`.`ID`)"
        }
      },
      {
        "table": {
          "table_name": "ESH",
          "access_type": "ALL",
          "rows_examined_per_scan": 2560,
          "rows_produced_per_join": 4924,
          "filtered": "3.76",
          "using_join_buffer": "Block Nested Loop",
          "cost_info": {
            "read_cost": "328.66",
            "eval_cost": "984.81",
            "prefix_cost": "10281.52",
            "data_read_per_join": "9M"
          },
          "used_columns": [
            "THREAD_ID",
            "EVENT_ID",
            "END_EVENT_ID",
            "EVENT_NAME",
            "SOURCE",
            "TIMER_START",
            "TIMER_END",
            "TIMER_WAIT",
            "LOCK_TIME",
            "SQL_TEXT",
            "DIGEST",
            "DIGEST_TEXT",
            "CURRENT_SCHEMA",
            "OBJECT_TYPE",
            "OBJECT_SCHEMA",
            "OBJECT_NAME",
            "OBJECT_INSTANCE_BEGIN",
            "MYSQL_ERRNO",
            "RETURNED_SQLSTATE",
            "MESSAGE_TEXT",
            "ERRORS",
            "WARNINGS",
            "ROWS_AFFECTED",
            "ROWS_SENT",
            "ROWS_EXAMINED",
            "CREATED_TMP_DISK_TABLES",
            "CREATED_TMP_TABLES",
            "SELECT_FULL_JOIN",
            "SELECT_FULL_RANGE_JOIN",
            "SELECT_RANGE",
            "SELECT_RANGE_CHECK",
            "SELECT_SCAN",
            "SORT_MERGE_PASSES",
            "SORT_RANGE",
            "SORT_ROWS",
            "SORT_SCAN",
            "NO_INDEX_USED",
            "NO_GOOD_INDEX_USED",
            "NESTING_EVENT_ID",
            "NESTING_EVENT_TYPE",
            "NESTING_EVENT_LEVEL"
          ],
          "attached_condition": "((`performance_schema`.`ESH`.`THREAD_ID` = `performance_schema`.`TH`.`THREAD_ID`) and ((`performance_schema`.`ESH`.`EVENT_NAME` like '%select%') or (`performance_schema`.`ESH`.`EVENT_NAME` like '%insert%') or (`performance_schema`.`ESH`.`EVENT_NAME` like '%update%') or (`performance_schema`.`ESH`.`EVENT_NAME` like '%delete%')))"
        }
      }
    ]
  }
}

HOW to repeat:
1) use 5.7.6 m-16
2) update setup_actors set ENABLED='NO' where user='%'; 
3) insert into setup_actors values('%','stress','%','YES'); 
4) activate consumer like update setup_consumers set ENABLED='YES' where NAME='events_statements_history';
5) disable some instruments and keep only:
	(root@localhost) [performance_schema]>select * from setup_instruments where ENABLED='YES';
+-------------------------------+---------+-------+
| NAME                          | ENABLED | TIMED |
+-------------------------------+---------+-------+
| statement/sql/select          | YES     | YES   |
| statement/sql/update          | YES     | YES   |
| statement/sql/insert          | YES     | YES   |
| statement/sql/insert_select   | YES     | YES   |
| statement/sql/delete          | YES     | YES   |
| statement/sql/replace_select  | YES     | YES   |
| statement/sql/delete_multi    | YES     | YES   |
| statement/sql/update_multi    | YES     | YES   |
| statement/abstract/Query      | YES     | YES   |
| statement/abstract/new_packet | YES     | YES   |
| statement/abstract/relay_log  | YES     | YES   |
+-------------------------------+---------+-------+
6) truncate table events_statements_history;
7) run twice :
select TH.PROCESSLIST_USER,ISPL.HOST,ISPL.DB, TH.PROCESSLIST_ID, ESH.* from events_statements_history ESH, threads TH, information_schema.processlist ISPL where TH.THREAD_ID=ESH.THREAD_ID AND TH.PROCESSLIST_ID=ISPL.ID AND EVENT_NAME like '%select%' OR EVENT_NAME like '%insert%'  OR EVENT_NAME like '%update%'  OR EVENT_NAME like '%delete%'\G
[31 Mar 2015 7:46] Marc ALFF
This is not a bug.

After the following steps:

1) use 5.7.6 m-16
2) update setup_actors set ENABLED='NO' where user='%'; 
3) insert into setup_actors values('%','stress','%','YES'); 

table setup_actors indicate that **NEW** sessions from anyone but 'stress' are not instrumented, so a new session for user root@localhost will not be instrumented.

This has no effect on sessions already connected.

To disable instrumentation for connections already established for root@localhost,
use:
  UPDATE performance_schema.threads set INSTRUMENTED='NO' WHERE ...
[31 Mar 2015 11:53] Marco Tusa
True ... I already got that a NEW session will filter but the existing one, the one that set the filter will not.
This is NOT in line with the documentation, and is NOT what should happen given I could require to use the filter inside the existing session.

As such this is a bug, of a feature that require better implementation.
[31 Mar 2015 12:22] Marc ALFF
Please refer to:

http://dev.mysql.com/doc/refman/5.7/en/setup-actors-table.html

And in particular to the paragraph:

"
Modifications to the setup_actors table affect only foreground threads created subsequent to the modification, not existing threads.
"

About the following comment:
"
This is NOT in line with the documentation
"
see the quote above.

About:
"
and is NOT what should happen given I could require to use the filter inside the existing session.
"
There is only one setup_actors table, and the content is global for the server.
Which session performs an update is irrelevant, and there is no reason to change the behavior of the current session after a change to setup_actors.

Unless I misunderstood the bug report (please clarify then),
the performance schema works as designed and documented.