phpsocketread卡住技巧_记一次socket read导致营业线程壅塞的案例分析arthas神器也

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

jstat

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

从curl结果看是无法建立网络连接，疑惑什么就检讨什么，看看网络连接情形吧。

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 -lnt | grep 8080

全连接行列步队

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

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

全连接和半连接被drop的数量

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

对付网络运用程序来说，常日的线程模型是：独立的线程accept网络连接，拿到连接后丢到其余的线程做报文解析、反序列化、业务处理等，是不是tomcat业务线程壅塞住了？

通过剖析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()}'

vmtool精确定位线程栈

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

一起代码跟下去，org.apache.coyote.http11.Http11Protocol类是我们这次关注点，该类线程池配置：线程池配置的最大线程数

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

vmtool获取tomcat线程配置

可以看到配置的最大线程数是：360线程池运行状态

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

vmtool获取线程运行状态

从图中看pool size=360,active threads=360,queued tasks=40,解释tomcat线程池已经用满了，到这里curl无法建立连接的缘故原由算是定位到了。
接下来我们根据线程栈一步步排查吧（很多问题不理解业务并不影响问题排查，但是理解业务的话会更快地剖析定位问题）。

反编译业务Controller，看看从详细业务逻辑中是否能够找到线索。

jad 类的全局限定名

jad反编译查看业务代码

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

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

sc查看依赖包

看了下lib目录下有比较新的版本，彷佛用新版本更好一些。

vmtool HttpGet

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

vmtool查看HttpGet

从图中可以看出要求的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线程池中的线程都被壅塞了。

我们随着org.apache.http.impl.client.DefaultHttpClient工具看看Socket的配置信息。

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

vmtool查看DefaultHttpClient

socket是在什么时候创建的？非常socket的创建韶光是否有规律性？我们接着一层层找下去

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

vmtool查看PoolEntry

批量查看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

vmtool查看socket创建韶光

涌现问题的Socket的创建韶光并没有什么规律，也便是说不太可能是由于本运用的一些规律性事宜（比如GC、锁等）导致的。

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

socket配置信息

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

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

socket配置信息

timeout=0，当被调用做事没有相应或是被调用做事连接非常断开而没关照到的情形下，线程会一贯壅塞在这里，剖析到这里已经比较方向是做事端没有相应造成了一贯read，进而壅塞了全体线程。
如果做事端一贯没有相应，那么socket吸收行列步队和http client吸收数据的buffer都该当是没有数据，现在我们验证下这个猜想。

netstat -antp | grep 55084

查看吸收行列步队是否有数据

从图中看吸收行列步队是0，没有待处理的数据。

从线程栈看http client代码正在等待解析http head的数据，一起代码跟下去，org.apache.http.impl.io.SessionInputBufferImpl是终极与Socket.InputStream交互的类，该类中存放着吸收到数据；org.apache.http.impl.io.SessionInputBufferImpl是在DefaultHttpClientConnection初始化的时候构建的：

SessionInputBufferImpl

接下来我们查看下本地端口号是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抓包，从返回的数据看，与剖析是同等的：

tcpdump抓包验证

从返回的非常数据（-ERR … get …）预测这是做事端代码在访问redis时候涌现的报错信息，无论如何做事端出问题了。