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 processlistState的含义。以下内容全部是基于存储引擎中每一个执行线程而言

  • 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:
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 206,839评论 6 482
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 88,543评论 2 382
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 153,116评论 0 344
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 55,371评论 1 279
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 64,384评论 5 374
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,111评论 1 285
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,416评论 3 400
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,053评论 0 259
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 43,558评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,007评论 2 325
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,117评论 1 334
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,756评论 4 324
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,324评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,315评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,539评论 1 262
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,578评论 2 355
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,877评论 2 345

推荐阅读更多精彩内容