记一次socket read导致业务线程阻塞的案例分析

本文涉及的产品
应用实时监控服务-用户体验监控,每月100OCU免费额度
Serverless 应用引擎免费试用套餐包,4320000 CU,有效期3个月
可观测可视化 Grafana 版,10个用户账号 1个月
简介: 记一次socket read导致业务线程阻塞的案例分析

问题描述

TAM同学反馈某个应用阻塞了:访问应用健康检查URL也访问不通,目前排查了EDAS、SLB及WAF等云产品均没有发现明显问题。

我登录到ECS,curl健康检查URL,确实已经访问不通了(建立连接超时)。

基本情况

流量是从互联网终端请求过来的,最终经过云产品SLB负载均衡到该应用,该应用使用的是taobao-tomcat-7.0.59,监听端口是8080。

分析过程

系统负载太高了?

首先怀疑是不是因为系统负载太高了,导致应用无法处理请求,所以先检查一下系统指标。

top

对于4c8g的配置来说,CPU、内存、Load等指标都很低。

jstat

GC情况也算正常,不像是系统负载过高导致的问题,需要换个思路了。

网络连接有问题?

从curl结果看是无法建立网络连接,怀疑什么就检查什么,看看网络连接情况吧。

netstat

netstat -ant | grep 8080 | awk '/^tcp/{++state[$NF]};END{for(key in state) print key,state[key]}'

netstat多执行几次,发现CLOSE_WAIT状态的连接一直存在,按道理CLOSE_WAIT状态的连接应该很快就会消失才对;而SYNC_REVC状态也是一种不经常见到的状态,难道真的无法建立连接了?

ss

ss -lnt | grep 8080

从图中看我们的全连接队列最大长度是128,当前全连接数量是129?多执行几次依然是这种状态,全连接队列满了。

netstat -s

netstat -s | grep -E 'overflowed|SYNs'

从图中看有连接不断的连过来,无论是握手成功还是半握手失败的数量都在不断增加。

线程阻塞?

对于网络应用程序来说,通常的线程模型是:独立的线程accept网络连接,拿到连接后丢到另外的线程做报文解析、反序列化、业务处理等,是不是tomcat业务线程阻塞住了?

jstack

通过分析jstack文件,发现tomcat线程都处在java.net.SocketInputStream.socketRead0的地方。

vmtool --action getInstances --className java.lang.Thread --limit 700 --express 'instances.{? #this.getName().equals("http-bio-8080-exec-6")}.{#this.getStackTrace()}'

从jstack线程栈来看,这么多的tomcat业务线程都处于同一个代码逻辑,已经很不正常,通过jstack信息怀疑此时tomcat线程池已经满了?

tomcat thread pool

一路代码跟下去,org.apache.coyote.http11.Http11Protocol类是我们此次关注点,该类线程池配置:

线程池配置的最大线程数

vmtool --action getInstances --className org.apache.coyote.http11.Http11Protocol --express 'instances[0].getExecutor().getMaximumPoolSize()'

可以看到配置的最大线程数是:360

线程池运行状态

vmtool --action getInstances --className org.apache.coyote.http11.Http11Protocol --express 'instances[0].getExecutor().toString()'

从图中看pool size=360,active threads=360,queued tasks=40,说明tomcat线程池已经用满了,到这里curl无法建立连接的原因算是定位到了。

接下来我们根据线程栈一步步排查吧(很多问题不了解业务并不影响问题排查,但是了解业务的话会更快的分析定位问题)。

jad

反编译业务Controller,看看从具体业务逻辑中是否能够找到线索。

jad 类的全局限定名

一眼看去这块代码存在几个很明显的问题:

  • Controller每接收到一个请求都新创建一个DefaultHttpClient对象是不合理的,因为DefaultHttpClient本身就是连接池的概念,全局使用一个就可以了;
  • 由于DefaultHttpClient是方法局部变量,当方法执行完后该对象在某个时候就会被垃圾回收掉,该对象持有的连接能保证安全关闭吗?
  • 该DefaultHttpClient对象没有设置任何socket相关的参数,没有数据返回的情况下,socket.read会不会一直阻塞着?

