Tuesday, April 1, 2014

MySQL Performance Schema : Prepared Statements Instrumentation.

A new feature in MySQL Performance Schema is added in DMR 5.7.4. Instrumentation for Prepared statements. This instrumentation gives details of PREPARE and EXECUTE statistics for a prepared statement.

New Table
New table added to display run time statistics of Prepared Statements is named as prepared_statements_instances.

mysql> describe performance_schema.prepared_statements_instances;
+-----------------------+------------------------------------------------------
| Field                 | Type                                                
+-----------------------+------------------------------------------------------ 
| OBJECT_INSTANCE_BEGIN | bigint(20) unsigned                                 
| STATEMENT_ID          | bigint(20) unsigned                                 
| STATEMENT_NAME        | varchar(64)                                         
| SQL_TEXT              | longtext                                            
| OWNER_THREAD_ID       | bigint(20) unsigned                                 
| OWNER_EVENT_ID        | bigint(20) unsigned                                 
| OWNER_OBJECT_TYPE     | enum('EVENT','FUNCTION','PROCEDURE','TABLE','TRIGGER')
| OWNER_OBJECT_SCHEMA   | varchar(64)                                          
| OWNER_OBJECT_NAME     | varchar(64)                                          
| TIMER_PREPARE         | bigint(20) unsigned                                  
| COUNT_REPREPARE       | bigint(20) unsigned                                  
| COUNT_EXECUTE         | bigint(20) unsigned                                  
<Other Execution Stats>

+-----------------------+------------------------------------------------------
35 rows in set (0.05 sec)

An Example
Here is an example for execution stats of a prepared statement to show how this table looks like :

mysql> prepare stmt1 from "select * from test.t1";
Query OK, 0 rows affected (0.01 sec)
Statement prepared

mysql> execute stmt1; 

+------+
| ch   |
+------+
|    2 |
+------+
1 row in set (0.01 sec)


mysql> select <snip> from performance_schema.events_statements_history_long\G
*************************** 1. row ***************************
 THREAD_ID: 20
  EVENT_ID: 4
EVENT_NAME: statement/sql/prepare_sql
  SQL_TEXT: prepare stmt1 from "select * from test.t1"
*************************** 2. row ***************************
 THREAD_ID: 20
  EVENT_ID: 19
EVENT_NAME: statement/sql/execute_sql
  SQL_TEXT: execute stmt1

mysql> select <snip> from performance_schema.prepared_statements_instances\G 

*************************** 1. row ***************************
OBJECT_INSTANCE_BEGIN: 140646757207136
         STATEMENT_ID: 1
       STATEMENT_NAME: stmt1
             SQL_TEXT: select * from test.t1
      OWNER_THREAD_ID: 20
       OWNER_EVENT_ID: 4
    OWNER_OBJECT_TYPE: NULL
  OWNER_OBJECT_SCHEMA: NULL
    OWNER_OBJECT_NAME: NULL
        TIMER_PREPARE: 3481513000
      COUNT_REPREPARE: 0
        COUNT_EXECUTE: 1
1 row in set (0.00 sec)


Now, it can be seen above that 'stmt1' is prepared in thread with id '20', and the event which prepared it has id '4'. This information is shown in preapred_statements_instances table i.e. from this table we can relate that this particular prepared statement is prepared by which statement execution and from which thread. TIMER_PREPARE shows the time it took to prepare the statement. And once executed, its execution stats get collected (like COUNT_EXECUTE here).

Prepared statement within Stored Procedure
Things to be noted in above examples are the columns : OWNER_OBJECT_TYPE/SCHEMA/NAME. These columns are shown as NULL here because this stmt1 is not prepared inside any stored procedure. Had it been prepared inside a stored procedure, these column would have been populated with its details. For example :

mysql> delimiter |
mysql> CREATE PROCEDURE test.p1 () BEGIN prepare stmt1 from "SELECT * FROM t1"; END|

Query OK, 0 rows affected (0.00 sec)

mysql> delimiter ;
mysql> call test.p1();

Query OK, 0 rows affected (0.00 sec)

mysql> execute stmt1;

+------+
| ch   |
+------+
|    2 |
+------+
1 row in set (0.00 sec)

mysql> select <snip> from performance_schema.events_statements_history_long\G
<snip>
*************************** 2. row ***************************
 THREAD_ID: 20
 EVENT_ID: 4
 EVENT_NAME: statement/sql/create_procedure
 SQL_TEXT: CREATE PROCEDURE test.p1 () BEGIN prepare stmt1 from "SELECT * FROM t1"; END
<snip>

