HttpClient SSL Session默认设置导致线程阻塞几分钟的案例分析

开发 前端
通过查看GC Log,发现CMS GC耗时较长,与超时的时间点是能够对应上的,终于发现了线索。发生CMS GC的时候,线程都在忙些什么呢?

问题描述

几年前在做某学习APP的时候,评论服务(comment)访问评论后端服务(comment-server)正常RT在【几毫秒 ~ 几十毫秒】,偶尔(每隔几天)RT达到几十秒甚至几分钟,造成用户看不到评论列表,发表评论失败等不好的体验。

分析过程

系统交互关系

系统交互关系

  • 网关与comment之间通讯协议是LWP(LaiWang Protocol)
  • comment与SLB之间通讯协议是https

comment调用comment-server超时?

在应用调用依赖服务的时候,会记录下【时间戳,依赖类别,调用的接口,响应时间,状态码】等指标信息。
通过监控及日志信息,出现问题的时候与SLB交互的RT是【452秒】,初步定位是【SLB】或【comment-server】处理慢导致的,所以联系了运维同学、负责【comment-server】的同学一起排查。

与SLB交互耗时

SLB日志

其中request_time:0.004秒,upstream_response_time:0.004秒

comment-server处理耗时

应用日志

处理耗时【4毫秒】,看来锅是自己的。

Review代码

应用访问SLB使用的是Apache HttpClient,代码抽象表达如下:

代码示例

这个代码哪里似乎有问题?

GC导致的阻塞?

通过查看GC Log,发现CMS GC耗时较长,与超时的时间点是能够对应上的,终于发现了线索。
发生CMS GC的时候,线程都在忙些什么呢?这时候LWP框架的线程dump起到了关键作用,下面对LWP简单做下介绍。

线程模型

LWP是一个RPC框架,网络通讯框架使用的是netty。

线程模型

业务线程池

线程池初始化

线程池配置

拒绝策略

拒绝策略

在线程blocked的时候,LWP框架打印出了当时的线程栈信息,发现所有业务线程都阻塞在了SSL交互过程中。

问题根因

SSLSessionContext’s ssl session缓存(which is a SoftReference cache) 超时时间默认是86400s (24小时),ssl session缓存大小默认是没有限制的,导致CMS GC处理SoftReference的时候耗时较长导致的。
算是JDK的一个Bug,如下:

JDK Bug描述

解决办法

设置SSLContext实例的sessionCacheSize、sessionTimeout,示例:

sslContext.getClientSessionContext().setSessionCacheSize(1024);
sslContext.getClientSessionContext().setSessionTimeout(60);

不仅https,对于使用SSL通讯的应用同样需要注意上面的问题。


责任编辑:武晓燕 来源: 今日头条
相关推荐

2013-07-02 09:58:38

ClojureClojure教程

2016-09-30 15:13:01

Python代码

2010-01-06 15:35:06

JSON对象

2009-12-29 09:01:46

ADSL断线

2024-04-19 09:37:49

Ollama大语言模型开源

2017-08-03 17:30:26

戴尔IoT设备

2009-11-25 17:22:12

路由器安装

2010-03-01 18:13:22

Python程序

2010-02-23 14:19:30

Python目录操作

2010-01-21 09:46:24

C++程序

2010-01-06 13:39:51

扩展Jquery的Js

2010-03-04 10:01:01

Android基本组件

2009-12-21 13:51:54

ADO.NET处理

2009-11-30 13:27:12

Visual Stud

2021-12-02 11:54:10

云计算云错误配置网络安全

2010-01-26 14:53:43

C++

2022-04-06 09:28:04

漏洞SQL注入

2010-01-21 14:51:02

C++函数指针

2009-12-30 09:58:28

mpls标签

2022-04-12 08:46:30

for 循环遍历字符串
点赞
收藏

51CTO技术栈公众号