技术优化之耗时浅析

374 阅读12分钟

1 如何发现和描述耗时

耗时主要关注平均耗时(avgRT)或者百分比耗时(P9xxRT),百分比耗时更关注复杂场景。

1.1 Trace

使用中间件提供的Trace工具,正常前端请求带上tracId,后端存储在线程上下文中,rpc调用时框架(二开或者自研)传递过去,对于线程池和异步任务等场景需要定制开发。服务内子方法的耗时监控往往使用中间件提供的注解(类送LocalTrace等等)。这种方式最为正规和通用。

1.2 日志

使用日志打印,可以手动调用多次System.currentTimeMillis()或者使用SpringFrameWork工具类StopWatch。日志打印最好配置MDC上下文使得日志自动带上traceId,方便检索关联的日志。如果想要降低非功能性代码的侵入性,可以使用自定义注解。


public void doSomeThing() {
    long start = System.currentTimeMillis();
    try {
        // do business
    } catch (xxxException e) {
        LOGGER.message("doSomeThing failed", e).error();
        return null;
    } finally {
        long cost = System.currentTimeMillis() - start;
        LOGGER.message("doSomeThing cost").with("time", cost).info();
    }
}

or

StopWatch stopWatch = new StopWatch("collectTime");
stopWatch.start("doSomeThing1");
doSomeThing1()
stopWatch.stop();

stopWatch.start("doSomeThing2");
doSomeThing2()
stopWatch.stop();

LOGGER.message("collectTime cost").with("time", stopWatch.prettyPrint()).info();

其它工具

Arthas

线上问题排查时,没办法修改代码逻辑时,可以使用arthas的trace命令。使用idea的插件能快速生产需要的命令。
trace xxx.degradeResourceNotEnoughRequests -n 5 --skipJDKMethod false

或者生成火焰图

2 常见的策略

2.1 缓存(主要分析常用的读缓存)

这里的缓存主要指用于读加速的读缓存,缓存模式为旁路缓存。读缓存的使用目的为空间换时间的策略来降低数据的获取耗时,主要利用容量更小的高速存储(例如RAM内存、寄存器、CPU缓存)部分数据,全量数据还是放在慢速存储(机械硬盘)中。当RAM内存+机械硬盘组成缓存系统时,RAM内存为高速存储,机械硬盘则为慢速存储;当RAM内存+CPU缓存组成缓存系统时,CPU缓存为高速缓存,RAM内存则为慢速存储。假设慢速存储系统的读取时间为T1,快速存储系统的读取时间为T2,缓存命中的次数为N,则缓存节省的耗时为:N * (T1 - T2),因此读缓存适用的场景为同一数据高频读或者单次读取耗时非常大的场景,除此之外还有使用缓存分担慢速存储负载的。
MySql中就有很多缓存,既有key为执行命令,值为结果的server层读缓存,也有innodb引擎层实现change buffer缓存,都是加速读操作的。
缓存并不是“银弹”,首先缓存的大小往往有限,其次缓存引入了新的复杂度。引入缓存就需要考虑内存占用、缓存命中率(淘汰策略+预热)、数据一致性、缓存雪崩、缓存击穿、缓存穿透、监控,如果是分布式缓存还要考虑缓存系统的可用性以及如何避免缓存系统崩溃对业务的影响。

2.2 多线程

对于多个不相关的类似子任务,多线程往往可以加速任务的完成。多线程的优化收益可以参考Amdahl 定律。多线程也有自己的困扰:如何降低线程的创建成本、java线程模型代码的切换成本、多线程数目的确定(计算密集型和IO密集型有着完全不同的评估方式)、如何避免线程饥饿以及线程安全。

2.3 序列化

序列化方式就是如何用二进制无损地描述对象,主要的考量是序列化后的大小以及耗时。高压缩比(压缩前大小/压缩后大小)往往会带来更长的序列化耗时,因此往往要在两者间的权衡。无损的压缩方式往往就是冗余信息只表示一次的方式、统计特性等,例如前缀压缩、哈夫曼编码等。常见的序列化方式有json、gzip压缩编码、protobuf、zstd。序列化优化往往配合批量处理效果更佳,批量数据往往能提供更高的压缩比。
序列化优化的主要场景是网络带宽的使用,耗时只有部分场景下能优化(网络传输的耗时的优化往往被反序列化的耗时增加给抹平了)。

2.4 异步

拆分任务中非关键路径的部分(不需要立刻执行完,任务后续操作不依赖),使用主线程之外的其它线程来执行,主线程干的活就要少了,因此也能更快结束。例如redis中bigkey 删除、清空数据库、AOF 日志同步写都是在异步线程中完成的。非阻塞任务可以通过任务队列、MQ或者写入任务表的形式传递出去。 有个不常见的用法是非阻塞+轮询的方式处理网关超时的任务。
异步的主要问题是可靠性没法保证。例如在对于一致性有要求的场景,如果异步任务失败,则需要实现一系列补偿动作(回滚本地事务或者重试等),且回滚不一定能执行。

2.5 预计算

