Spring 服务响应时间优化
(给ImportNew加星标,提高Java技能)
编译:ImportNew/唐尤华
dzone.com/articles/spring-rest-api-when-you-think-you-improved-perfor
了解有关在Spring服务中提高处理速度的更多信息。
在最新版本的 Java 和 Spring 中,可以很方便地通过任务并行缩短处理时间。是不是必须了解语法它背后的线程使用才能做到这一点?请继续阅读,下文会给出答案。
从代码开始
下面是一个简单的 Service Controller(名叫 users 服务),根据输入的 userId 返回 user 对象:Id、name 和 phoneNumber:
@GetMapping(value = "/users/{userId}")
public User getUsers(@PathVariable String userId) {
logger.info("Getting the user object of: " + userId);
String name = getName(userId);
String phoneNumber = getPhoneNumber(userId);
return new User(userId, name, phoneNumber);
}
private String getName(String userId) {
logger.info("Calling metadata service to get the name of user: " + userId);
String url = "http://localhost:8090/metadata/names/" + userId;
return restTemplate.getForObject(url, String.class);
}
private String getPhoneNumber(String userId) {
logger.info("Calling metadata service to get the phone number of user: " + userId);
String url = "http://localhost:8090/metadata/phoneNumbers/" + userId;
return restTemplate.getForObject(url, String.class);
}
【完整项目可以在github.com/elirandav/springAsyncServlet。该服务是一个发布在嵌入式 Tomcat 上的 Spring Boot 应用程序。运行这种服务不消5分钟就可以完成】。
和上面看到的一样,要获取用户名和电话号码,需要使用其他服务(称作元数据服务 metadata service),这种情况很常见。GET /metadata/names/{userId} 和 GET /metadata/phoneNumbers/{userId} 的响应时间各约为300毫秒。这里重点关注GET users/{userId} 的响应时间(及优化)。用户名和电话号码是随机生成的。
通过 Postman 执行 http://localhost:8888/users/2505 GET 请求,响应时间为661毫秒。这个结果没有出乎我的意料,因为获取用户名大约需要300毫秒,获取电话号码也需要大约300毫秒,二者顺序执行:
17:49:19.432 [nio-8888-exec-3]: Getting the user object of: 2505
17:49:19.433 [nio-8888-exec-3]: Calling metadata service to get the name of user: 2505
17:49:19.783 [nio-8888-exec-3]: Calling metadata service to get the phone number of user: 2505
可以看到所有步骤都由 Tomcat 工作线程执行。
缩短处理时间
获取 name 和 phoneNumber 这两个请求彼此没有依赖,只需要传入 userid。为什么不并行处理,看看能否缩短响应时间?
有几种方式可以实现。CompletableFuture 非常简洁,它是 Java 8 并发 API 的新成员。CompletableFuture.supplyAsync 配合 lambda 表达式看起来很赞(参见下面代码)。只修改4-8行:
@GetMapping(value = "/users_parallel/{userId}")
public User getUsers(@PathVariable String userId) throws ExecutionException, InterruptedException {
logger.info("Getting user object of: " + userId);
CompletableFuture<String> name = CompletableFuture
.supplyAsync(()-> getName(userId));
CompletableFuture<String> phoneNumber = CompletableFuture
.supplyAsync(()-> getPhoneNumber(userId));
return new User(userId, name.get(), phoneNumber.get());
}
通过 Postman 进行 http://localhost:8888/users_parallel/2505 GET 请求,347毫秒就收到了响应。响应时间缩短了近50%。很赞!是时候打开香槟,开始庆祝吗?等等...
与生产商品类似,会出现多个客户端同时请求的情况,因此需要对服务进行性能测试。这也是我们的目标。通常,更多请求意味着更多的活动。先从每秒20个请求基本测试开始。假定 metadata 服务不是瓶颈。
记住,我们的重点是 /users 和 /users_parallel API。
为了模拟客户端请求,使用Gatling(一个用 Scala 开发的开源框架)。在 Gatling 中,执行操作被定义为“simulation 模拟”。定义 simulation 非常容易,可以在这里找到测试中用到的“每60秒发起20个请求”的 simulation。下面是测试结果:橙色线表示活跃的 users/requests 数,在60秒开始急剧下降。
该图描述响应时间伴随时间变化的过程。可以看到随着时间变化响应时间一直增加,平均用时27289毫秒,95%的响应时间为51370毫秒。通过 VisualVM 监视服务,结果没有发现与 CPU 或内存有关的问题。为了进行比较,用相同的基准测试(每秒20个请求) 顺序执行 /users 请求。结果如下:
香槟可以收起来了。我们看到,“改进”前,95%的响应时间明显更短——709毫秒。与开头观察到的处理时间相比,这确实有意义:每个 metadata 服务调用大约需要300毫秒。究竟哪里出了问题?
分析瓶颈
让我们回到并行执行,试着分析瓶颈。下面收到一个请求执行过程日志:
10:14:53.886 [nio-8888-exec-1] : Got request: 2505
10:14:53.887 [onPool-worker-7] : Calling metadata service to get the name of user: 2505
10:14:53.887 [onPool-worker-1] : Calling metadata service to get the phone number of user: 2505
可以看到,调用 metadata 服务不是在 Tomcat 工作线程(即 nio-X-exec-Y)完成的,而是由 ForkJoinPool.commonPool() 线程完成,后者是 CompletableFuture 的默认线程池。
调试线程时,我通常会在不同线程处理中(每个线程的开始、结束)记录 request-id 用来定位瓶颈。因此,加上日志代码后再次运行(简单起见,用 UUID 加用户 id 连接作为 request-id)。重新运行 simulation 并使用 request id(2505_e6a1f189-ee48-4742-8b2d-f506dcbeb599)筛选日志,下面是筛选结果:
21:11:24.553 INFO [o-8888-exec-164] : Got request: 2505_e6a1f189-ee48-4742-8b2d-f506dcbeb599
21:11:39.221 INFO [onPool-worker-1] : Calling metadata service to get the name of user: 2505_e6a1f189-ee48-4742-8b2d-f506dcbeb599
21:11:39.304 INFO [onPool-worker-7] : Calling metadata service to get the phone number of user: 2505_e6a1f189-ee48-4742-8b2d-f506dcbeb599
尽管 Tomcat 线程在21:11:24就开始执行请求,但 ForkJoinPool 线程直到21:11:39才开始调用 metadata 服务。这意味着等待了15秒才有一个可用线程执行 metadata调用。看起来 ForkJoinPool.commonPool() 似乎是瓶颈。Tomcat线程(默认200个)被 ForkJoinPool.commonPool() 阻塞。根据我机器的处理器数量,后者只有8个线程。按照ForkJoinPool文档:
对于需要使用独立或自定义线程池的应用程序,可以使用指定并行级别的ForkJoinPool,默认为处理器个数。
使用 VisualVM 监视线程,总能看到有7个“正在运行”的ForkJoinPool工作线程(其中一个不知道为什么丢失了,欢迎评论):
Tomcat 线程通常处于 “Park” 状态(译注:进入 WAITING 状态)。调用 LockSupport.park 时会触发该状态,这是 CompletableFuture.get 实现的一部分。在示例中,当 Tomcat 线程等待 ForkJoinPool 线程完成时(参见 name.get() 和getUsersParallel 中的phoneNumber.get()。如果200个 Tomcat 线程大多数情况下被这7个线程阻塞,实际上可以把 Tomcat 线程个数设为8,以期望得到相同结果。在 application.properties 中加入以下内容,得到:
server.tomcat.max-threads=8
在 /users_parallel 上运行相同的 simulation,得到的结果与并行 simulation 预览相比要更好一些。平均响应时间为26524毫秒,95%的请求响应时间为49066毫秒。这可能由于上下文切换较少,
因此,使用更少的线程会得到更好的结果。
替代解决方案
我们知道,(200个)Tomcat 线程要求每个线程提供2个可用线程,这样不被阻塞(因为需要获取用户名和电话号码)。因此,拥有400个线程的 CompletableFuture 可以解除瓶颈:
@RestController
public class GetUsersController {
...
ExecutorService executorService = Executors.newFixedThreadPool(400);
@GetMapping(value = "/users_parallel_more_threads/{userId}")
public User getUsersParallelMoreThreads(@PathVariable String userId) throws ExecutionException, InterruptedException {
CompletableFuture<String> name = CompletableFuture
.supplyAsync(()-> getName(userId), executorService);
CompletableFuture<String> phoneNumber = CompletableFuture
.supplyAsync(()-> getPhoneNumber(userId), executorService);
return new User(userId, name.get(), phoneNumber.get());
}
...
}
再次运行 simulation,得到的平均响应时间为339毫秒,95%请求的响应时间为345毫秒,与看到的所有选项相比这个是最好的结果。
总结
我们必须理解 ava.util.concurrent 和 Spring 中线程的用法。下一步工作,实际上取决于服务的使用常见和资源。如果 /users 是一个后台任务,那么顺序执行足以满足要求。如果 /users 是一个面向用户的应用程序,那么响应时间就非常重要。因此,必须采用并行方法管理我们自己的线程池,并根据参数确定线程个数。
备选解决方案需要认真检查,因为实际上已经添加了资源,并且应该能够验证是否与生产环境中的机器匹配。内存应该不是问题(通常会添加400个线程),但是需要确认 CPU 不会疲于进行切换线程。
建议在测试时确认您计算机的性能性能表现最佳时的线程个数。逻辑核心更多或 CPU 更快时(指令/秒)支持的线程也越多。对于 /users 这样的 I/O 密集型任务,线程个数可以多余 CPU 核心数;但是,对于 CPU 密集型任务(比如转码),应该保持线程数等于核心数。
推荐阅读
(点击标题可跳转阅读)
Vavr Option:Java Optional 的另一个选项
看完本文有收获?请转发分享给更多人
关注「ImportNew」,提升Java技能
好文章,我在看❤️