Mysql高级第三弹——查询日志

一、慢查询日志学习

1.慢查询日志是什么?
  • MySQL的慢查询日志是MySQL提供的一种日志记录,它用来记录在MySQL中响应时间超过阈值的语句,具体指运行时间超过 long_query_time 值的SQL,则会被记录到慢查询日志中。
  • long_query_time 的默认值为10,意思是运行10秒以上的语句。
  • 由慢查询日志来查看哪些SQL超出了我们的最大忍耐时间值,比如一条SQL执行超过5秒钟,我们就算慢SQL,希望能收集超过5秒钟的SQL,结合之前 explain 进行全面分析。

特别说明

默认情况下,MySQL数据库没有开启慢查询日志,需要我们手动来设置这个参数。

当然,如果不是调优需要的话,一般不建议启动该参数,因为开启慢查询日志会或多或少带来一定的性能影响。慢查询日志支持将日志记录写入文件。

2.查看慢查询日志是否开以及如何开启
  • 查看慢查询日志是否开启:SHOW VARIABLES LIKE ‘%slow_query_log%’;。
  • 开启慢查询日志:SET GLOBAL slow_query_log = 1 ; 。 使用该方法开启MySQL的慢查询日志只对当前数据库生效,如果MySQL重启后会失效。

如果要使慢查询日志永久开启,需要修改my.cnf文件,在[mysqld]下增加修改参数。

# my.cnf
[mysqld]
# 1.这个是开启慢查询。注意ON需要大写
slow_query_log=ON  

# 2.这个是存储慢查询的日志文件。这个文件不存在的话,需要自己创建
slow_query_log_file=/var/lib/mysql/slow.log

开启了慢查询日志后,什么样的SQL才会被记录到慢查询日志里面呢?

这个是由参数long_query_time控制的,默认情况下long_query_time的值为10秒。

MySQL中查看long_query_time的时间:SHOW VARIABLES LIKE ‘long_query_time%’;

修改long_query_time的时间,需要在my.cnf修改配置文件

1.方法一
set global long_query_time = 1;


2.方法二
[mysqld]
# 这个是设置慢查询的时间,我设置的为1秒
long_query_time=1

//配置慢查询时间
slow _query_log=1;
//配置慢查询日志保存文件
slow_query _log_file=/var/lib/mysql/atguigu-slow.loglong_query_time=3;
//不在控制台输出
log_output=FILE

打开cat /var/lib/mysql//var/lib/mysql/slow.log

