Instrumenting plugins for Performance Schema

Copyright © 2017, Oracle and/or its affiliates. All rights reserved. |
Instrumenting Plugins for
Performance Schema
Mark Leith
Senior Software Development Manager
MySQL Enterprise Tools, Oracle

Program Agenda
Yea but “Why?”
The Interfaces
An example
Questions
1
2
3
4

Yea but “Why?”
• There’s a bunch of great interfaces in to the MySQL Server now,
from the well known storage engines, through pre/post parser
plugins, auditing, full text search, INFORMATION_SCHEMA tables,
UDFs, replication interfaces, and more..
• We’ve made great strides in instrumenting the core server, but if
you want to use plugins, and don’t also add to the instrumentation
in the new standard ways, this will cause new black holes in your
available performance data

The Performance Schema
Event Horizon

The Interfaces
• The main interface is within ./include/mysql/psi/
• The ABI is maintained via ./include/mysql/psi/psi.h
• Great Doxygen based docs here:
• https://dev.mysql.com/doc/dev/mysql-server/8.0.0/PAGE_PFS_PSI.html

The Interfaces
• The API is broken down by the type of instrumentation
• Threads, sync points (mutexes, rwlocks, conditions etc.) in
include/mysql/psi/mysql_thread.h
• File IO in include/mysql/psi/mysql_file.h
• Memory in include/mysql/psi/mysql_memory.h
• Network IO in include/mysql/psi/mysql_socket.h
• These all use the underlying versioned performance schema
interfaces via the psi.h ABI

An Example
• Let us dream of an audit plugin
• It will:
• Log statements that cause errors to a file
• Track some error stats with some global status variables
• That requires:
• Some file operations
• A mutex to protect concurrent access to the variables and file

pthread_mutex_t LOCK_client_error;
static int client_error_plugin_init(…)
{
pthread_mutex_init(&LOCK_client_error, NULL);
…
}
8
An Example - Mutex init
mysql_mutex_t LOCK_client_error;
PSI_mutex_key key_LOCK_client_error;
static PSI_mutex_info client_error_mutexes[]=
{
{ &key_LOCK_client_error,
"LOCK_client_error", PSI_FLAG_GLOBAL }
};
{
const char* category= "client_error";
int count;
count= array_elements(client_error_mutexes);
mysql_mutex_register(category,
client_error_mutexes, count);
mysql_mutex_init(key_LOCK_client_error,
&LOCK_client_error, MY_MUTEX_INIT_FAST);
…
}
P_S
Instrument Info
Register
within P_S

FILE *fp;
{
if(!(fp = fopen(“client_errors.log”, “a+”)))
return true;
…
}
9
An Example - File init
PSI_file_key key_file_client_error_log;
static PSI_file_info client_error_files[]=
{
{ &key_file_client_error_log,
"client_error_log", 0}
};
{
…
count= array_elements(client_error_files);
mysql_file_register(category, client_error_files, count);
…
if (!(client_error_log=
mysql_file_create(key_file_client_error_log,
“client_errors.log”, 0,
O_WRONLY | O_APPEND,
MYF(MY_WME))))
}
See
my_sys.h,
in this case, write
message on
error

static int client_error_notify(…)
{
…
if (error_event->event_subclass ==
MYSQL_AUDIT_GENERAL_ERROR)
{
pthread_mutex_lock(&LOCK_client_error);
…
/* Increment some counters */
/* Create some log line buffer in buff */
…
write(fp, (uchar*) buff, len);
pthread_mutex_unlock(&LOCK_client_error);
}
}
10
An Example - Writing to the file
{
…
{
mysql_mutex_lock(&LOCK_client_error);
…
/* Increment some counters */
/* Create some log line buffer in buff */
…
mysql_file_write(client_error_log,
(uchar*) buff, len, MYF_RW);
mysql_mutex_unlock(&LOCK_client_error);
}
}
Write message on
error, or if not all
bytes are
processed

