性能优化-压测实战-分析电商项目购物车qps低的几种情况

性能优化-压测实战-电商项目购物车

背景：对学过的一个电商项目购物车相关接口性能优化手段再次复盘，添加一些个人笔记

配置Jmeter压测计划

  1. Jmeter压测可视化

原理：通过配置Jmeter线程组下的后端监听器Backend Listener，压测过程中，实时发送统计指标数据，如TPS、响应时间、线程数、错误率等信息，给时序数据库Influxdb，并借助配置了Influxdb数据源的Grafana，我们便可实时获取到更美观友好的Jmeter的压测结果。

搭建过程：略

  1. 创建压测请求

准备过程：在上面新建的线程组下面新增Simple Controller，再把我们要压测的接口全部放这下面；在jmeter里添加csv data数据供接口参数和head中的token使用，例如，为测试同时有1000人发送下单请求时，接口的性能表现如何，在csv文件里构造1000条不同的接口参数和用户登录token；最后在jmeter里创建JSON Extractor来解析一个接口依赖另外一个接口的数据（被依赖的接口下），创建BeanShell PreProcessor在发生采样之前解析和组装需要的参数（依赖其他接口数据的接口）。

JMeter官方文档：https://jmeter.apache.org/usermanual/component_reference.html?spm=a2c4g.11186623.0.0.44e65495ghEDJq#CSV_Data_Set_Config

  1. 开始压测

准备完成后，在线程组上配置压测的线程数，开始压测。

压测结果分析

  1. 压测添加购物车接口

查看grafana的jmeter压测数据，平均qps不到20，开始定位原因。

寻找原因

  • 打开mysql的grafana监控图，发现有不少慢查询（Mysql Slow Queries图）
  • 查看skywalking这个接口的链路时长，找出是慢在哪一步，发现某个mysql操作耗时数秒钟，拖慢了整个post接口执行速度
  • 拉出sql查看sql执行计划，分析是否合理的走了索引，没有走索引或索引失效则添加合适的索引或者修改sql语句走合适的索引
  • 重新压测，qps达到数百，好像优化有效果，继续一直压测下去，会发现qps一直在慢慢往下掉

再次寻找原因

  • 发现此时mysql机器cpu严重超载，判断还有其他sql执行慢
  • 再次查看skywalking，原先那条sql经过优化，执行时间已经到了几毫秒了；发现多了一条mysql操作有一百多毫秒
  • 再次拉出sql看下查询计划，之前这条sql执行较快可能是因为数据量不大，随着我们压测的进行，数据量越来越大，这条有问题的sql就暴露出来了，优化这条sql，添加联合索引，
  • 再次压测，qps提升了一个数量级，达到数千，mysql的cpu占用也下降了很多，优化效果明显，可见平时工作中对数据库的sql优化是非常重要的，一条慢sql在高并发场景下甚至可以拖垮整个数据库；再看下skywalking这条sql的执行时间也到了几毫秒了，对应的post请求的总执行时间也下降了很多。

4.1. 慢查询实战

4.1.1. 慢查询日志是否开启

show variables  like '%slow_query_log%';  -- 查看是否开启慢查询
set global slow_query_log=1;  -- 没有开启的话，就开启慢查询
show variables  like '%slow_query_log%';  -- 再次查看是否开启慢查询

4.1.2 慢查询sql的设置时间

show variables like 'long_query_time%';  -- 查看慢查询阈值，默认判断时间为10s
set global long_query_time=0.5;  -- 设置慢查询阈值(单位s)，设置完需要重新开启session才能生效
show variables like 'long_query_time%';  -- 再次查看慢查询阈值

4.1.3 慢查询日志存储方式

show variables like '%log_output%';  -- 查看日志的存储方式，是写入文件还是数据表，默认是写入文件
set global log_output='TABLE';  -- 设置为写入数据表，这样日志信息就会被写入到mysql.slow_log表
show variables like '%log_output%';  -- 再次查看写入文件还是数据表

4.1.4 慢查询测试

select sleep(1);  -- 执行一条慢查询
select * from mysql.slow_log; -- 查看慢查询记录表
TRUNCATE mysql.slow_log; -- 清空慢查询记录表

mysql慢查询具体参数 https://blog.csdn.net/qq_40884473/article/details/89455740

show variables like 'log_slow_admin_statements'; --是否将慢管理语句例如ANALYZE TABLE和ALTER TABLE等记入慢查询日志。
show global status like '%Slow_queries%'; --查询有多少条慢查询记录

4.1.5 慢查询辅助工具-mysqldumpslow

mysql> set global log_output='FILE,TABLE';  -- 设置为写入数据表和文件
mysql> show VARIABLES like 'slow_query_log_file'; --先查看日志存放地址
mysqldumpslow -s t -t 10 /var/lib/mysql/3c86be2ff75f-slow.log --再得到花费总时间最多的前10个SQL

语法： mysqldumpslow -s r -t 10 slow-mysql.log
-s order (c,t,l,r,at,al,ar) 
  c:总次数 
  t:总时间 
  l:锁的时间 
  r:获得的结果行数 
  at,al,ar: 指t,l,r平均数 【例如：at = 总时间/总次数】 
