mysql慢查询binlog_binlog以及慢查询

得有root权限，不是必须。毕竟有时候文件权限很重要，建议在自己本地测试，或者在docker中测试，免得引起不必要的问题。

mysqlbinlog -d dbname bin-log.xxxxxx

慢日志相关内容

# 查看具体的参数信息

show variables like '%query%';

slow_query_log 参数值ON代表慢查询功能打开了，Off代表关闭

long_query_time 当一条SQL超过此时间，就会被记录为慢日志

slow_query_log_file记录慢日志的文件名，mysql5.6及以上没指定的话会给默认的缺省文件host_name-slow.log

log_queries_not_using_indexes 参数值为On代表捕获哪些没有使用索引的SQL查询，而不关注这条SQL执行的时间的长短。

设置方法：

my.cnf 文件中的[mysqld] 条项下加入

log-slow-queries=/data/xxx、slowquery.log # 注意这个目录需要有mysql账号的写权限，已满放到mysql的数据目录即可

long_query_time=2 # 单位：秒

对当前数据库进行修改的命令为：

set slow_query_log=1;

重启会失效。

起一个例子。

# 拉取镜像

docker pull mysql:latest

# run一个实例

docker run -d -p 3306:3306 -e MYSQL_ROOT_PASSWORD=123456 --name=MYSQL mysql

# 查看跑起来的服务

docker ps -a

CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES

9020e1df3052 mysql "docker-entrypoint.s…" 3 hours ago Up 3 hours 0.0.0.0:3306->3306/tcp, 33060/tcp MYSQL

# 进入容器进行操作

docker exec -it 9020e1df3052 /bin/bash

# 建库test，建表user

mysql> show create table user;

+-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

| Table | Create Table |

+-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

| user | CREATE TABLE `user` (

`id` int(11) NOT NULL AUTO_INCREMENT,

`name` varchar(255) NOT NULL,

PRIMARY KEY (`id`)

) ENGINE=InnoDB AUTO_INCREMENT=4610364 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci |

+-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

1 row in set (0.02 sec)

# 查看binlog

root@9020e1df3052:/var/lib/mysql# mysqlbinlog -d test binlog.000002 | tail

WARNING: The option --database has been used. It may filter parts of transactions, but will include the GTIDs in any case. If you want to exclude or include transactions, you should use the options --exclude-gtids or --include-gtids, respectively, instead.

#190611 14:09:00 server id 1 end_log_pos 46302458 CRC32 0xb651fcbe Query thread_id=9 exec_time=0 error_code=0

SET TIMESTAMP=1560262140/*!*/;

SET @@session.time_zone='SYSTEM'/*!*/;

flush privileges

/*!*/;

SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;

DELIMITER ;

# End of log file

/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

# 查看slowquery和其他变量信息

mysql> show variables like '%query%';

+------------------------------+--------------------------------------+

| Variable_name | Value |

+------------------------------+--------------------------------------+

| binlog_rows_query_log_events | OFF |

| ft_query_expansion_limit | 20 |

| have_query_cache | NO |

| long_query_time | 1.000000 |

| query_alloc_block_size | 8192 |

| query_prealloc_size | 8192 |

| slow_query_log | ON |

| slow_query_log_file | /var/lib/mysql/9020e1df3052-slow.log |

+------------------------------+--------------------------------------+

8 rows in set (0.01 sec)

# 如果上面的slow_query_log和long_query_time不是预期，需要设置开启

mysql> set long_query_time=1;

mysql> set slow_query_log=1;

# 插入测试数据 name全是'abc',大概460万行。

docker cp /tmp/data.sql 9020e1df3052:/var/lib/mysql

# 拷贝到容器中 后实际查看下

root@9020e1df3052:/var/lib/mysql# ls -alh|grep data.sql

-rw-r--r-- 1 501 root 36M Jun 11 14:05 data.sql

# explain 查看执行计划，确保没有使用索引，并进行全表查询

mysql> explain select * from user where name!='abc';

+----+-------------+-------+------------+------+---------------+------+---------+------+---------+----------+-------------+

| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |

+----+-------------+-------+------------+------+---------------+------+---------+------+---------+----------+-------------+

| 1 | SIMPLE | user | NULL | ALL | NULL | NULL | NULL | NULL | 4602909 | 90.00 | Using where |

+----+-------------+-------+------------+------+---------------+------+---------+------+---------+----------+-------------+

1 row in set, 1 warning (0.00 sec)

# 开始慢日志查询

mysql> select * from user where name!='abc';

+----+------+

| id | name |

+----+------+

| 1 | guo |

| 2 | rui |

| 3 | biao |

+----+------+

3 rows in set (1.61 sec)

# 实际查看slowquery.log

root@9020e1df3052:/var/lib/mysql# ls

#innodb_temp binlog.000001 ca-key.pem client-key.pem ib_logfile0 ibtmp1 performance_schema server-cert.pem test

9020e1df3052-slow.log binlog.000002 ca.pem data.sql ib_logfile1 mysql private_key.pem server-key.pem undo_001

auto.cnf binlog.index client-cert.pem ib_buffer_pool ibdata1 mysql.ibd public_key.pem sys undo_002

root@9020e1df3052:/var/lib/mysql# tail 9020e1df3052-slow.log

# Time: 2019-06-11T14:09:14.249339Z

# User@Host: root[root] @ localhost [] Id: 9

# Query_time: 1.607225 Lock_time: 0.000226 Rows_sent: 3 Rows_examined: 4610363

SET timestamp=1560262152;

select * from user where name!='abc';

如此，可以正常走一遍具体的查看慢查询的流程。实际生产环境打开慢查询会有一定的性能损耗，所以一般只有在彻查SQL性能问题的时候会设置slow_query_log=ON。

show processlist中State的含义。以下内容全部是基于存储引擎中每一个执行线程而言：

Checking table: 自动行为，正在检查数据表

Closing tables:把修改的数据刷回磁盘，并关闭已经用完的表。此操作很快，如果不是这样，检查磁盘IO负载或者查看磁盘空间。

Connect Out: 复制服务器正在连接主服务器

Copying to tmp table on disk:

Creating tmp table:

deleting from main table: 服务器正在执行多表删除的第一部分，刚删除第一个表。

delete fron reference tables:服务器正在执行多表删除的第二部分，正在删除其他表的记录。

flushing tables:等待其他县城关闭数据库。

killed: 发送了一个kill请求给某个线程，线程会先检查kill标志位，并忽略下一个kill请求。该标志位表示此线程是否被kill的状态。

locked: 此线程被其他查询锁住了。

sending data: 正在处理select查询的记录，同时正在把结果发给客户端。

Sorting for group:

Opening tables:

Removing duplicates:

Reopen table:

Repair by sorting: 修复指令正在利用索引缓存，一个一个地创建新索引。

Searching rows for update:

Sleeping: 正在等待客户端发送新请求。

System lock:

Upgrading lock:

Updating:

User Lock:

Waiting for tables:

waiting for handler insert: