I love our community.
Not long after posting my update on ps_helper, I had a couple of comments around the formatting of values within the output. Daniël van Eeden gave the suggestion that I could add a couple of Stored Functions, for formatting byte and time based values.
Of course, this was a great idea – not least for myself, because I no longer have to worry about how to format certain columns in the output.
I’ve added the following:
format_bytes()
format_time()
format_path()
format_statement()
extract_schema_from_file_name()
extract_table_from_file_name()
I’ve updated all of the views within ps_helper to use these new functions as well (I may have missed some).
Along the way, I caught a couple of bugs (a missing SUM on the COUNT columns of the file IO summaries), and added a couple of updates.
The first was to update the output for the schema_table_statistics view, to include more of the data available within Performance Schema, and also to start using some of the data from the INFORMATION_SCHEMA.INNODB_BUFFER_PAGE table that is now available within MySQL 5.6.
Now the output looks like this:
mysql> select * from schema_table_statistics limit 1\G
*************************** 1. row ***************************
table_schema: mem
table_name: mysqlserver
rows_fetched: 27087
fetch_latency: 442.72 ms
rows_inserted: 2
insert_latency: 185.04 µs
rows_updated: 5096
update_latency: 1.39 s
rows_deleted: 0
delete_latency: 0 ps
io_read_requests: 2565
io_read_bytes: 1121627
io_read_latency: 10.07 ms
io_write_requests: 1691
io_write_bytes: 128383
io_write_latency: 14.17 ms
io_misc_requests: 2698
io_misc_latency: 433.66 ms
innodb_buffer_pages: 19
innodb_buffer_pages_hashed: 19
innodb_buffer_pages_old: 19
innodb_buffer_bytes_allocated: 311296
innodb_buffer_bytes_data: 1924
innodb_buffer_rows_cached: 2
I’ve also added another view within the 5.6 set, called statements_with_runtimes_in_95th_percentile.
This outputs all statement digests that have an average run time, in microseconds, that are above the 95th percentile of all statements. It’s output is similar to the statement_analysis view:
mysql> select * from statements_with_runtimes_in_95th_percentile where query not like 'show%'; +-------------------------------------------------------------------+-----------+------------+-----------+------------+---------------+-------------+-------------+-----------+---------------+--------------+----------------------------------+ | query | full_scan | exec_count | err_count | warn_count | total_latency | max_latency | avg_latency | rows_sent | rows_sent_avg | rows_scanned | digest | +-------------------------------------------------------------------+-----------+------------+-----------+------------+---------------+-------------+-------------+-----------+---------------+--------------+----------------------------------+ | SELECT plugin_name FROM inform ... tus = ? ORDER BY plugin_name | * | 169 | 0 | 0 | 2.37 s | 64.45 ms | 14.03 ms | 4394 | 26 | 10816 | 23234b56a0b1f1e350bf51bef3050747 | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 170.08 ms | 5.68 ms | 1.44 ms | 13582 | 115 | 13582 | 34694223091aee1380c565076b7dfece | | SELECT CAST ( SUM_NUMBER_OF_BY ... WHERE EVENT_NAME = ? LIMIT ? | * | 566 | 0 | 0 | 779.56 ms | 2.93 ms | 1.38 ms | 342 | 1 | 17286 | 58d34495d29ad818e68c859e778b0dcb | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 153.35 ms | 3.06 ms | 1.30 ms | 13228 | 112 | 13228 | b816579565d5a2882cb8bd496193dc00 | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 143.31 ms | 4.57 ms | 1.21 ms | 13646 | 116 | 13646 | 27ff8681eb2c8cf999233e7507b439fe | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 143.04 ms | 7.22 ms | 1.21 ms | 13584 | 115 | 13584 | 10b863f20e83dcd9c7782dac249acbb0 | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 137.46 ms | 16.73 ms | 1.16 ms | 13922 | 118 | 13922 | 351ebc26af6babb67570843bcc97f6b0 | | UPDATE `mem30__inventory` . `R ... mestamp` = ? WHERE `hid` = ? | | 114 | 0 | 0 | 127.64 ms | 30.33 ms | 1.12 ms | 0 | 0 | 114 | f4ecf2aebe212e7ed250a0602d86c389 | | UPDATE `mem30__inventory` . `I ... ` = ? , `hasOldBlocksTime` ... | | 56 | 0 | 0 | 61.05 ms | 16.41 ms | 1.09 ms | 0 | 0 | 56 | cdc78c70d83c505c5708847ba810d035 | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 121.76 ms | 1.95 ms | 1.03 ms | 13936 | 118 | 13936 | 20f97c53c2a59f5eadc06b2fa90fbe75 | | UPDATE `mem30__inventory` . `M ... mpileOs` = ? WHERE `hid` = ? | | 114 | 0 | 0 | 114.16 ms | 22.34 ms | 1.00 ms | 0 | 0 | 114 | c5d4a65f3f308f4869807e730739af6d | | CALL `dc_string_insert` (...) | | 80 | 0 | 0 | 79.89 ms | 2.62 ms | 998.50 ┬╡s | 0 | 0 | 240 | 93eb9cab8ced45cf3b98400e8803f8af | | SELECT `this_` . `target` AS ` ... D `this_` . `timestamp` <= ? | | 118 | 0 | 0 | 116.19 ms | 1.32 ms | 984.60 ┬╡s | 13484 | 114 | 13484 | bd23afed9a41367591e2b71dac76f334 | +-------------------------------------------------------------------+-----------+------------+-----------+------------+---------------+-------------+-------------+-----------+---------------+--------------+----------------------------------+
And to give an example using some of the bytes formatting as well, here’s an example for the latest_file_io view:
mysql> select * from latest_file_io limit 10; +----------------------+----------------------------------------+------------+-----------+-----------+ | thread | file | latency | operation | requested | +----------------------+----------------------------------------+------------+-----------+-----------+ | msandbox@localhost:1 | @@tmpdir/#sqlcf28_1_4e.MYI | 9.26 µs | write | 124 bytes | | msandbox@localhost:1 | @@tmpdir/#sqlcf28_1_4e.MYI | 4.00 µs | write | 2 bytes | | msandbox@localhost:1 | @@tmpdir/#sqlcf28_1_4e.MYI | 56.34 µs | close | NULL | | msandbox@localhost:1 | @@tmpdir/#sqlcf28_1_4e.MYD | 53.93 µs | close | NULL | | msandbox@localhost:1 | @@tmpdir/#sqlcf28_1_4e.MYI | 104.05 ms | delete | NULL | | msandbox@localhost:1 | @@tmpdir/#sqlcf28_1_4e.MYD | 661.18 µs | delete | NULL | | msandbox@localhost:1 | @@datadir/Cerberus.log | 35.99 ms | write | 57 bytes | | msandbox@localhost:1 | @@datadir/ps_helper/latest_file_io.frm | 7.40 µs | stat | NULL | | msandbox@localhost:1 | @@datadir/ps_helper/latest_file_io.frm | 9.81 µs | open | NULL | | msandbox@localhost:1 | @@datadir/ps_helper/latest_file_io.frm | 16.06 µs | read | 3.17 KiB | +----------------------+----------------------------------------+------------+-----------+-----------+
Keep the feedback coming!