-s 对结果进行排序，怎么排，根据后面所带的 (c,t,l,r,at,al,ar)，缺省为at
-t NUM just show the top n queries：仅显示前n条查询 
-g PATTERN 正则匹配

结果

Reading mysql slow query log from /var/lib/mysql/3c86be2ff75f-slow.log
Count: 2  Time=1.02s (2s)  Lock=0.00s (0s)  Rows=5046.0 (10092), root[root]@[113.110.222.149]
  SELECT * FROM tb_a a LEFT JOIN tb_b b
  on a.id = b.a_id
  1. 压测查询购物车接口

同理，基于skywalking分析这个接口的执行链路跟踪，对于sql操作耗时的拉出sql分析执行计划并优化，不再赘述。
特别地，发现链路追踪图gateway网关的请求时间很长，而跳过网关直接压测接口qps有翻倍地提升，开始尝试优化网关gateway应用。

5.1 网关背景

  • API网关为微服务架构的系统提供简单、有效且统一的API路由管理，作为系统的统一入口。主要功能包含认证、鉴权、路由转发、安全策略、防刷、流量控制、监控日志等。
  • SpringCloud Gateway 是基于 Spring 5.0，Spring Boot 2.0 和 Project Reactor 等技术开发的网关。为了提升网关的性能，SpringCloud Gateway 是基于 WebFlux 框架实现的，而 WebFlux 框架底层则使用了高性能的 Reactor 模式通信框架 Netty。
  • SpringCloudGateway 是由 WebFlux+Netty+Reactor 实现的响应式的API网关。

  • 客户端向SpringCloudGateway发出请求，如果请求与网关程序定义的路由匹配，则该请求就会被发送到网关Web处理程序，此时处理程序运行特定的请求过滤器链。
  • 过滤器之间用虚线分开的原因是过滤器可能会在发送代理请求的前后执行逻辑。所有pre过滤器逻辑先执行，然后执行代理请求；代理请求完成后，执行post过滤器逻辑。

5.2 Gateway源码分析

  • DispatcherHandler#handle ：WebFlux的请求入口，请求调度器，负责请求分发，请求和响应实例会被封装为ServerWebExchange。 （对比webmvc的DispatcherServlet#doDispatch理解）在DispatcherHandler中三个依次调用的核心接口是HandlerMapping、HandlerAdapter、HandlerResultHandler。

DispatcherHandler接收到请求，先匹配 HandlerMapping，此处会匹配到RoutePredicateHandlerMapping。

  • HandlerMapping#getHandler ：HandlerMapping负责路径到handler的映射，它匹配请求对应的路由，并返回一个WebHandler。

匹配路由信息，通过断言判断路由是否可用： 调用 RouteDefinitionRouteLocator#getRoutes () 方法，获得全部 Route ， 并调用 Mono.just(route).filterWhen (Predicate#test) 方法，顺序匹配一个 Route。此时会遍历缓存中的路由列表，然后获取每一个路由的断言器 ，将请求信息传入断言器工厂，根据path去判断是否和当前的路由匹配

绑定路由信息到请求上下文 exchange.getAttributes().put(GATEWAY_ROUTE_ATTR, r)

  • HandlerAdapter#invokeHandler 适配器，适配HandlerMapping返回的handler，执行gateway过滤器链

  • HandlerResultHandler#handleResult 处理响应结果

5.3 分析网关，查看java应用线程、堆占用、GC情况

# arthas 查看线程和堆占用情况：
java -jar arthas-boot.jar  `ps -ef|grep gateway.jar |grep -v grep|awk '{print $2}'`
命令：dashboard   #看线程和堆占用的资源有没有异常情况
命令：thread   #查看下线程执行情况，有没有被阻塞的线程（控制台BLOCKED 参数）
命令：thread ‐n 3   #最繁忙的3个线程（占用cpu最多的前3个），输出栈信息
命令：thread ‐b   #输出阻塞的线程栈信息，如果响应慢，阻塞状态的线程比较多，我们需要重点关注
命令：jvm   #查看有没有死锁（控制台DEADLOCK—COUNT 参数）

# 查看gc情况
命令：ps -ef |grep gateway.jar 或者命令： jps  |grep gateway.jar # 先获取进程编号
命令：jstat -gcutil pid 1000 1000   #查看gc情况
命令：jmap -histo pid | head -30  #如果FGC比较频繁我们可以通过jmap查看下对象占用内存的情况，包括实例个数以及占用内存大小
命令：jinfo -flags pid  #查看当前堆内存情况 设置的JVM参数

5.4 分析网关的性能瓶颈

5.4.1 gateway内部worker线程池繁忙，大量线程占用cpu高，造成堵塞

主从reactor线程池初始化的源码   reactor.netty.resources.LoopResources#create
netty默认工作线程数为  Math.max(Runtime.getRuntime().availableProcessors(), 4)
默认值偏小，可修改 reactor.netty.ioWorkerCount 参数，调节gateway的netty的worker工作线程池的大小

5.4.2 路由数量过多，排序越后的路由匹配越慢，导致吞吐量的下降

重写RoutePredicateHandlerMapping#lookupRoute
posted @ 2022-12-13 22:20  Luke!  阅读(562)  评论(0)  编辑  收藏  举报