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.

Friday, January 10, 2014

Performance Schema implementation Internals: Registering instruments

This is the very first post in the series of Performance Schema Implementation Internals. This series is for MySQL Developers to understand implementation of Performance Schema. For user point of view of performance Schema, please refer to mysql documentation link : http://dev.mysql.com/doc/refman/5.7/en/performance-schema-quick-start.html

This post talks about the mechanism to register instruments in Performance Schema (referred as P_S from hereon) so that their statistics could be collected at runtime.

To understand this, lets first understand different instrument classes in P_S.

Instrument Classes in P_S:

An enum PFS_class_type is there to keep track of all possible classes of instruments.

enum PFS_class_type                                    
{                                                     
    PFS_CLASS_NONE=        0,                             
  PFS_CLASS_MUTEX=       1,                           
  PFS_CLASS_RWLOCK=      2,                           
  PFS_CLASS_COND=        3,                           
  PFS_CLASS_FILE=        4,                           
  PFS_CLASS_TABLE=       5,                           
  PFS_CLASS_STAGE=       6,                           
  PFS_CLASS_STATEMENT=   7,                           
  ...                                                 
};                    
                                       

For eg. here PFS_CLASS_STATEMENT is type of a class which is used for all statement related instruments (eg. statement/sql/select, statement/sql/insert etc.).

Now there is a base class PFS_instr_class from which all other instrument classes are derived. Following figure shows the relationship.

Each instrument in P_S is instantiated with one of the above class.

For every set of instruments (Stages, Waits, Statements etc.) we maintain arrays which we name as class array. An array of this kind keeps records of all the instruments in that particular class and their configurations (i.e. name, enabled, timed etc.). For example:
      PFS_mutex_class *mutex_class_array : to hold information of all mutex instruments.
      PFS_statement_class *statement_class_array : to hold information of all statement instruments.

During initialization of P_S, memory is allocated to these arrays based on their sizing values eg. mutex_class_max, statement_class_max. Default values of these sizing are set internally, but user can also specify them while starting MySQL server. If user specify a sizing value less then the number of instruments available in that specific class, few instruments of that class won't be registered to be tracked. These lost instrument information can be seen in "show status command as follow".

mysql> show status like "%performance%";
+-----------------------------------------------+-------+
| Variable_name                                 | Value |
+-----------------------------------------------+-------+
| Performance_schema_cond_classes_lost          | 0     |
| Performance_schema_file_classes_lost          | 0     |

 ...

Instrument Class Array 

Now, lets see how does an array of an instrument class look like and what does each element represent in that array.

 

Above figure shows statement_class_array. Each element of this array represent an instrument (statement/sql/select in this case) and contains information about that instrument. In this case, select instrument is enabled and it is to be timed as well. This m_enabled/m_timed could be seen for instruments (statement/sql/select in this case) on the fly when MySQL server is running with P_S.



Similarly there are arrays for other class types as well and each element of those arrays represents an instrument of its respective class.

Registering Instruments:

As it might have been obvious by now that this is the array which P_S use during execution to find out information of instruments. So it is necessary for each instrument (which we intend to instrument) should be in one of these array i.e. should be registered.

Lets see how do we register instruments (i.e. keep their information in the class array). Here I took example of statement instruments.

Hold on!!
Before that lets understand one more structure. I call it info structure.

struct PSI_statement_info_v1
{
  /** The registered statement key. */
  PSI_statement_key m_key;
  /** The name of the statement instrument to register. */
  const char *m_name;
  /** The flags of the statement instrument to register. */
  int m_flags;
};

This is a structure which keeps "where to look" information (m_key) of an instrument which would be used at run time to get other information about that instrument. 
m_name : keeps the name of the instrument to be registered ( say select)
m_key  : is an index in the statement_class_array where the information of this     
                     instrument is stored.
m_flags: flag for that instrument.

Similar to PSI_statement_info_v1, there are info structure for other classes as well like PSI_stage_info_v1, PSI_mutex_info_v1 etc.

An array, sql_statement_info, is made of this structure and each element of array represent a statement instrument of SQL Statement. Information (m_name) in this array is filled up by function init_sql_statement_info() which does nothing but populate m_name from all possible sql statements in MySQL and reset flags to '0'.

Still with me?

Now we have sql_statement_info populated but its still not linked to statement_class_array. To do that, a call to mysql_statement_register() is made with this sql_statement_info array.

This function, mysql_statement_register() which finally maps to pfs_statement_register_v1() (pfs.cc) does following:

  1. for all elements in sql_statement_info
    1. make a formatted string to be stored for instrument name (eg. statement/sql/select)
    2. call register_statement_class(), which would stores information of this instrument in statement_class_array and return its index.
    3. store this index into m_key.
Now lets see what function register_statement_class() does.
  1. call REGISTER_CLASS_BODY_PART to see if this instrument already registered. If yes, then return that index.
  2. search for first empty index in  statement_class_array and populate information by calling init_instr_class().
  3. populate event_name_index with index.
  4. call configure_instr_class(), to set the user specified values (if any).
  5. return index+1 to be stored in m_key.

Thats it !!! Its done.


Now for a particular instrument in sql_statement_info, this m_key is populated with the index in statement_class_array where information about this instrument is stored. During execution, P_S use this m_key to see the information of that instrument in statement_class_array.
This entire flow could be depicted from following figure:
 Similarly registration mechanism exists for all the instruments available in P_S. Once registered, instruments become ready to be collected statistics for in P_S.


Performance Schema Implementation Internals : To be continued ...