*************************** 4. row ***************************
 THREAD_ID: 20
 EVENT_ID: 33
 EVENT_NAME: statement/sql/call_procedure
 SQL_TEXT: call test.p1()


mysql> select <snip> from performance_schema.prepared_statements_instances\G
*************************** 1. row ***************************
OBJECT_INSTANCE_BEGIN: 140483816899296
         STATEMENT_ID: 1
       STATEMENT_NAME: stmt1
             SQL_TEXT: SELECT * FROM t1
      OWNER_THREAD_ID: 20
       OWNER_EVENT_ID: 33     

    OWNER_OBJECT_TYPE: PROCEDURE
  OWNER_OBJECT_SCHEMA: test
    OWNER_OBJECT_NAME: p1
        TIMER_PREPARE: 3174380000
      COUNT_REPREPARE: 0
        COUNT_EXECUTE: 1
1 row in set (0.00 sec)


Note that event which created the procedure is '4' but the event which prepared the statement stmt1 i.e. call to procedure p1 event is '33' and that is the OWNER_EVENT_ID for stmt1 in prepared_statements_instances.


COUNT_REPREPARE Column
When metadata of tables or views, which are referred to by a prepared statement, changes, it causes automatic repreparation of the prepared statement when it is next executed. COUNT_REPREPARE column here denotes how many time this prepared statement has been reprepared. For Ex:

mysql> create table test.t1 (c1 int, c2 int);
Query OK, 0 rows affected (0.25 sec)

mysql> insert into test.t1 values ('1', '2');
Query OK, 1 row affected (0.06 sec)

mysql> prepare stmt1 from "select * from test.t1";

Query OK, 0 rows affected (0.00 sec)
Statement prepared

mysql> select <snip> from performance_schema.prepared_statements_instances\G
*************************** 1. row ***************************
       STATEMENT_NAME: stmt1
             SQL_TEXT: select * from test.t1
      COUNT_REPREPARE: 0
        COUNT_EXECUTE: 0
1 row in set (0.00 sec)


mysql> alter table test.t1 drop column c2;
Query OK, 0 rows affected (0.42 sec)
Records: 0  Duplicates: 0  Warnings: 0


mysql> execute stmt1;
+------+

| c1   |
+------+
|    1 |
+------+
1 row in set (0.01 sec)


mysql> select <snip> from performance_schema.prepared_statements_instances\G
*************************** 1. row ***************************
       STATEMENT_NAME: stmt1
             SQL_TEXT: select * from test.t1
      COUNT_REPREPARE: 1
        COUNT_EXECUTE: 1
1 row in set (0.00 sec)


Deleting a Prepared Statement
Dropping a prepared statement: Once a prepared statement is created/executed, its statistics are captured in P_S. Now when that statement is dropped (deleted) corresponding statistics are deleted from P_S table. For ex: 

mysql> prepare stmt1 from "select * from test.t1";
Query OK, 0 rows affected (0.00 sec)
Statement prepared

mysql> select <snip> from performance_schema.prepared_statements_instances\G
*************************** 1. row ***************************
OBJECT_INSTANCE_BEGIN: 139695153515552
         STATEMENT_ID: 1
       STATEMENT_NAME: stmt1
             SQL_TEXT: select * from test.t1
      OWNER_THREAD_ID: 20
       OWNER_EVENT_ID: 2
    OWNER_OBJECT_TYPE: NULL
  OWNER_OBJECT_SCHEMA: NULL
    OWNER_OBJECT_NAME: NULL
        TIMER_PREPARE: 3444041000
      COUNT_REPREPARE: 0
        COUNT_EXECUTE: 0
1 row in set (0.00 sec)

mysql> drop prepare stmt1;
Query OK, 0 rows affected (0.00 sec)

mysql> select <snip> from performance_schema.prepared_statements_instances\G
Empty set (0.01 sec)
 

New server/status variables:
A new server variable added:
performance_schema_max_prepared_statements_instances:
It denotes the maximum number of prepared statements which could be instrumented.

A new status variable added:
performance_schema_prepared_statements_lost:
It denotes how many prepared statements could not be instrumented.

Collection of Statistics:
It depends on existing instrumentations' value:
- "statement/sql/prepare_sql" for SQLCOM_PREPARE
         If enabled, prepare statistics of statements prepared from SQL query would be instrumented.
- "statement/com/prepare" for COM_STMT_PREPARE 
         If enabled, prepare statistics of statements prepared from C API would be instrumented.
- "statement/sql/execute_sql" for SQLCOM_EXECUTE
         If enabled, execute statistics of statements executed from SQL query would be instrumented.
 - "statement/com/execute" for COM_STMT_EXECUTE
         If enabled, execute statistics of statements executed from C API would be instrumented.