预计算的主要思想是在任务中要用时刻之前就开始计算,而不是用的时候才开始去计算。预计算往往会带来资源的浪费,因为资源是否要使用往往不是预计算开始时刻能确定的,所以对于不需要该资源的分支也会预计算一份。

2.6 池化

线程池或者连接池,不做展开,避免每次对象创建和销毁的开支。Netty中堆外对象池就是这个原理。

2.7 数据库优化

数据库优化的主要围绕带宽和索引展开,主要手段是分库、分表、建索引。

2.8 高性能存储/计算

字面意思

2.9 高效的数据结构和算法

这个和具体的业务领域相关。

  • 对于查找,数据结构使用哈希表而不是数组便利匹配,如果使用查找算法可以使用二分查找
  • 判断两个几何体是否相交,可以先用几何体的外包围长方体来判断相交,不相交则肯定不相交,相交则进一步判断

2.10 去除冗余业务操作

如果当前操作或者部分操作是冗余的,即这个操作的结果已经存在,则这样的优化的收益也是最大的。业务中遇到过非常长的操作路径:例如:进入某个业务场景,前端框架默认从服务A取了数据B并记录下来(前端团队1负责),服务A返回的部分数据是从服务B取的,接下来执行一堆操作,接着又进入一个子场景(前端团队2负责),调用服务C,服务C需要从服务B取数据,其中服务A\B\C都是不同后端团队维护的,其中服务C从服务B取数据的操作就是冗余,这部分数据一开始前端就有了。

3 优化实践

3.1 优化case1

脱敏后的业务描述

背景

// 复杂的场景下,该接口2-3秒,d3数据比较大,发现有20M
1. 前端调服务S1接口A传商品id拿到数据d1
   1.1 调用服务S2接口B拿到数据DO d2(rpc调用,主要耗时操作)
   1.2 d2执行业务操作转换为DTO d3并返回
// 复杂的场景下4-6秒都有,网关5秒超时,只有调用链路能看到实际耗时
2. 前端调服务S1接口B传d3获取d4
   2.1 调用服务S2接口C传d3得到d2 (rpc,耗时不短,2-3秒)
   2.2 同步循环调用服务S3接口D传d2得到d4返回 (rpc调用,耗时最长,3-4秒)
上述两个接口在前端都有很多使用的地方。
上述接口流量都不大,单机QPS5左右,pod数5-10
已有的技术栈redis,rocketMQ,公司自研分布式异步任务队列,cos腾讯云对象存储
付费商家NO.1提出的优化要求,因此尽可能时间短,提高他们的优化体验,正合我意。   

行动

整体框架

image.png

异步 + 轮询

任务耗时比较长,防止网关的超时,将任务改为了提交异步任务,利用返回的任务id,等间隔50ms轮询10秒。

多线程

“同步循环调用服务S3接口D传d2得到d4返回”这个流程使用多线程来并发执行

缓存
  • 使用redis缓存任务状态,并利用状态机+lua脚本实现任务状态的原子更新,防止误更新。
  • 任务信息存放在redis中,结果数据存放在对象存储cos中。
  • 当源数据发生变更时,会发送变更消息,消费者会失效redis中的缓存数据。
  • 利用任务状态实现同一时间段内任务至多执行一次,防止重复任务。

image.png

状态机流转描述:

image.png

  • 创建中状态(CREATING)
    使用下述脚本创建任务状态,则结束;创建成功,则执行一些数据准备。数据准备完成则进入创建完成状态(CREATED)。
local key = KEYS[1];
local createTime = ARGV[1];
local lastModifiedTime = ARGV[1];
local taskState = ARGV[3];

-- 检查taskState是否存在,如果taskState存在,返回0
local taskStateExists = redis.call('HEXISTS', key, 'taskState');
if taskStateExists == 1 then
    return 0
end
-- 删除整个hash 
redis.call('DEL', key);
-- 尝试设置字段,刚开始创建任务时间和修改时间是一样的
local result1 = redis.call('HSET', key, 'createTime', createTime);
local result2 = redis.call('HSET', key, 'lastModifiedTime', lastModifiedTime);
local result3 = redis.call('HSET', key, 'taskState', taskState);

-- 检查是否所有字段都设置成功
if result1 == 1 and result2 == 1 and result3 == 1 then
    // 过期时间为一秒
    redis.call('EXPIRE', key, 1);
    return 1
else
    return 0
end
  • 创建完成状态(CREATED)
    当任务在CREATING时,并完成数据准备,提交异步任务成功,并生成任务id时,使用下述脚本修改任务状态,并记录任务id,并返回前端任务id。失败,则结束。
local key = KEYS[1];
local expectedLastModifiedTime = ARGV[1];
local taskId = ARGV[2];
local taskState = ARGV[3];
local newLastModifiedTime = ARGV[4];

-- 获取当前lastModifiedTime值
local currentLastModifiedTime = redis.call('HGET', key, 'lastModifiedTime');

-- 检查lastModifiedTime是否与传入的一致
if currentLastModifiedTime ~= expectedLastModifiedTime then
    return 0;
