菜单

Loen
发布于 2025-08-30 / 5 阅读
0
1

mysql慢日志分析--头部数据解读

起因:

领导突发奇想使用阿里云的dns解析做负载均衡,我感觉他之前可能只做过单机项目,所以想体验负载均衡,其实目前生产系统的业务量远远打不满的单机节点的,领导做事情不需要向大头兵解释,咱也不晓得他啥时候改的解析,事后来记录一下盘查慢日志的过程.

关于阿里云的域名dns

解析能配置多个ip,正常来说不会使用这种方式去做负载均衡,因为dns解析生效时间不可控,修改解析生效时间需要等待很长时间,阿里云要同步全球dns服务器,不同的客户端ip访问的dns服务器可能得到不同的结果.

特别是当你某台机器故障时,你是没办法即时清理掉这个故障节点的;

分析慢查询日志使用的工具是 pt-query-digest,下面是分析后的文件头部,汇总统计:

40.3s user time, 210ms system time, 68.71M rss, 263.14M vsz
Current date: Fri Aug 29 17:19:51 2025
Hostname: VM-0-13-centos
Files: mysql-slow.log
Overall: 308.93k total, 300 unique, 0.03 QPS, 0.15x concurrency ________
Time range: 2025-05-15T17:37:29 to 2025-08-29T09:19:39
Attribute          total     min     max     avg     95%  stddev  median
============     ======= ======= ======= ======= ======= ======= =======
Exec time        1384350s      3s   4979s      4s      6s     13s      4s
Lock time           230s       0     14s   743us   144us    61ms   103us
Rows sent         33.29M       0   2.37M  113.00  487.09   8.40k    0.99
Rows examine     629.53G       0 259.56M   2.09M   2.26M   1.90M   1.95M
Query size        46.40M       8 108.83k  157.50  271.23  308.67  124.25

这是一个MySQL慢查询日志分析报告的开头部分,逐行解释:

第2行 - 系统资源使用情况

# 40.3s user time, 210ms system time, 68.71M rss, 263.14M vsz
  • 40.3s user time: 用户态CPU时间,表示分析工具本身运行了40.3秒
  • 210ms system time: 内核态CPU时间,系统调用耗时210毫秒
  • 68.71M rss: 常驻内存集大小,程序实际使用的物理内存约68.71MB
  • 263.14M vsz: 虚拟内存大小,程序分配的虚拟内存约263.14MB

第3-6行 - 基本信息

# Current date: Fri Aug 29 17:19:51 2025
# Hostname: VM-0-13-centos
# Files: mysql-slow.log
# Overall: 308.93k total, 300 unique, 0.03 QPS, 0.15x concurrency ________
  • 分析时间:2025年8月29日17:19:51
  • 主机名:VM-0-13-centos
  • 分析文件:mysql-slow.log
  • 总体统计:
    • 308.93k total: 总共308,930条慢查询记录
    • 300 unique: 300种不同的查询模式
    • 0.03 QPS: 平均每秒0.03个查询(非常低)
    • 0.15x concurrency: 平均并发度0.15

第7行 - 时间范围

# Time range: 2025-05-15T17:37:29 to 2025-08-29T09:19:39

慢查询日志覆盖的时间范围:从2025年5月15日到8月29日,跨度约3个多月

第8-14行 - 性能指标统计

# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time        1384350s      3s   4979s      4s      6s     13s      4s
# Lock time           230s       0     14s   743us   144us    61ms   103us
# Rows sent         33.29M       0   2.37M  113.00  487.09   8.40k    0.99
# Rows examine     629.53G       0 259.56M   2.09M   2.26M   1.90M   1.95M
# Query size        46.40M       8 108.83k  157.50  271.23  308.67  124.25

关键问题指标:

  • 执行时间: 总执行时间138万秒,平均4秒,最长4979秒(约83分钟!)
  • 锁等待时间: 总锁等待230秒,最长14秒
  • 返回行数: 总共返回3329万行,平均113行
  • 扫描行数: 总共扫描6295亿行,平均209万行(这是主要性能瓶颈)
  • 查询大小: 总共46.4MB,平均157字节

总结: 这个数据库存在严重的性能问题,主要是查询扫描了过多的行数(平均每次查询扫描209万行),导致执行时间过长。建议优化索引和查询语句。


评论