sc

sc -d org.apache.http.impl.client.DefaultHttpClient

看了下lib目录下有比较新的版本,似乎用新版本更好一些。

vmtool HttpGet

vmtool --action getInstances --className org.apache.http.client.methods.HttpGet --express 'instances[0]'

从图中可以看出请求的url,接下来看一下与这个url的建立的网络连接情况:

netstat -ant | grep 10.3.50.152 | awk '/^tcp/{++state[$NF]};END{for(key in state) print key,state[key]}'

从图中可以看出有360个网络连接,跟tomcat线程池中线程个数基本一致,也就是说tomat线程池中的线程都被阻塞了。

vmtool Socket

我们跟着org.apache.http.impl.client.DefaultHttpClient对象看看Socket的配置信息。

DefaultHttpClient

vmtool --action getInstances --className org.apache.http.impl.client.DefaultHttpClient --express 'instances[0]'

socket是在什么时候创建的?异常socket的创建时间是否有规律性?我们接着一层层找下去

poolEntry

vmtool --action getInstances --className org.apache.http.impl.client.DefaultHttpClient --express 'instances.{? #this.connManager.conn.poolEntry.conn.socket.impl.localport=55084}.{#this.connManager.conn.poolEntry}' -x 2

批量查看Socket创建时间

vmtool -c 5e7cfcd6 --action getInstances --className org.apache.http.impl.client.DefaultHttpClient --express 'instances.{#crt=#this.connManager.conn.poolEntry.created,@org.apache.logging.log4j.core.util.datetime.FastDateFormat@getInstance("yyyy-MM-dd HH:mm:ss,SSS").format(#crt)} --limit 400

出现问题的Socket的创建时间并没有什么规律,也就是说不太可能是因为本应用的一些规律性事件(比如GC、锁等)导致的。

socket

vmtool --action getInstances --className org.apache.http.impl.client.DefaultHttpClient --express 'instances[0].connManager.conn.poolEntry.conn.socket'

从图中看,socket状态是很正常的:created=true,connected=true,closed=false。接下来查看超时时间配置

socket.impl

vmtool --action getInstances --className org.apache.http.impl.client.DefaultHttpClient --express 'instances[0].connManager.conn.poolEntry.conn.socket.impl'

timeout=0,当被调用服务没有响应或是被调用服务连接异常断开而没通知到的情况下,线程会一直阻塞在这里,分析到这里已经比较倾向是服务端没有响应造成了一直read,进而阻塞了整个线程。

如果服务端一直没有响应,那么socket接收队列和http client接收数据的buffer都应该是没有数据,现在我们验证下这个猜想。

该socket接收队列是否有未被应用读取的数据?

netstat -antp | grep 55084

从图中看接收队列是0,没有待处理的数据。

当前接收队列中没有数据,那之前是否接收到过数据呢?

从线程栈看http client代码正在等待解析http head的数据,一路代码跟下去,org.apache.http.impl.io.SessionInputBufferImpl是最终与Socket.InputStream交互的类,该类中存放着接收到数据;

org.apache.http.impl.io.SessionInputBufferImpl是在DefaultHttpClientConnection初始化的时候构建的:

查看SessionInputBuffer是否接收过数据

接下来我们查看下本地端口号是55084的连接,是否之前接收过数据及接收的数据是什么样的

vmtool -c 5e7cfcd6 --action getInstances --className org.apache.http.impl.client.DefaultHttpClient --express 'instances.{? #this.connManager.conn.poolEntry.conn.socket.impl.localport=55084}.{#bf=this.connManager.conn.poolEntry.conn.poolEntry.conn.inbuffer.buffer,@org.apache.commons.codec.binary.StringUtils@newStringUsAscii(#bf)}' -x 2 --limit 50

