Helper Functions for ps_helper

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! :)

Got something to say?