Using the New MySQL Query Profiler
The Best Way to Diagnose Performance Problems
- Bottleneck analysis - focuses on answering the questions: What is my database server waiting on; what is a user connection waiting on; what is a piece of SQL code waiting on?
- Workload analysis - examines the server and who is logged on to determine the resource usage and activity of each.
- Ratio-based analysis - utilizes a number of rule-of-thumb ratios to gauge performance of a database, user connection, or piece of code.
Getting started with the SQL Profiler
mysql> set profiling=1; Query OK, 0 rows affected (0.00 sec)
profiling
is created in the INFORMATION_SCHEMA database for your particular session (not viewable by any other MySQL session) that stores all the SQL diagnostic results. This table remains persistent until you disconnect from MySQL at which point it is destroyed.
mysql> select count(*) from client where broker_id=2; +----------+ | count(*) | +----------+ | 200 | +----------+ 1 row in set (0.00 sec)
mysql> show profiles; +----------+------------+-----------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+-----------------------------------------------+ | 0 | 0.00007300 | set profiling=1 | | 1 | 0.00044700 | select count(*) from client where broker_id=2 | +----------+------------+-----------------------------------------------+ 2 rows in set (0.00 sec)
mysql> select sum(duration) from information_schema.profiling where query_id=1; +---------------+ | sum(duration) | +---------------+ | 0.000447 | +---------------+ 1 row in set (0.00 sec)
mysql> show profile for query 1; +--------------------+------------+ | Status | Duration | +--------------------+------------+ | (initialization) | 0.00006300 | | Opening tables | 0.00001400 | | System lock | 0.00000600 | | Table lock | 0.00001000 | | init | 0.00002200 | | optimizing | 0.00001100 | | statistics | 0.00009300 | | preparing | 0.00001700 | | executing | 0.00000700 | | Sending data | 0.00016800 | | end | 0.00000700 | | query end | 0.00000500 | | freeing items | 0.00001200 | | closing tables | 0.00000800 | | logging slow query | 0.00000400 | +--------------------+------------+ 15 rows in set (0.00 sec)
SHOW PROFILE
and exclude the identification of a specific profile number to see the very last profile you created.
SELECT
statements as this example shows:
mysql> alter table t engine=myisam; Query OK, 112050 rows affected (0.64 sec) Records: 112050 Duplicates: 0 Warnings: 0 mysql> show profiles; +----------+------------+-----------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+-----------------------------------------------+ | 0 | 0.00007300 | set profiling=1 | | 1 | 0.00044700 | select count(*) from client where broker_id=2 | | 2 | 0.00003400 | set profiling=0 | | 3 | 0.00007400 | set profiling=1 | | 4 | 0.63789700 | alter table t engine=myisam | | 5 | 0.00004000 | set profiling=0 | +----------+------------+-----------------------------------------------+ 6 rows in set (0.00 sec) mysql> show profile for query 4; +----------------------+------------+ | Status | Duration | +----------------------+------------+ | (initialization) | 0.00002900 | | checking permissions | 0.00000800 | | init | 0.00004000 | | Opening table | 0.00009400 | | System lock | 0.00000500 | | Table lock | 0.00000700 | | setup | 0.00004200 | | creating table | 0.00195800 | | After create | 0.00010900 | | copy to tmp table | 0.52264500 | | rename result table | 0.11289400 | | end | 0.00004600 | | query end | 0.00000700 | | freeing items | 0.00001300 | +----------------------+------------+ 14 rows in set (0.00 sec)
ALTER TABLE
statement spends the bulk of its time in the temporary table copy step. Armed with this type of information, you have more insight into the hoops your query is jumping through from start to finish, and therefore, you can then work to tune your queries to help eliminate any identified bottlenecks.
mysql> show profile cpu for query 4; +----------------------+------------+------------+------------+ | Status | Duration | CPU_user | CPU_system | +----------------------+------------+------------+------------+ | (initialization) | 0.00002900 | 0.00000000 | 0.00000000 | | checking permissions | 0.00000800 | 0.00000000 | 0.00000000 | | init | 0.00004000 | 0.00000000 | 0.00000000 | | Opening table | 0.00009400 | 0.00100000 | 0.00000000 | | System lock | 0.00000500 | 0.00000000 | 0.00000000 | | Table lock | 0.00000700 | 0.00000000 | 0.00000000 | | setup | 0.00004200 | 0.00000000 | 0.00000000 | | creating table | 0.00195800 | 0.00000000 | 0.00100000 | | After create | 0.00010900 | 0.00000000 | 0.00000000 | | copy to tmp table | 0.52264500 | 0.55591600 | 0.04199300 | | rename result table | 0.11289400 | 0.00199900 | 0.00000000 | | end | 0.00004600 | 0.00000000 | 0.00000000 | | query end | 0.00000700 | 0.00000000 | 0.00000000 | | freeing items | 0.00001300 | 0.00000000 | 0.00000000 | +----------------------+------------+------------+------------+ 14 rows in set (0.00 sec)
SHOW PROFILE
command include:
- ALL - displays all information
- BLOCK IO - displays counts for block input and output operations
- CONTEXT SWITCHES - displays counts for voluntary and involuntary context switches
- IPC - displays counts for messages sent and received
- MEMORY - is not currently implemented
- PAGE FAULTS - displays counts for major and minor page faults
- SOURCE - displays the names of functions from the source code, together with the name and line number of the file in which the function occurs
- SWAPS - displays swap counts
Using the Profiler for Tuning Queries
EXPLAIN
's to troubleshoot queries. But the new profiler makes things pretty nice and easy.
mysql> select * from v_client_portfolio_high; +-----------+-------------------+------------------+-----------------+ | client_id | client_first_name | client_last_name | portfolio_value | +-----------+-------------------+------------------+-----------------+ | 5 | ABNER | ROSSELLETT | 1252115.50 | | 500 | CANDICE | BARTLETT | 1384877.50 | +-----------+-------------------+------------------+-----------------+ 2 rows in set (3.73 sec)
mysql> set profiling=1; Query OK, 0 rows affected (0.00 sec) mysql> select * from v_client_portfolio_high; +-----------+-------------------+------------------+-----------------+ | client_id | client_first_name | client_last_name | portfolio_value | +-----------+-------------------+------------------+-----------------+ | 5 | ABNER | ROSSELLETT | 1252115.50 | | 500 | CANDICE | BARTLETT | 1384877.50 | +-----------+-------------------+------------------+-----------------+ 2 rows in set (4.01 sec) mysql> set profiling=0; Query OK, 0 rows affected (0.00 sec) mysql> show profiles; +----------+------------+-----------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+-----------------------------------------------+ | 0 | 0.00007300 | set profiling=1 | | 1 | 0.00044700 | select count(*) from client where broker_id=2 | | 2 | 0.00003400 | set profiling=0 | | 3 | 0.00007400 | set profiling=1 | | 4 | 0.63789700 | alter table t engine=myisam | | 5 | 0.00004000 | set profiling=0 | | 6 | 0.00007600 | set profiling=1 | | 7 | 4.01965600 | select * from v_client_portfolio_high | | 8 | 0.00003500 | set profiling=0 | +----------+------------+-----------------------------------------------+
SHOW PROFILE
for query 7, which is my view query, but instead let's see just how many lines of diagnostic data the profiler has collected for me:
mysql> select count(*) from information_schema.profiling where query_id=7; +----------+ | count(*) | +----------+ | 74734 | +----------+
SHOW PROFILE
command (even though a LIMIT option is provided). Instead, let's use a SQL query against the profiling table to see what our query did:
mysql> select min(seq) seq,state,count(*) numb_ops,-> round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,-> round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu-> from information_schema.profiling-> where query_id = 7-> group by state-> order by seq; +-------+----------------------+----------+---------+---------+---------+---------+ | seq | state | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu | +-------+----------------------+----------+---------+---------+---------+---------+ | 0 | (initialization) | 1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 | | 1 | Opening tables | 1 | 0.00023 | 0.00023 | 0.00000 | 0.00000 | | 2 | System lock | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 3 | Table lock | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 4 | checking permissions | 1 | 0.00010 | 0.00010 | 0.00000 | 0.00000 | | 5 | optimizing | 4 | 0.00004 | 0.00001 | 0.00000 | 0.00000 | | 6 | statistics | 4 | 0.00007 | 0.00002 | 0.00100 | 0.00025 | | 7 | preparing | 4 | 0.00005 | 0.00001 | 0.00000 | 0.00000 | | 8 | Creating tmp table | 1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 | | 9 | executing | 37352 | 0.16631 | 0.00000 | 0.05899 | 0.00000 | | 10 | Copying to tmp table | 1 | 0.00006 | 0.00006 | 0.00000 | 0.00000 | | 15 | Sending data | 37353 | 3.85151 | 0.00010 | 3.72943 | 0.00010 | | 74717 | Sorting result | 1 | 0.00112 | 0.00112 | 0.00100 | 0.00100 | | 74719 | removing tmp table | 2 | 0.00003 | 0.00001 | 0.00000 | 0.00000 | | 74721 | init | 1 | 0.00002 | 0.00002 | 0.00000 | 0.00000 | | 74727 | end | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 74728 | query end | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 | | 74729 | freeing items | 1 | 0.00002 | 0.00002 | 0.00000 | 0.00000 | | 74730 | closing tables | 2 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 74733 | logging slow query | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 | +-------+----------------------+----------+---------+---------+---------+---------+
Sending data
step, with that step and the executing
step experiencing over 37,000 operations. Why would this be the case? Let's take a look at the underlying view definition and see what the actual query looks like:
create view v_client_portfolio_high (client_id,client_first_name,client_last_name,portfolio_value ) as select b.client_id,b.client_first_name,b.client_last_name,(select sum(number_of_units * price) from client_transaction c where c.action = 'buy' and c.client_id = b.client_id) - (select sum(number_of_units * price) from client_transaction d where d.action = 'sell' and d.client_id = b.client_id) portfolio_value from client_transaction a,client b where a.client_id = b.client_id group by b.client_id,b.client_first_name,b.client_last_name having portfolio_value > 1000000
mysql> drop view v_client_portfolio_high; Query OK, 0 rows affected (0.00 sec) mysql> create view v_client_portfolio_high-> (-> client_id,-> client_first_name,-> client_last_name,-> portfolio_value-> )-> as-> select b.client_id,-> b.client_first_name,-> b.client_last_name,-> sum(number_of_units * price) --> case-> (select sum(number_of_units * price)-> from client_transaction d-> where d.action = 'sell' and-> d.client_id = b.client_id)-> when NULL then 0-> else-> (select sum(number_of_units * price)-> from client_transaction d-> where d.action = 'sell' and-> d.client_id = b.client_id)-> end portfolio_value-> from client_transaction a,-> client b-> where a.client_id = b.client_id and-> action = 'buy'-> group by b.client_id,-> b.client_first_name,-> b.client_last_name-> having portfolio_value > 1000000; Query OK, 0 rows affected (0.00 sec) mysql> set profiling=1; Query OK, 0 rows affected (0.00 sec) mysql> select * from v_client_portfolio_high; +-----------+-------------------+------------------+-----------------+ | client_id | client_first_name | client_last_name | portfolio_value | +-----------+-------------------+------------------+-----------------+ | 5 | ABNER | ROSSELLETT | 1252115.50 | | 500 | CANDICE | BARTLETT | 1384877.50 | +-----------+-------------------+------------------+-----------------+ 2 rows in set (0.47 sec) mysql> set profiling=0; Query OK, 0 rows affected (0.00 sec) mysql> show profiles; +----------+------------+-----------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+-----------------------------------------------+ | 0 | 0.00007300 | set profiling=1 | | 1 | 0.00044700 | select count(*) from client where broker_id=2 | | 2 | 0.00003400 | set profiling=0 | | 3 | 0.00007400 | set profiling=1 | | 4 | 0.63789700 | alter table t engine=myisam | | 5 | 0.00004000 | set profiling=0 | | 6 | 0.00007600 | set profiling=1 | | 7 | 4.01965600 | select * from v_client_portfolio_high | | 8 | 0.00003500 | set profiling=0 | | 9 | 0.00007500 | set profiling=1 | | 10 | 0.45292700 | select * from v_client_portfolio_high | | 11 | 0.00003800 | set profiling=0 | +----------+------------+-----------------------------------------------+ 12 rows in set (0.00 sec) mysql> select min(seq) seq,state,count(*) numb_ops,-> round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,-> round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu-> from information_schema.profiling-> where query_id = 10-> group by state-> order by seq; +-------+----------------------+----------+---------+---------+---------+---------+ | seq | state | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu | +-------+----------------------+----------+---------+---------+---------+---------+ | 0 | (initialization) | 1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 | | 1 | Opening tables | 1 | 0.00024 | 0.00024 | 0.00000 | 0.00000 | | 2 | System lock | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 3 | Table lock | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 4 | checking permissions | 1 | 0.00012 | 0.00012 | 0.00100 | 0.00100 | | 5 | optimizing | 4 | 0.00005 | 0.00001 | 0.00000 | 0.00000 | | 6 | statistics | 4 | 0.00007 | 0.00002 | 0.00000 | 0.00000 | | 7 | preparing | 4 | 0.00005 | 0.00001 | 0.00000 | 0.00000 | | 8 | Creating tmp table | 1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 | | 9 | executing | 11194 | 0.04983 | 0.00000 | 0.01800 | 0.00000 | | 10 | Copying to tmp table | 1 | 0.00008 | 0.00008 | 0.00000 | 0.00000 | | 15 | Sending data | 11195 | 0.39853 | 0.00004 | 0.36794 | 0.00003 | | 22401 | Sorting result | 1 | 0.00375 | 0.00375 | 0.00400 | 0.00400 | | 22403 | removing tmp table | 2 | 0.00005 | 0.00002 | 0.00000 | 0.00000 | | 22405 | init | 1 | 0.00002 | 0.00002 | 0.00000 | 0.00000 | | 22411 | end | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 22412 | query end | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 | | 22413 | freeing items | 1 | 0.00002 | 0.00002 | 0.00000 | 0.00000 | | 22414 | closing tables | 2 | 0.00001 | 0.00001 | 0.00000 | 0.00000 | | 22417 | logging slow query | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 | +-------+----------------------+----------+---------+---------+---------+---------+ 20 rows in set (0.44 sec)
Some Last Thoughts on the Profiler
profiling_history_size
session variable.Certain diagnostics rely on operating system support for the
getrusage()
system call, so you may see NULL values for some statistics if you're on a platform that doesn't support this function.
SHOW PROFILES
command before enabling profiling. Another concerned duration statistics that were not accurately paired up for each SQL execution step. All these have been fixed now and will be in the next Community server source drop and binary.
转载于:https://blog.51cto.com/imysql/308291
Using the New MySQL Query Profiler相关推荐
- mysql query profiler_MySQL Query Profiler
查看MySQL语法详细执行时间与CPU/记忆体使用量: MySQL Query Profiler MySQL的SQL语法调整主要都是使用EXPLAIN,但是这个并没办法知道详细的Ram(Memory) ...
- mysql query profile_MySQL Query Profile
MySQL Query Profile MySQL 5.0.37 以上开始支持 MySQL Query Profiler, 可以查询到此 SQL 会执行多少时间, 并看出 CPU/Memory 使用量 ...
- mysql自带的监控报告_MYSQL监控-自带工具Query Profiler的使用
Query Profiler是MYSQL自带的一种query诊断分析工具,通过它可以分析出一条SQL语句的性能瓶颈在什么地方.通常我们是使用的explain,以及slow query log都无法做到 ...
- MYSQL监控-自带工具Query Profiler的使用
2019独角兽企业重金招聘Python工程师标准>>> Query Profiler是MYSQL自带的一种query诊断分析工具,通过它可以分析出一条SQL语句的性能瓶颈在什么地方. ...
- 比explain更加详细的分析计划:Query Profiler
一.前言 这篇博客是之前总结的一个知识点,也是偶然看别人博客的时候发现的这个东东,,也算是解析sql语句性能的利器吧,记录一哈. Query Profiler是MYSQL自带的一种quer ...
- mysql query 优化_第 8 章 MySQL 数据库 Query 的优化
前言: 在之前"影响 MySQL 应用系统性能的相关因素"一章中我们就已经分析过了Query语句对数据库性能的影响非常大,所以本章将专门针对 MySQL 的 Query 语句的优化 ...
- mysql query browswer_MySQL数据库新特性之存储过程入门教程
MySQL数据库新特性之存储过程入门教程 在MySQL 5中,终于引入了存储过程这一新特性,这将大大增强MYSQL的数据库处理能力.在本文中将指导读者快速掌握MySQL 5的存储过程的基本知识,带领用 ...
- mysql query cache
1.概述: MySQL Query Cache 缓存客户端提交给MySQL的SELECT(注意只是select)语句以及该语句的结果集. 注意:query_cache是mysql server端的查询 ...
- mysql 查询分析器_mysql查询分析工具|mysql查询分析器(MySQL Query Browser)下载v1.1.20 官方版_ IT猫扑网...
mysql查询分析器又名为mysqlquerybrowser,是一款可以帮助用户快捷进行sql语句查询的工具,让你在编程的过程中更加方便的进行工作.有需要的朋友就来IT猫扑下载吧! MySQL Que ...
最新文章
- vuex是什么?怎么用,例子
- 几经沉浮,自乱前程——硬盘巨头启示录之迈拓篇
- [kuangbin] M - Find a way(简单广搜)
- 前端网页 — 初始化文件
- 用hundred造句子_2020朋友圈感恩节祝福语大全:微信感恩节鞠躬的图片文案句子说说[多图]...
- 安卓航班Android开发经典教程大总结1----基础编程及源码推送
- AjaxControltoolkit学习笔记—ListSearch 使用详解
- fedora 23 vlc 以root运行的方法
- 重构kz-admin
- 搜索引擎的一些简单命令-防止自己忘记系列
- 独立键盘检测,矩阵键盘检测
- 管理者的50堂课之创始人篇 读书笔记
- 《算法帝国》第一章第二章读书笔记
- 博客项目——登录功能实现
- 传奇私服服务器怎么增加npc,在自己的传奇服务器中如何添加NPC
- 车牌检测与识别:License plate detection and recognition (LPDR)
- Value Use User
- 【经典面试题】strcmp 函数的实现
- 企业信息化不可缺少之方正OA
- [Python]学习笔记5——For循环
热门文章
- CES2018:英特尔披露量子计算和神经拟态计算研究最新进展
- DeepMind推出「控制套件」:为「强化学习智能体」提供性能基准
- 为什么你那么努力,却很难突破技术瓶颈?
- 漫画 | 辞职前与老板的最后一次谈话有哪些禁忌?
- 秒抢红包的背后,是复杂的即时付款系统
- 微软转向,鸿蒙拥抱,炒房团都来了,Linux 为何引各方英雄竞折腰?
- 使用云祺虚拟机备份软件恢复Citrix XenServer 虚拟机
- Python 设计模式: 单例模式(singleton pattern)
- SGI STL 内存分配方式及malloc底层实现分析
- Linux的chattr与lsattr命令详解