分析到这里已经颠覆了之前的猜想,之前猜想是由于服务端一直没返回数据造成socket一直阻塞在read上,现在看服务端返回了数据,但是返回的数据格式不符合http协议,所以一直在parseHead处阻塞着(话说这个地方算不算是httpclient的bug?)。

查看了其他有问题的socket,返回的数据也是异常的;

通过tcpdump抓包,从返回的数据看,与分析是一致的:

从返回的异常数据(-ERR … get …)猜测这是服务端代码在访问redis时候出现的报错信息,无论如何服务端出问题了。

解决办法

  • 将异常信息告知服务提供方
  • 优化httpclient使用方式
  • 去掉httpclient低版本依赖,使用高版本httpclient
  • 建立全局httpclient实例
  • 为httpclient设置合适的参数
  • 完善接口监控指标
目录
相关文章
|
2月前
|
存储 NoSQL Redis
Redis 新版本引入多线程的利弊分析
【10月更文挑战第16天】Redis 新版本引入多线程是一个具有挑战性和机遇的改变。虽然多线程带来了一些潜在的问题和挑战,但也为 Redis 提供了进一步提升性能和扩展能力的可能性。在实际应用中,我们需要根据具体的需求和场景,综合评估多线程的利弊,谨慎地选择和使用 Redis 的新版本。同时,Redis 开发者也需要不断努力,优化和完善多线程机制,以提供更加稳定、高效和可靠的 Redis 服务。
56 1
|
2月前
线程CPU异常定位分析
【10月更文挑战第3天】 开发过程中会出现一些CPU异常升高的问题,想要定位到具体的位置就需要一系列的分析,记录一些分析手段。
78 0
|
20天前
|
调度 开发者
核心概念解析:进程与线程的对比分析
在操作系统和计算机编程领域,进程和线程是两个基本而核心的概念。它们是程序执行和资源管理的基础,但它们之间存在显著的差异。本文将深入探讨进程与线程的区别,并分析它们在现代软件开发中的应用和重要性。
38 4
|
2月前
|
安全 Java
Java多线程通信新解:本文通过生产者-消费者模型案例,深入解析wait()、notify()、notifyAll()方法的实用技巧
【10月更文挑战第20天】Java多线程通信新解:本文通过生产者-消费者模型案例,深入解析wait()、notify()、notifyAll()方法的实用技巧,包括避免在循环外调用wait()、优先使用notifyAll()、确保线程安全及处理InterruptedException等,帮助读者更好地掌握这些方法的应用。
24 1
|
3月前
|
JSON 前端开发 JavaScript
socket.io即时通信前端配合Node案例
本文介绍了如何使用socket.io库在Node.js环境下实现一个简单的即时通信前端配合案例,包括了服务端和客户端的代码实现,以及如何通过socket.io进行事件的发送和监听来实现实时通信。
51 2
|
3月前
|
安全 Java 调度
python3多线程实战(python3经典编程案例)
该文章提供了Python3中多线程的应用实例,展示了如何利用Python的threading模块来创建和管理线程,以实现并发执行任务。
67 0
|
3月前
|
并行计算 API 调度
探索Python中的并发编程:线程与进程的对比分析
【9月更文挑战第21天】本文深入探讨了Python中并发编程的核心概念,通过直观的代码示例和清晰的逻辑推理,引导读者理解线程与进程在解决并发问题时的不同应用场景。我们将从基础理论出发,逐步过渡到实际案例分析,旨在揭示Python并发模型的内在机制,并比较它们在执行效率、资源占用和适用场景方面的差异。文章不仅适合初学者构建并发编程的基础认识,同时也为有经验的开发者提供深度思考的视角。
|
4月前
|
存储 监控 Java
|
4月前
|
安全 Java 开发者
Swing 的线程安全分析
【8月更文挑战第22天】
71 4
|
4月前
|
Java 数据库连接 数据库
当线程中发生异常时的情况分析
【8月更文挑战第22天】
127 4