“前事不忘,后事之师”--《战国策》
公司年前的最后一周禁止普通发布,所有发布一律走线上紧急发布,紧急发布流程复杂,还要层层审批,所以默认这一周是不做发布的,除非有重大bug需要紧急修复。秉着少做少错,不做不错的理念【不要摆烂,小心被优化】,以为可以度过轻松的一周。结果周一早上九点四十五运营反馈社区功能组件管理后台无法使用(非告警发现,难受!!!),此项目之前的负责同学离职,上一次bug修复是在上个周五由我负责修复并发布上线。我首先排除是上一次变更发布引起的故障,然后查看监控面板,发现50QPS下接口平均响应时间飙高已知至20s+,接口直接依赖的是redis和mysql,看了下中间件监控,redis的各指标正常,mysql的cpu使用率异常sql执行时间变高,查看日志发现下面一条ERROR日志频繁出现
Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. ### The error may exist in xxx.java (best guess) ### The error may involve xxxMapper.selectList ### The error occurred while executing a query ### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
于是联系平台的负责mysql的运维帮忙看下原因,运维老哥发现其中频繁使用的一条sql语句查询,没有索引全走的全表扫描,cpu被打满了。于是我让运维老哥帮我先禁掉sql,然后帮我给查询条件建一个联合索引,线上十点十分恢复正常。
之前常听到别人因为无索引导致锁表领了事故报告,今天自己又重蹈覆辙,不得不感叹事情真的是只有自己经历过才会印象深刻,不然就会事不关己高高挂起,转身就忘掉。事后我就在想1.全表扫描时,数据量多少时能明显感觉到慢(因为之前常听到,数据量少建索引意义不大,那多少数据量起索引对查询有提升了)2.接手别人的项目时,如何去规避类似问题引发的线上故障了,借着这次机会做了以下探究和思考。
测试
环境准备
环境 | 版本 | 备注 |
---|---|---|
MySQL | 5.7 | 机器8c16G 内网开发服务器 |
spring boot | 2.3.12.RELEASE | |
mybati-plus | 3.5.3.1 | 最新版 3.5.3.1 |
p6spy | 3.8.2 | sql性能记录工具 |
MySQL
建表语句
CREATE TABLE ops_component_index (
id BIGINT UNSIGNED PRIMARY KEY AUTO_INCREMENT COMMENT '主键',
component_id BIGINT UNSIGNED NOT NULL COMMENT '组件id',
user_id BIGINT UNSIGNED NOT NULL COMMENT '用户id',
`options` VARCHAR ( 60 ) NOT NULL COMMENT '用户选项'
) CHARSET = utf8;
springboot
依赖
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<parent>
<groupId>com.homeey</groupId>
<artifactId>high-lp</artifactId>
<version>1.0.20230128</version>
</parent>
<artifactId>speed-index</artifactId>
<packaging>jar</packaging>
<name>speed-index</name>
<url>http://maven.apache.org</url>
<properties>
<maven.compiler.source>8</maven.compiler.source>
<maven.compiler.target>8</maven.compiler.target>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
<spring.boot.version>2.3.12.RELEASE</spring.boot.version>
<mybatis.plus.version>3.5.3.1</mybatis.plus.version>
<p6spy.version>3.8.2</p6spy.version>
</properties>
<dependencyManagement>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-dependencies</artifactId>
<version>${spring.boot.version}</version>
<type>pom</type>
<scope>import</scope>
</dependency>
<dependency>
<groupId>p6spy</groupId>
<artifactId>p6spy</artifactId>
<version>${p6spy.version}</version>
</dependency>
<dependency>
<groupId>com.baomidou</groupId>
<artifactId>mybatis-plus-boot-starter</artifactId>
<version>${mybatis.plus.version}</version>
</dependency>
</dependencies>
</dependencyManagement>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
</dependency>
<dependency>
<groupId>com.baomidou</groupId>
<artifactId>mybatis-plus-boot-starter</artifactId>
</dependency>
<dependency>
<groupId>p6spy</groupId>
<artifactId>p6spy</artifactId>
</dependency>
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<optional>true</optional>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
</dependency>
</dependencies>
</project>
配置文件
server:
port: 80
spring:
application:
name: app
datasource:
url: jdbc:p6spy:mysql://localhost:3306/homeey
driver-class-name: com.p6spy.engine.spy.P6SpyDriver
username: root
password: 123456
p6spy
spy.properties
module.log=com.p6spy.engine.logging.P6LogFactory,com.p6spy.engine.outage.P6OutageFactory
# 自定义日志打印
logMessageFormat=com.baomidou.mybatisplus.extension.p6spy.P6SpyLogger
#日志输出到控制台,解开注释就行了
# appender=com.baomidou.mybatisplus.extension.p6spy.StdoutLogger
# 指定输出文件位置
logfile=sql.log
# 使用日志系统记录 sql
#appender=com.p6spy.engine.spy.appender.Slf4JLogger
# 设置 p6spy driver 代理
deregisterdrivers=true
# 取消JDBC URL前缀
useprefix=true
# 配置记录 Log 例外,可去掉的结果集有error,info,batch,debug,statement,commit,rollback,result,resultset.
excludecategories=info,debug,result,batch,resultset
# 日期格式
dateformat=yyyy-MM-dd HH:mm:ss
# 实际驱动可多个
#driverlist=org.h2.Driver
# 是否开启慢SQL记录
outagedetection=true
# 慢SQL记录标准 2 秒
outagedetectioninterval=2
测试计划
目标sql
select id,component_id,user_id,options from ops_component_index where component_id = ? and user_id = ?
表数据量 | 查询单条速度【无索引】 | 查询单条速度【有索引】 |
---|---|---|
50000 | 31ms | 13ms |
100_000 | 45ms | 13ms |
500_000 | 176ms | 15ms |
1_000_000 | 543ms | 16ms |
从测试结果中发现,当数据量到50w级别能明显感觉到走全表扫描的sql慢了,如果实验的目标MySQL服务期配置再差点【相对于8c16G】,应该能提早感知到慢。不过对于在线应用来说,如果sql执行时间大于100ms我们就应提早去做预防优化,对于一般复杂的业务sql的耗时超过100ms再加上其他外部依赖和内部逻辑的处理可能轻易的让接口rt超过200ms,那么在这种情况下接口的能支持的并发相当有限。sql走了索引后,查询时间是相对稳定且快速的,具体如何建好索引不是本次讨论的重点,有需求的小伙伴可以参考 阿里巴巴开发规范 章节5.2索引规约。
思考
从事故上来看,一般由索引引发的线上事故大多发生在后续新的迭代,增加新的查询条件时未考虑到是否需要新建索引,且一般测试环境不会有如此大的数据量供测试或开发发现问题。故最好在做新迭代时,对新使用到的查询条件需要评估是否需要新增索引,或是能否使用已有的索引字段做查询条件。
接手别人的项目如何规避事故风险了?我认为主要有三点
- 确认监控是否完善 ,不完善还得加
- 确认告警是否完备且正常,该有得告警都能告出来【最好是交接前能用混沌工程通过故障注入,把这些都走一遍,眼见为实耳听为虚嘛】
- 过程文档和应急预案是否都完整
满足这三点得话,有问题也能及时通过告警发现,通过应急预案快速处理,减小对用户的影响。总的来说就是研发过程要重视应用的可观测性,当黑盒变成透明的白盒时,一切问题将无所遁形。