An Example - Adding Stages
• Now you know where you may be waiting for thread synchronisation
or file IO (or network IO, I won’t talk about that here, look at the
API if you’re doing some Daemon plugin)
• You can track more major sections of code with Stages - the thread
states that exposed via process lists and profiling interfaces
• API is within include/mysql/psi/mysql_stage.h

PSI_stage_info opening_client_error_log_file=
{ 0, "Opening client error log file", 0 };
PSI_stage_info recording_error_statistics=
{ 0, "Recording error statistics", 0 };
PSI_stage_info *client_error_stages[]=
{
&opening_client_error_log_file,
&recording_error_statistics
};
12
An Example - Stages
static int client_error_log_open()
{
mysql_set_stage(opening_client_error_log_file.m_key);
mysql_mutex_lock(&LOCK_client_error_log);
/* Open the file, maybe write some header */
return 0;
}
{
…
{
mysql_set_stage(recording_error_statistics.m_key);
/* Update stats, write log file etc. */
}
return 0;
}

An Example - Adding Stages
• Note that when adding stages, you are hijacking the current stage
• Think about where in the flow your stage can be added
• Consider adding a “continuation” stage
• This can show code executed after your plugin (or face the blame
game)

An Example - Stage Progress
• You can also track progress of stages within 5.7+
• Call mysql_set_stage(…)
• Then mysql_stage_set_work_estimated(<stage>, <estimate count>)
• Then while doing the estimated work, at the right interval:
• mysql_stage_set_work_completed(<stage>, <completed count>);

An Example - Performance Schema Output
15
( SELECT thread_id, nesting_event_id, event_id, event_name, sys.format_time(timer_wait) AS time
FROM performance_schema.events_stages_history_long ORDER BY event_id )
UNION ALL
( SELECT thread_id, nesting_event_id, event_id, concat('-> ', event_name), sys.format_time(timer_wait) AS time
FROM performance_schema.events_waits_history_long WHERE event_name != 'idle' ORDER BY event_id )
ORDER BY thread_id, event_id;
+-----------+------------------+----------+--------------------------------------------------------+-----------+
| thread_id | nesting_event_id | event_id | event_name | time |
+-----------+------------------+----------+--------------------------------------------------------+-----------+
| 24 | 427 | 428 | stage/sql/starting | 120.46 us |
…
| 24 | 428 | 437 | -> wait/synch/rwlock/sql/LOCK_grant | 437.32 ns |
| 24 | 427 | 438 | stage/sql/Opening tables | 28.21 us |
| 24 | 427 | 440 | stage/client_error/Recording error statistics | 23.14 us |
| 24 | 440 | 441 | -> wait/synch/mutex/client_error/LOCK_client_error_log | 203.58 ns |
| 24 | 440 | 442 | -> wait/io/file/client_error/client_error_log | 11.25 us |
| 24 | 427 | 443 | stage/sql/query end | 3.52 us |
| 24 | 443 | 444 | -> wait/synch/mutex/sql/THD::LOCK_query_plan | 158.34 ns |
| 24 | 427 | 445 | stage/sql/closing tables | 1.68 us |
| 24 | 427 | 446 | stage/sql/freeing items | 50.63 us |

Question and feedback time!

Safe Harbor Statement
The preceding is intended to outline our general product direction. It is
intended for information purposes only, and may not be incorporated into any
contract. It is not a commitment to deliver any material, code, or functionality,
and should not be relied upon in making purchasing decisions. The development,
release, and timing of any features or functionality described for Oracle’s
products remains at the sole discretion of Oracle.

Instrumenting plugins for Performance Schema

Instrumenting plugins for Performance Schema

More Related Content

What's hot

What's hot (20)

Similar to Instrumenting plugins for Performance Schema

Similar to Instrumenting plugins for Performance Schema (20)

Recently uploaded

Recently uploaded (20)

Instrumenting plugins for Performance Schema