end

-- 尝试更新字段
local result1 = redis.call('HSET', key, 'taskId', taskId);
local result2 = redis.call('HSET', key, 'taskState', taskState);
local result3 = redis.call('HSET', key, 'lastModifiedTime', newLastModifiedTime);

-- 检查是否所有字段都更新成功
if result1 == 0 or result2 == 0 or result3 == 0 then
    return 0;
end

-- 为整个hash设置过期时间为2秒
redis.call('EXPIRE', key, 2);

-- 返回1,表示所有操作成功
return 1;
  • 任务执行中状态(RUNNING)
    当任务消费者开始消费任务的时候,会将任务状态改为改为RUNNING。
local key = KEYS[1];
local expectedLastModifiedTime = ARGV[1];
local taskState = ARGV[3];
local newLastModifiedTime = ARGV[4];

-- 获取当前lastModifiedTime值
local currentLastModifiedTime = redis.call('HGET', key, 'lastModifiedTime');

-- 检查lastModifiedTime是否与传入的一致
if currentLastModifiedTime ~= expectedLastModifiedTime then
    return 0;
end

-- 尝试更新字段
local result1 = redis.call('HSET', key, 'taskState', taskState);
local result2 = redis.call('HSET', key, 'lastModifiedTime', newLastModifiedTime);

-- 检查是否所有字段都更新成功
if result1 == 0 or result2 == 0 then
    return 0;
end

-- 为整个hash设置过期时间为5秒
redis.call('EXPIRE', key, 5);

-- 返回1,表示所有操作成功
return 1;
  • 任务执行成功状态(SUCCESS)
    当任务执行成功,并将结果gzip压缩并上传COS,如果成功,会将任务改为SUCCESS。
local key = KEYS[1];
local expectedLastModifiedTime = ARGV[1];
local taskState = ARGV[3];
local newLastModifiedTime = ARGV[4];
local cosKey = ARGV[5];

-- 获取当前lastModifiedTime值
local currentLastModifiedTime = redis.call('HGET', key, 'lastModifiedTime');

-- 检查lastModifiedTime是否与传入的一致
if currentLastModifiedTime ~= expectedLastModifiedTime then
    return 0;
end

-- 尝试更新字段
local result1 = redis.call('HSET', key, 'taskState', taskState);
local result2 = redis.call('HSET', key, 'lastModifiedTime', newLastModifiedTime);
local result3 = redis.call('HSET', key, 'cosKey', cosKey);

-- 检查是否所有字段都更新成功
if result1 == 0 or result2 == 0 or result3 == 0 then
    return 0;
end

-- 为整个hash设置过期时间为30分钟
redis.call('EXPIRE', key, 1800);

-- 返回1,表示所有操作成功
return 1;
  • 任务执行失败状态(FAILED)
    当任务执行失败时,由于非系统性的异常引起的失败则会设置状态为失败,系统性异常导致的则会直接删除redis中的任务状态信息。
local key = KEYS[1];
local expectedLastModifiedTime = ARGV[1];
local taskState = ARGV[3];
local newLastModifiedTime = ARGV[4];

-- 获取当前lastModifiedTime值
local currentLastModifiedTime = redis.call('HGET', key, 'lastModifiedTime');

-- 检查lastModifiedTime是否与传入的一致
if currentLastModifiedTime ~= expectedLastModifiedTime then
    return 0;
end

-- 尝试更新字段
local result1 = redis.call('HSET', key, 'taskState', taskState);
local result2 = redis.call('HSET', key, 'lastModifiedTime', newLastModifiedTime);

-- 检查是否所有字段都更新成功
if result1 == 0 or result2 == 0 or result3 == 0 then
    return 0;
end

-- 为整个hash设置过期时间为5分钟
redis.call('EXPIRE', key, 300);

-- 返回1,表示所有操作成功
return 1;

防止重试伪代码的实现:

   // 提交任务时至多重试三次,每次先获取最新的任务状态信息。
   // 如果任务状态已存在
   //    如果任务已经成功,则返回任务结果在cos的地址;如果任务已创建,则返回创建好的taskId;
   //    如果任务已经失败,则返回创建失败;如果任务在创建中,则休眠20ms然后重新尝试上述步骤
   //如果任务状态不存在,则使用创建脚本尝试创建任务,成功则返回taskId,失败则继续上述步骤重试
   retryTimes = 0;
   while retryTimes < MAX_RETRY_TIMES:
      taskInfo = getTaskInfoFromRedis
      if taskInfo exist:
         if taskInfo.taskState is SUCCESS:
            return taskInfo.cosKey
         else if taskInfo.taskState is CREATED:
            return taskInfo.taskId
         else if taskInfo.taskState is FAILED
            return Response.FAILURE
      else:
         res = tryCreateTaskInfoUsingCreate.lua
         if res is available taskId:
            return taskId
      sleep(20ms);
      retryTimes++;
   return Response.FAILURE

结果

同一个方案原来整个流程6-9秒,优化后前端全流程耗时埋点显示,初次调用2秒多。平均耗时1780ms->600ms