1 / 67

Performance Schema and ps_helper

Performance Schema and ps_helper. Mark Leith Senior Software Development Manager @ Oracle @MarkLeith Http://www.markleith.co.uk. Program Agenda. Performance Schema Overview ps_helper Overview ps_helper Examples A peak at what is coming in 5.7. Performance Schema Overview.

iolana
Download Presentation

Performance Schema and ps_helper

An Image/Link below is provided (as is) to download presentation Download Policy: Content on the Website is provided to you AS IS for your information and personal use and may not be sold / licensed / shared on other websites without getting consent from its author. Content is provided to you AS IS for your information and personal use only. Download presentation by click this link. While downloading, if for some reason you are not able to download a presentation, the publisher may have deleted the file from their server. During download, if you can't get a presentation, the file might be deleted by the publisher.

E N D

Presentation Transcript

  1. Performance Schema and ps_helper Mark LeithSenior Software Development Manager @ Oracle @MarkLeith Http://www.markleith.co.uk

  2. Program Agenda • Performance Schema Overview • ps_helper Overview • ps_helper Examples • A peak at what is coming in 5.7...

  3. Performance Schema Overview What is Performance Schema? Who has used the most time / resources? What was executed to take those resources? Where was time spent in execution? When were these things executed?

  4. Performance Schema Overview Monitoring Pre Performance Schema

  5. Performance Schema Overview Or maybe ... CC image courtesy of Ghostboy on Flickr

  6. Performance Schema Overview Monitoring Post Performance Schema CC image courtesy of jurvetson on Flickr

  7. Performance Schema Overview • Exposed within performance_schema schema • Tables use new PERFORMANCE_SCHEMA storage engine • Records various run time statistics via in-built instrumentation points

  8. Performance Schema Overview • Instrumentation Points • Performance Schema tracks latency for various events • Latency is exposed to picosecond precision (a trillionth of a second) • In 5.5: • File I/O, Mutexes, Read/Write Locks, Conditions • In 5.6: • Network I/O, Table I/O, Table Locks, Stages, Statements, Idle • Also track other data as appropriate, like bytes, source position, etc.

  9. Performance Schema Overview • Wait Events • Idle idle (5.6) • Table Locks wait/lock/table/% (5.6) • Network IO wait/io/socket/% (5.6) • Table IO wait/io/table/% (5.6) • File IO wait/io/file/% (5.5) • Mutexes wait/synch/mutex/% (5.5) • Read/Write Locks wait/synch/rwlock/% (5.5) • Conditions wait/synch/cond/% (5.5)

  10. Performance Schema Overview • Statement and Stage Events (5.6+) • Statements have two types of event • SQL Statements statement/sql/% • COM Commands statement/com/% • Stages are the thread states (like SHOW PROFILE, but available across connections) • One form so far stage/sql/% • Apart from... stage/mysys/Waiting for table level lock

  11. Performance Schema Overview A Raw Wait Event mysql> select * from performance_schema.events_waits_history limit 1\G *************************** 1. row *************************** THREAD_ID: 3 EVENT_ID: 11 END_EVENT_ID: 11 EVENT_NAME: wait/io/file/innodb/innodb_log_file SOURCE: os0file.cc:5542 TIMER_START: 2543370511043700 TIMER_END: 2543370535624100 TIMER_WAIT: 24580400 SPINS: NULL ...

  12. Performance Schema Overview A Raw Wait Event mysql> select * from performance_schema.events_waits_history limit 1\G *************************** 1. row *************************** ... OBJECT_SCHEMA: NULL OBJECT_NAME: /Users/mark/sb/msb_5_7_2/data/ib_logfile0 INDEX_NAME: NULL OBJECT_TYPE: FILE OBJECT_INSTANCE_BEGIN: 4771328832 NESTING_EVENT_ID: NULL NESTING_EVENT_TYPE: NULL OPERATION: write NUMBER_OF_BYTES: 512 FLAGS: NULL

  13. Performance Schema Overview A Raw Stage Event mysql> select * from performance_schema.events_stages_history_long limit 1\G *************************** 1. row *************************** THREAD_ID: 25 EVENT_ID: 5199518 END_EVENT_ID: 5199536 EVENT_NAME: stage/sql/System lock SOURCE: lock.cc:304 TIMER_START: 280557566125986000 TIMER_END: 280557566190403000 TIMER_WAIT: 64417000 NESTING_EVENT_ID: 5199509 NESTING_EVENT_TYPE: STATEMENT

  14. Performance Schema Overview A Raw Statement Event mysql> select * from performance_schema.events_statements_history_long limit 1\G *************************** 1. row *************************** THREAD_ID: 24 EVENT_ID: 3923 END_EVENT_ID: 4044 EVENT_NAME: statement/sql/insert_select SOURCE: mysqld.cc:931 TIMER_START: 251016737474892000 TIMER_END: 251016738730372000 TIMER_WAIT: 1255480000 LOCK_TIME: 573000000 ...

  15. Performance Schema Overview A Raw Statement Event mysql> select * from performance_schema.events_statements_history_long limit 1\G *************************** 1. row *************************** ... SQL_TEXT: insert into t2 select * from t1 DIGEST: e6f8db8a3f557ffbb2bf6a7b237cd897 DIGEST_TEXT: INSERT INTO `t2` SELECT * FROM `t1` CURRENT_SCHEMA: test OBJECT_TYPE: NULL OBJECT_SCHEMA: NULL OBJECT_NAME: NULL OBJECT_INSTANCE_BEGIN: NULL ...

  16. Performance Schema Overview A Raw Statement Event mysql> select * from performance_schema.events_statements_history_long limit 1\G *************************** 1. row *************************** ... MYSQL_ERRNO: 0 RETURNED_SQLSTATE: 00000 MESSAGE_TEXT: Records: 5 Duplicates: 0 Warnings: 0 ERRORS: 0 WARNINGS: 0 ROWS_AFFECTED: 5 ROWS_SENT: 0 ROWS_EXAMINED: 5 ...

  17. Performance Schema Overview A Raw Statement Event mysql> select * from performance_schema.events_statements_history_long limit 1\G *************************** 1. row *************************** ... CREATED_TMP_DISK_TABLES: 0 CREATED_TMP_TABLES: 0 SELECT_FULL_JOIN: 0 SELECT_FULL_RANGE_JOIN: 0 SELECT_RANGE: 0 SELECT_RANGE_CHECK: 0 SELECT_SCAN: 1 ...

  18. Performance Schema Overview Performance Schema Overview A Raw Statement Event mysql> select * from performance_schema.events_statements_history_long limit 1\G *************************** 1. row *************************** ... SORT_MERGE_PASSES: 0 SORT_RANGE: 0 SORT_ROWS: 0 SORT_SCAN: 0 NO_INDEX_USED: 1 NO_GOOD_INDEX_USED: 0 NESTING_EVENT_ID: NULL NESTING_EVENT_TYPE: NULL

  19. Performance Schema Overview Performance Schema Overview Event Nesting Events are linked in a hierarchy Use NESTING_EVENT_ID to EVENT_ID I.e Statements → Stages → Waits

  20. Performance Schema Overview

  21. Program Agenda ps_helper Overview

  22. ps_helper Overview What is ps_helper? A collection of Views, Functions and Stored Procedures Designed to make reading raw Performance Schema data easier Implements many common DBA and Developer use cases http://www.markleith.co.uk/ps_helper/ https://github.com/MarkLeith/dbahelper/

  23. ps_helper Overview Loading ps_helper $ git clone https://github.com/MarkLeith/dbahelper.git dbahelper $ cd dbahelper $ mysql -u user -p < ps_helper_<version>.sql <version> can be 55, 56 or 57, for 5.5, 5.6 and 5.7 respectively.

  24. ps_helper Overview Once loaded, creates a new ps_helper schema containing all objects mysql> select object_type, count -> from ps_helper.schema_object_overview -> where db = 'ps_helper'; +-------------+-------+ | object_type | count | +-------------+-------+ | FUNCTION | 8 | | VIEW | 49 | | PROCEDURE | 12 | +-------------+-------+

  25. ps_helper Overview Functions • Make the raw data more readable to a human • format_time() / format_bytes() • Compress data for CLI output • format_statement() / format_path() • Extract some data to assist JOIN etc. • extract_[schema | table]_from_file_name()

  26. ps_helper Overview Procedures – Convenience for P_S Config • currently_enabled() / currently_disabled() • enable_current_thread() / disable_current_thread() • enable_background_threads() / disable_background_threads() • save_current_config() / reload_saved_config() • reset_to_default() / truncate_all() • only_enable()

  27. ps_helper Overview Procedures – Analysis of Instrumentation • dump_thread_stack() • analyze_statement_digest()

  28. ps_helper Overview Views Summarize raw Performance Schema data for certain use cases Expose both formatted and raw views where formatting is used

  29. Program Agenda ps_helper Examples

  30. ps_helper Examples User Analysis +--------------------------------+ | Tables_in_ps_helper | +--------------------------------+ | user_summary | | user_summary_by_stages | | user_summary_by_statement_type | +--------------------------------+ High level User Overview What Statements User uses Where User Waits Most

  31. user_summary Summary of user activity per user mysql> select * from user_summary\G *************************** 1. row *************************** user: root total_statements: 3072 total_latency: 00:04:44.92 avg_latency: 92.75 ms current_connections: 1 total_connections: 10 unique_hosts: 1

  32. user_summary_by_stages Breakdown of the most expensive stages of execution per user mysql> select * from user_summary_by_stages; +------+--------------------------------+-------+-----------+-----------+ | user | event_name | count | wait_sum | wait_avg | +------+--------------------------------+-------+-----------+-----------+ | root | stage/sql/creating table | 8 | 1.42 s | 178.10 ms | | root | stage/sql/System lock | 28 | 246.30 ms | 8.80 ms | | root | stage/sql/checking permissions | 59 | 205.34 ms | 3.48 ms | | root | stage/sql/Opening tables | 40 | 28.55 ms | 713.79 us | | root | stage/sql/query end | 45 | 18.51 ms | 411.42 us | | root | stage/sql/updating | 4 | 16.94 ms | 4.23 ms | | root | stage/sql/statistics | 18 | 11.96 ms | 664.43 us | | root | stage/sql/init | 75 | 3.57 ms | 47.62 us | | root | stage/sql/Sending data | 18 | 1.28 ms | 71.21 us |

  33. user_summary_by_statement_type Breakdown of statement types and their stats per user mysql> select * from user_summary_by_statement_type; +------+-----------------------+-------+---------------+-------------+--------------+-----------+----------------------+---------------+------------+ | user | statement | count | total_latency | max_latency | lock_latency | rows_sent | rows_examined | rows_affected | full_scans | +------+-----------------------+-------+---------------+-------------+--------------+-----------+----------------------+---------------+------------+ | root | create_view | 879 | 00:02:16.98 | 966.39 ms | 1.11 s | 0 | 0 | 0 | 0 | | root | call_procedure | 5 | 00:02:06.75 | 00:01:05.80 | 00:02:06.13 | 0 | 11414288391619301677 | 0 | 2 | | root | select | 114 | 6.15 s | 1.57 s | 1.00 s | 878 | 26038 | 0 | 65 | | root | Field List | 181 | 2.90 s | 514.46 ms | 498.74 ms | 0 | 0 | 0 | 0 | | root | drop_view | 858 | 2.05 s | 223.08 ms | 0 ps | 0 | 0 | 0 | 0 | | root | show_tables | 33 | 1.80 s | 1.00 s | 814.10 ms | 795 | 795 | 0 | 33 | | root | drop_function | 159 | 1.48 s | 966.11 ms | 1.38 s | 0 | 0 | 0 | 0 | | root | create_table | 8 | 1.43 s | 520.83 ms | 0 ps | 0 | 0 | 0 | 0 | | root | drop_db | 13 | 1.22 s | 249.29 ms | 1.15 s | 0 | 0 | 514 | 0 | | root | show_fields | 14 | 913.79 ms | 424.08 ms | 514.58 ms | 192 | 192 | 0 | 14 | | root | show_databases | 19 | 662.52 ms | 479.86 ms | 333.05 ms | 95 | 95 | 0 | 19 | | root | create_procedure | 235 | 510.45 ms | 137.29 ms | 417.21 ms | 0 | 0 | 0 | 0 | | root | set_option | 72 | 396.58 ms | 140.56 ms | 0 ps | 0 | 0 | 0 | 0 |

  34. ps_helper Examples +------------------------------+ | Tables_in_ps_helper | +------------------------------+ | io_by_thread_by_latency | | io_global_by_file_by_bytes | | io_global_by_file_by_latency | | io_global_by_wait_by_bytes | | io_global_by_wait_by_latency | +------------------------------+ IO Analysis IO Breakdown by File IO Breakdown by IO Event IO Breakdown by Thread

  35. io_by_thread_by_latency Threads waiting the longest on file IO mysql> select * from io_by_thread_by_latency limit 1\G *************************** 1. row *************************** user: root@localhost count_star: 8153 total_latency: 16.54 s min_latency: 448.63 ns avg_latency: 1.36 ms max_latency: 279.73 ms thread_id: 20 processlist_id: 1

  36. io_global_by_file_by_latency Files that have the highest latency mysql> select * from io_global_by_file_by_latency limit 1\G *************************** 1. row *************************** File: @@datadir/ps_helper/statement_analysis_raw.frm~ count_star: 30 total_latency: 513.96 ms count_read: 0 read_latency: 0 ps count_write: 5 write_latency: 132.13 us count_misc: 25 misc_latency: 513.83 ms

  37. io_global_by_file_by_bytes Files doing the most IO by bytes mysql> select * from io_global_by_file_by_bytes limit 1\G *************************** 1. row *************************** file: @@datadir/ibtmp1 count_read: 0 total_read: 0 bytes avg_read: 0 bytes count_write: 48 total_written: 13.06 MiB avg_write: 278.67 KiB total: 13.06 MiB write_pct: 100.00

  38. io_global_by_wait_by_latency File IO events with highest latency mysql> select * from io_global_by_wait_by_latency limit 1\G *************************** 1. row *************************** event_name: sql/file_parser count_star: 2066 total_latency: 15.91 s avg_latency: 7.70 ms max_latency: 279.73 ms read_latency: 0 ps write_latency: 9.80 ms misc_latency: 15.90 s ...

  39. io_global_by_wait_by_latency cont.. File IO events with highest latency mysql> select * from io_global_by_wait_by_latency limit 1\G *************************** 1. row *************************** ... count_read: 0 total_read: 0 bytes avg_read: 0 bytes count_write: 281 total_written: 878.16 KiB avg_written: 3.13 KiB

  40. latest_file_io The latest File IO events in the history mysql> select * from latest_file_io limit 10; +-----------------------------------+------------------------------+-----------+-----------+-----------+ | thread | file | latency | operation | requested | +-----------------------------------+------------------------------+-----------+-----------+-----------+ | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_3f.MYI | 22.33 us | write | 124 bytes | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_3f.MYI | 2.34 us | write | 2 bytes | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_3f.MYI | 113.38 us | close | NULL | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_3f.MYD | 39.82 us | close | NULL | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_3f.MYI | 48.53 us | delete | NULL | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_3f.MYD | 358.41 us | delete | NULL | | srv_master_thread:16 | @@datadir/ib_logfile0 | 22.27 us | write | 512 bytes | | srv_master_thread:16 | @@datadir/ib_logfile0 | 298.87 us | sync | NULL | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_41.MYI | 233.38 us | create | NULL | | service_manager@localhost:59760:3 | @@tmpdir/#sql11e48_20_41.MYD | 119.15 us | create | NULL | +-----------------------------------+------------------------------+-----------+-----------+-----------+

  41. ps_helper Examples +-------------------------------------+ | Tables_in_ps_helper | +-------------------------------------+ | schema_index_statistics | | schema_object_overview | | schema_table_statistics | | schema_table_statistics_with_buffer | | schema_tables_with_full_table_scans | | schema_unused_indexes | +-------------------------------------+ Schema Analysis Table Usage Stats Index Usage Stats Object Overviews

  42. schema_object_overview Overview of objects by type and count mysql> select * from schema_object_overview; +--------------------+---------------+-------+ | db | object_type | count | +--------------------+---------------+-------+ | common_schema | BASE TABLE | 18 | | common_schema | FUNCTION | 70 | | common_schema | INDEX (BTREE) | 49 | | common_schema | PROCEDURE | 131 | | common_schema | VIEW | 62 | | information_schema | SYSTEM VIEW | 60 | | mysql | BASE TABLE | 28 |

  43. schema_table_statistics_with_buffer Table IO and File IO per table, along with InnoDB buffer use mysql> select * from schema_table_statistics_with_buffer\G *************************** 1. row *************************** table_schema: mem__quan table_name: example_statements rows_fetched: 544 fetch_latency: 672.82 ms rows_inserted: 10815 insert_latency: 00:07:12.10 rows_updated: 522 update_latency: 11.88 s rows_deleted: 0 delete_latency: 0 ps

  44. schema_table_statistics_with_buffer cont... Table IO and File IO per table, along with InnoDB buffer use mysql> select * from schema_table_statistics_with_buffer\G *************************** 1. row *************************** ... io_read_requests: 36 io_read: 88.60 KiB io_read_latency: 192.23 us io_write_requests: 1947 io_write: 34.02 MiB io_write_latency: 73.89 ms io_misc_requests: 142 io_misc_latency: 1.48 s ...

  45. schema_table_statistics_with_buffer cont... Table IO and File IO per table, along with InnoDB buffer use mysql> select * from schema_table_statistics_with_buffer\G *************************** 1. row *************************** ... innodb_buffer_allocated: 4.93 MiB innodb_buffer_data: 6.32 MiB innodb_buffer_pages: 631 innodb_buffer_pages_hashed: 631 innodb_buffer_pages_old: 631 innodb_buffer_rows_cached: 10450

  46. schema_index_statistics Index IO by index mysql> select * from schema_index_statistics limit 1\G *************************** 1. row *************************** table_schema: mem__inventory table_name: mysqlserver index_name: PRIMARY rows_selected: 2619 select_latency: 36.46 s rows_inserted: 0 insert_latency: 0 ps rows_updated: 494 update_latency: 2.35 s rows_deleted: 0 delete_latency: 0 ps

  47. schema_unused_indexes Indexes that have had no IO mysql> select * from schema_unused_indexes limit 20; +-------------------+-----------------------------------+--------------------+ | object_schema | object_name | index_name | +-------------------+-----------------------------------+--------------------+ | mem__config | user_form_defaults | FKC1AEF1F9E7EE2CFB | | mem__enterprise | mos_service_requests | PRIMARY | | mem__enterprise | whats_new_entries | entryId | | mem__enterprise | whats_new_entries | PRIMARY | | mem__events | actions | PRIMARY | | mem__events | action_logs | policyId | | mem__events | action_logs | ts | +-------------------+-----------------------------------+--------------------+

  48. ps_helper Examples Statement Analysis +---------------------------------------------+ | Tables_in_ps_helper | +---------------------------------------------+ | statement_analysis | | statements_with_errors_or_warnings | | statements_with_full_table_scans | | statements_with_runtimes_in_95th_percentile | | statements_with_sorting | | statements_with_temp_tables | +---------------------------------------------+ Normalized Statement Overview Statements by Usage

  49. statement_analysis Statistics on Normalize Statements, sorted by highest latency mysql> select * from statement_analysis limit 1\G *************************** 1. row *************************** query: SELECT * FROM ( SELECT `digest ... ` , `sum_no_index_used` AS ... full_scan: * exec_count: 99 err_count: 0 warn_count: 0 total_latency: 59.47 s max_latency: 2.47 s avg_latency: 600.74 ms lock_latency: 69.14 ms ...

More Related