/usr/sbin/mysqld, Version: 5.7.34 (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
# Time: 2021-10-27T14:03:33.201362Z
# User@Host: root[root] @ DESKTOP-2JU9EV3.lan [192.168.199.132]  Id:    11
# Query_time: 4.001308  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
use db01;
SET timestamp=1635343413;
select sleep(4);

二、日志分析工具的使用

日志分析工具 mysqldumpslow:在生产环境中,如果要手工分析日志,查找、分析SQL,显然是个体力活,MySQL提供了日志分析工具 mysqldumpslow

# 1、mysqldumpslow --help 来查看mysqldumpslow的帮助信息
root@1dcb5644392c:/usr/bin# mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

Parse and summarize the MySQL slow query log. Options are

  --verbose    verbose
  --debug      debug
  --help       write this text to standard output

  -v           verbose
  -d           debug
  -s ORDER     what to sort by (al, at, ar, c, l, r, t), 'at' is default  # 按照何种方式排序
                al: average lock time		# 平均锁定时间
                ar: average rows sent		# 平均返回记录数
                at: average query time	# 平均查询时间
                 c: count  # 访问次数
                 l: lock time						# 锁定时间
                 r: rows sent						# 返回记录
                 t: query time					# 查询时间 
  -r           reverse the sort order (largest last instead of first)
  -t NUM       just show the top n queries  # 返回前面多少条记录
  -a           don't abstract all numbers to N and strings to 'S'
  -n NUM       abstract numbers with at least n digits within names
  -g PATTERN   grep: only consider stmts that include this string  
  -h HOSTNAME  hostname of db server for *-slow.log filename (can be wildcard),
               default is '*', i.e. match all
  -i NAME      name of server instance (if using mysql.server startup script)
  -l           don't subtract lock time from total time
  
# 2、 案例
# 2.1、得到返回记录集最多的10个SQL
mysqldumpslow -s r -t 10 /var/lib/mysql/slow.log
 
# 2.2、得到访问次数最多的10个SQL
mysqldumpslow -s c -t 10 /var/lib/mysql/slow.log
 
# 2.3、得到按照时间排序的前10条里面含有左连接的查询语句
mysqldumpslow -s t -t 10 -g "left join" /var/lib/mysql/slow.log

# 2.4、另外建议使用这些命令时结合|和more使用,否则出现爆屏的情况
mysqldumpslow -s r -t 10 /var/lib/mysql/slow.log | more

二、批量数据脚本

由于开启过慢查询日志,开启了bin-log,我们就必须为function指定一个参数,否则使用函数会报错。

# 在mysql中设置 
# log_bin_trust_function_creators 默认是关闭的 需要手动开启
mysql> SHOW VARIABLES LIKE 'log_bin_trust_function_creators';
+---------------------------------+-------+
| Variable_name                   | Value |
+---------------------------------+-------+
| log_bin_trust_function_creators | OFF   |
+---------------------------------+-------+
1 row in set (0.00 sec)

mysql> SET GLOBAL log_bin_trust_function_creators=1;
Query OK, 0 rows affected (0.00 sec)

上述修改方式MySQL重启后会失败,在my.cnf配置文件下修改永久有效。

[mysqld]
log_bin_trust_function_creators=ON
2.创建函数
# 1、函数:随机产生字符串
DELIMITER $$
CREATE FUNCTION rand_string(n INT) RETURNS VARCHAR(255)
BEGIN
    DECLARE chars_str VARCHAR(100) DEFAULT 'abcdefghijklmnopqrstuvwsyzABCDEFGHIJKLMNOPQRSTUVWXYZ';
    DECLARE return_str VARCHAR(255) DEFAULT '';
    DECLARE i INT DEFAULT 0;
    WHILE i < n DO
    SET return_str = CONCAT(return_str,SUBSTRING(chars_str,FLOOR(1+RAND()*52),1));
    SET i = i + 1;
    END WHILE;
    RETURN return_str;
END $$

# 2、函数:随机产生部门编号
DELIMITER $$
CREATE FUNCTION rand_num() RETURNS INT(5)
BEGIN
    DECLARE i INT DEFAULT 0;
    SET i = FLOOR(100 + RAND() * 10);
    RETURN i;
END $$
3.创建存储过程
# 1、函数:向dept表批量插入
DELIMITER $$
CREATE PROCEDURE insert_dept(IN START INT(10),IN max_num INT(10))
BEGIN
DECLARE i INT DEFAULT 0;
    SET autocommit = 0;
    REPEAT
    SET i = i + 1;
    INSERT INTO dept(deptno,dname,loc) VALUES((START + i),rand_string(10),rand_string(8));
    UNTIL i = max_num
    END REPEAT;
    COMMIT;
END $$

# 2、函数:向emp表批量插入
DELIMITER $$
CREATE PROCEDURE insert_emp(IN START INT(10),IN max_num INT(10))
BEGIN
DECLARE i INT DEFAULT 0;
    SET autocommit = 0;
    REPEAT
    SET i = i + 1;
    INSERT INTO emp(empno,ename,job,mgr,hiredata,sal,comm,deptno) VALUES((START + i),rand_string(6),'SALESMAN',0001,CURDATE(),2000,400,rand_num());
    UNTIL i = max_num
    END REPEAT;
    COMMIT;
END $$
4.调用存储过程
# 1、调用存储过程向dept表插入10个部门。
DELIMITER ;
CALL insert_dept(100,10);

# 2、调用存储过程向emp表插入50万条数据。
DELIMITER ;
CALL insert_emp(100001,500000);

三、Show Profile

MySQL提供可以用来分析当前会话中语句执行的资源消耗情况。

可以用于SQL的调优的测量。默认情况下,参数处于关闭状态,并保存最近15次的运行结果。

分析步骤

  • 1.查看是否支持
# 查看Show Profile功能是否开启
mysql> SHOW VARIABLES LIKE 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | OFF   |
+---------------+-------+
1 row in set (0.00 sec)
    1. 开启Show Profile功能,默认是关闭的,使用前需要开启
# 开启Show Profile功能
mysql> SET profiling=ON;
Query OK, 0 rows affected, 1 warning (0.00 sec)
  • 3.运行SQL
SELECT * FROM `emp` GROUP BY `id`%10 LIMIT 150000;

SELECT * FROM `emp` GROUP BY `id`%20 ORDER BY 5;
  • 4.查看结果,执行SHOW PROFILES;

Duration:持续时间。

mysql> SHOW PROFILES;
+----------+------------+---------------------------------------------------+
| Query_ID | Duration   | Query                                             |
+----------+------------+---------------------------------------------------+
|        1 | 0.00156100 | SHOW VARIABLES LIKE 'profiling'                   |
|        2 | 0.56296725 | SELECT * FROM `emp` GROUP BY `id`%10 LIMIT 150000 |
|        3 | 0.52105825 | SELECT * FROM `emp` GROUP BY `id`%10 LIMIT 150000 |
|        4 | 0.51279775 | SELECT * FROM `emp` GROUP BY `id`%20 ORDER BY 5   |
+----------+------------+---------------------------------------------------+
4 rows in set, 1 warning (0.00 sec)
  • 5.诊断SQL,SHOW PROFILE cpu,block io FOR QUERY Query_ID;
# 这里的3是第四步中的Query_ID。
# 可以在SHOW PROFILE中看到一条SQL中完整的生命周期。
mysql> SHOW PROFILE cpu,block io FOR QUERY 3;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000097 | 0.000090 |   0.000002 |            0 |             0 |
| checking permissions | 0.000010 | 0.000009 |   0.000000 |            0 |             0 |
| Opening tables       | 0.000039 | 0.000058 |   0.000000 |            0 |             0 |
| init                 | 0.000046 | 0.000046 |   0.000000 |            0 |             0 |
| System lock          | 0.000011 | 0.000000 |   0.000000 |            0 |             0 |
| optimizing           | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |
| statistics           | 0.000023 | 0.000037 |   0.000000 |            0 |             0 |
| preparing            | 0.000014 | 0.000000 |   0.000000 |            0 |             0 |
| Creating tmp table   | 0.000041 | 0.000053 |   0.000000 |            0 |             0 |
| Sorting result       | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |
| executing            | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |
| Sending data         | 0.520620 | 0.516267 |   0.000000 |            0 |             0 |
| Creating sort index  | 0.000060 | 0.000051 |   0.000000 |            0 |             0 |
| end                  | 0.000006 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000011 | 0.000000 |   0.000000 |            0 |             0 |
| removing tmp table   | 0.000006 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |
| closing tables       | 0.000009 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items        | 0.000032 | 0.000064 |   0.000000 |            0 |             0 |
| cleaning up          | 0.000019 | 0.000000 |   0.000000 |            0 |             0 |
+----------------------+----------+----------+------------+--------------+---------------+
20 rows in set, 1 warning (0.00 sec)

Show Profile查询参数备注:

  • ● ALL:显示所有的开销信息。
  • ● BLOCK IO:显示块IO相关开销(通用)。
  • ● CONTEXT SWITCHES:上下文切换相关开销。
  • ● CPU:显示CPU相关开销信息(通用)。
  • ● IPC:显示发送和接收相关开销信息。
  • ● MEMORY:显示内存相关开销信息。
  • ● PAGE FAULTS:显示页面错误相关开销信息。
  • ● SOURCE:显示和Source_function。
  • ● SWAPS:显示交换次数相关开销的信息。

6、Show Profile查询列表,日常开发需要注意的结论:

  • ● converting HEAP to MyISAM:查询结果太大,内存都不够用了,往磁盘上搬了。
  • ● Creating tmp table:创建临时表(拷贝数据到临时表,用完再删除),非常耗费数据库性能。
  • ● Copying to tmp table on disk:把内存中的临时表复制到磁盘,危险!!!
  • ● locked:死锁。

四、全局查询日志

只在测试环境下才可以用

在mysql的my.cnf中,设置如下
#开启
general_log=1

#记录日志文件的路径
general_log_file=/path/logfile

#输出格式
log_output=FILE
set global general_log=1;
set global log_output='TABLE';

#此后编写的sql语句,将会记录到mysql库里的general_log表,可以用下面的命令查看
select * from mysql.general_log;
  • 1
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 打赏
    打赏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

抬头看天空

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付:¥1
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值