本文导读:java
业务简介:node
该服务主要是提供对外的代理接口,大部分接口都会调用第三方接口,获取数据后作聚合处理后,提供给客户端使用。程序员
有一天晚上,系统正处于高峰期间,项目组小伙伴正在津津有味的吃着「加班餐」,刚把🍚塞进嘴里,邮件和短信同时发起来告警。web
有一台服务器接口超时,平时偶尔也会收到相似告警,有时会由于网络波动等缘由。实在很差意思,没事总让人家「网络」同窗背锅 : )。可是,此次告警并无收敛,持续告警了十几分钟以上,感到了不妙。spring
点击邮件中告警的 URL 接口连接,一直在页面转圈圈,响应很慢,悲剧!apache
此刻,默默的把🍱盒饭推到一边去,不忍直视 :( c#
问题定位基本流程:segmentfault
1)肯定影响范围tomcat
该服务后面挂着多台服务器,仅有一台服务器挂掉了,因此对用户不会有太大的影响。
先临时从注册中心上摘掉,别让客户端继续重试到这台机器上了,保留事故现场。服务器
2)排查监控指标
查看接口服务的访问量,由于是晚高峰,所以会比其余时间段用户访问量会更大些,可是这个访问量看上去跟平时同一时段对比,并无特别明显突增现象。
监控上观察服务器的 CPU、内存、IO、网络指标看起来也一切正常。
3)服务器排查
登陆到服务器上,结合监控进一步查看服务器 CPU、内存 等指标,查看服务日志都是正常的,而且也没有发现特别的异常日志输出,Exception 或者 OOM 等异常。
咱们看到的现象是,接口服务已经没法正常响应了,应用跑在 JVM 上,快速经过 JDK 自带的经常使用命令排查一番了。
以下命令打印堆栈信息:
`
jstack -l $pid > jstack.log
`
统计结果以下:
cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c
994 java.lang.Thread.State: WAITING (parking) 501 java.lang.Thread.State: WAITING (on object monitor) 7 java.lang.Thread.State: TIMED_WAITING (sleeping) 13 java.lang.Thread.State: TIMED_WAITING (parking) 2 java.lang.Thread.State: TIMED_WAITING (on object monitor) 23 java.lang.Thread.State: RUNNABLE
若是遇到 java.lang.Thread.State: WAITING (parking)、java.lang.Thread.State: WAITING (on object monitor) 这类线程状态,就要引发注意了,通常可能都是程序自己问题致使的。
根据 java.lang.Thread.State: WAITING 查看 jstack.log 里的堆栈信息,发现了了大量的调用 HttpClient 工具类请求等待挂起的日志,具体堆栈信息待下面详细分析。
这些服务调用都是经过 HttpClient 工具直接调用的,对 Spring RestTemplate 作了一次封装,其底层也是调用的 Apache HttpClient 工具类来实现服务调用的。
除看到上述 jstack 日志异常外,还排查了服务器上的网络状态,这也是运维同窗们经常使用的排查手段。
附上统计网络链接状态的命令:
netstat -n | awk '/^tcp/ {++State[$NF]} END {for(i in State) print i, State[i]}'
统计结果:
TIME_WAIT 9 CLOSE_WAIT 3826 SYN_SENT 2 ESTABLISHED 28 SYN_RECV 8
这里注意了,咱们看到服务器诡异的网络链接统计中,出现了大量的 CLOSE_WAIT 状态的链接。
并且这个状态,当你间隔一段时间再次执行统计命令,仍是会存在,也就是不会被释放掉了,看上去问题有些严重。
进一步猜想,出现这些 CLOSE_WAIT 状态跟接口响应慢应该是有关系的,同时,也跟 java 堆栈信息中出现的 HttpClient 线程阻塞有关系,做为问题突破口去分析。
不如,咱们先来了解下 CLOSE_WAIT 状态,这个 CLOSE_WAIT 状态处于 TCP 网络断开链接过程当中,当客户端发起断连请求,服务端首次收到断连请求,回复确认消息,以后便处于 CLOSE_WAIT 状态了,当服务端响应处理完毕会回复网络包给客户端,正常链接会被关闭掉的。
尽管 CLOSE_WAIT 状态是在 TCP 网络链接四次挥手过程当中的。咱们仍是有必要,先来了解下 TCP 网络链接的三次握手,由于它是请求服务器要作的第一件事情,那就是创建 TCP 链接。
技术源于生活。
咱们能够举个平常生活中的例子来理解 TCP 三次握手的过程。
好比你在微信上想与一位好久不曾谋面的朋友聊一聊:
小东:小升,在吗?
(过了好久... ... )
小升: 在了,你还在吗?
(小东恰好在线,每天刷朋友圈... ... )
小东:嗯嗯,在了
(而后两位开始热聊起来... ...)
若是你平时跟朋友,开头总这么聊天是否是以为很累呢。
其实上面的过程,能够很好的理解 TCP 三次握手的过程。
咱们姑且将小东看作是「客户端」,小升看作是「服务端」。
小东是作名程序员,作 IT 工做。小升在老家开店创业中。
理解TCP三次握手过程:
1)小东做为「客户端」,向做为「服务端」的小升发起聊天,就是发送了一个网络包(包签名为 syn
)给小升。【这是 TCP 第一次握手
,小东状态此时处于 syn_sent
状态】
2)小升收到了小东的聊天网络包,你得确认下吧,表示你收到了。此时,小升还有别的事情,不像小东那样搞 IT 工做的,上班还上着微信。到了晚上,小升得空看了一眼手机微信,弹出了小东的消息。而后,激动的作了个回复「 针对小东发来的 sync
包,作了个 ack
回复确认」。因隔了一段时间了,小升也不肯定小东还在不在线了。【这是 TCP 第二次握手
,小升状态此时处于 syn_rcvd
状态 】
3)小东由于恰好在线,收到了小升的回复确认消息,立刻对此次消息作了一个回复「对着小升给的 sync + ack
,作了进一步 ack
回复确认,这是 TCP 第三次握手
」 。【小升状态此时变成了 established
可立刻聊天状态】
4)此时,小升也在线,两位就开始热聊起来了。【正式传输数据了,小东和小升的状态都处于 established
状态】
上述提到的那些状态 syn_sent
syn_rcvd
established
,正是 TCP 三次握手过程当中涉及的关键状态。
上一张图来直观理解下:
小东和小升的热聊结束了,已经很晚了,也忙了一天了,须要休息了。
小东因工做缘由明天要早起,因此提早跟小升说了:
小东:明天要凌晨4点起床升级系统,我要早点休息了,改天过来请你喝酒!
小升:额 ???这样,反正我也不懂!
小升:那你早点休息吧。你说的这顿酒仍是要喝的!
小东:嗯嗯,晚安啊!你也早点休息。
小升:好的,晚安,兄弟!
对应理解 TCP 四次挥手过程:
1)小东要休息了,发起了 fin1
包打算结束聊天了。【小东状态此时处于 fin_wait1
状态,这是 TCP 第一次挥手
】
2)小升收到了小东的 fin1
包,回复了 ack
确认消息。【此时,小升状态处于 close_wait
状态,小东此时状态为 fin_wait2
,这是 TCP 第二次挥手
】
3)小升来了一次最后确认,不打算继续聊了,发送了 fin2
包。【此时,小升状态处于 last_ack
状态,这是 TCP 第三次挥手
】
4)小东针对小升发来的 fin2
包,最终回复了个 ack
确认。【此时,小东状态处于 time_wait
状态,这是 TCP 第四次挥手
】
为何小东还要处于 time_wait
状态等一下呢?
由于他们按照「老规矩」,得确保最后此次消息小升的确收到了,才能最终结束此次聊天。
time_wait
状态标准持续等待时间是 4
分钟,在这段时间内,小东和小升创建的 TCP 网络链接套接字资源(端口),是不能被其余人所使用的,也不能被系统回收从新利用的。
若是小升没有收到反馈,还会继续问下「重发 fin2 消息」,直到小东发送了 ack 消息成功了。
双方正式关闭聊天通道,释放端口资源,链接关闭。
等待的 4 分钟就是 2 个 MSL,每一个 MSL 是 2 分钟。MSL就是 maximium segment lifetime——最长报文寿命。这个时间是由官方 RFC 协议规定的。
上一张图,进一步直观理解下:
分析完 TCP 四次挥手过程了,当服务端接收到 TCP 断开链接的请求包,须要回复一个确认消息给客户端,此时服务端状态便处于 CLOSE_WAIT 状态了。
咱们清楚了该状态所在的网络链接中的位置,结合前文中提到的问题,大量的线程阻塞在了 HttpClient 调用上。线程状态为 WAITING,服务器上统计出来,有大量处于 CLOSE_WAIT 状态的网络链接没法释放。
线程是 JVM 进程中比较宝贵的资源,若是一直有大量线程处于等待或阻塞状态,慢慢的全部线程都被占满,致使服务无法正常响应了。
咱们来经过 java 线程堆栈信息,再结合源码来分析下具体缘由。
找到第一段关键的堆栈日志
:
"http-nio-8970-exec-1108" #24971 daemon prio=5 os_prio=0 tid=0x00007f45b4445800 nid=0x61ad waiting on condition [0x00007f444ad69000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000006c2f30968> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:380) at org.apache.http.pool.AbstractConnPool.access$200(AbstractConnPool.java:69) at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:246) - locked <0x0000000641c7fe38> (a org.apache.http.pool.AbstractConnPool$2) at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:193) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:303) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:279) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:191) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:89) at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:660) at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:629) at org.springframework.web.client.RestTemplate.getForEntity(RestTemplate.java:329) at com.xxx.proxy.common.util.HttpClientUtil.getForEntity(HttpClientUtil.java:267) at com.xxx.proxy.common.util.HttpClientUtil.getForObject(HttpClientUtil.java:521) ... ...
堆栈日志中出现了大量的上述日志,基本都是 HttpClient 工具类所调用的,全部线程状态处于 java.lang.Thread.State: WAITING (parking)
状态。
出现 WAITING (parking)
线程挂起状态,由于接口服务内部大量调用了第三方接口,要获取 Http 链接,但始终没法获取到,只能等待。
HttpClientUtil 工具类是继承自 Spring RestTemplate 并作了一些参数、重试机制、代理定制,其包路径位于 org.springframework.web.client.RestTemplate
。
类图以下所示:
建立 HttpClient 工具示例代码:
HttpClientFactoryBean httpClientFactoryBean = new HttpClientFactoryBean(config); HttpComponentsClientHttpRequestFactory httpRequestFactory = new HttpComponentsClientHttpRequestFactory(httpClientFactoryBean.getObject()); return new HttpClientUtil(httpRequestFactory);
HttpClientFactoryBean 继承自 AbstractFactoryBean,重写 getObjectType() 和 createInstance() 方法。
类图以下所示:
HttpClientFactoryBean 部分示例方法:
@Override public Class<?> getObjectType() { return HttpClient.class; } @Override protected HttpClient createInstance() { if (restConfig == null) { HttpClients.custom().build(); } // 每一个路由最大的链接数 int maxPerRoute = restConfig.getMaxConnections(); // 总的最大链接数 int maxTotal = restConfig.getMaxTotalConnections(); // 链接超时时间 int connectTimeout = restConfig.getConnectionTimeout(); // 读取数据的超时时间 int socketTimeout = restConfig.getTimeout(); PoolingHttpClientConnectionManager connManager = new PoolingHttpClientConnectionManager(30, TimeUnit.SECONDS); connManager.setDefaultMaxPerRoute(maxPerRoute); connManager.setMaxTotal(maxTotal); connManager.setValidateAfterInactivity(1000); RequestConfig requestConfig = RequestConfig.custom().setConnectTimeout(connectTimeout) .setSocketTimeout(socketTimeout).build(); / ... 省略部分代码 return HttpClients.custom().setConnectionManager(connManager).evictExpiredConnections().setDefaultRequestConfig(requestConfig).build(); }
根据堆栈信息也能看到是从 PoolingHttpClientConnectionManager
的 leaseConnection() 方法获取链接,那咱们能够详细看下源代码,为何没有获取成功呢?
怎么查找源码,经过堆栈信息中的调用栈链路,就能很是容易的找到通过了哪些类哪些方法,第多少行代码。
根据上面jstack中的日志:
org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:380)
根据名称猜想,经过 AbstractConnPool 抽象链接池的类,调用 getPoolEntryBlocking 阻塞式方法获取链接,第 380 行代码。
查看源码:
private E getPoolEntryBlocking( final T route, final Object state, final long timeout, final TimeUnit tunit, final Future<E> future) throws IOException, InterruptedException, TimeoutException { Date deadline = null; // 链接获取超时时间参数 if (timeout > 0) { deadline = new Date (System.currentTimeMillis() + tunit.toMillis(timeout)); } this.lock.lock(); try { final RouteSpecificPool<T, C, E> pool = getPool(route); // .... 省略部分源码 boolean success = false; try { if (future.isCancelled()) { throw new InterruptedException("Operation interrupted"); } // 将 future,实际类型为 Future<CPoolEntry>,放入 pending 双向链表队列中 pool.queue(future); this.pending.add(future); if (deadline != null) { success = this.condition.awaitUntil(deadline); } else { // 这里正是第 380 行源代码 this.condition.await(); success = true; } if (future.isCancelled()) { throw new InterruptedException("Operation interrupted"); } } finally { // In case of 'success', we were woken up by the // connection pool and should now have a connection // waiting for us, or else we're shutting down. // Just continue in the loop, both cases are checked. pool.unqueue(future); this.pending.remove(future); } // check for spurious wakeup vs. timeout if (!success && (deadline != null && deadline.getTime() <= System.currentTimeMillis())) { break; } } throw new TimeoutException("Timeout waiting for connection"); } finally { this.lock.unlock(); } }
查找到第 380 行源码,调用了 condition 的 await() 方法:
this.condition.await();
这里使用了并发包下的 Condition 实现多线程协调通信机制,await() 方法调用后,会将当前线程加入到 Condition 等待队列中,是一个FIFO结构的队列,同时当前线程锁释放,若是不释放,会致使其余线程没法得到锁,可能形成死锁。
await() 方法源码:
public final void await() throws InterruptedException { if (Thread.interrupted()) throw new InterruptedException(); // 加入 Condition 等待队列 Node node = addConditionWaiter(); // 释放当前线程的锁 long savedState = fullyRelease(node); int interruptMode = 0; // 不在 AQS 同步队列中,将当前线程挂起,若是在 AQS 队列中退出循环 while (!isOnSyncQueue(node)) { LockSupport.park(this); if ((interruptMode = checkInterruptWhileWaiting(node)) != 0) break; } // 已被 signal() 方法唤醒,自旋等待尝试再次获取锁 if (acquireQueued(node, savedState) && interruptMode != THROW_IE) interruptMode = REINTERRUPT; if (node.nextWaiter != null) // clean up if cancelled unlinkCancelledWaiters(); if (interruptMode != 0) reportInterruptAfterWait(interruptMode); }
当前线程加入 Condition 等待队列结构图:
当经过 Condtion 调用 signalAll() 或者 signal() 方法时,会获取等待队列的首节点,将其移动到同步队列,利用 LockSupport 唤醒节点中的线程。节点从等待队列,移动到 AQS 同步队列以下结构图所示:
在 AbstractConnPool 类的找到了 release() 释放链接的代码。
release() 方法源码以下:
@Override public void release(final E entry, final boolean reusable) { this.lock.lock(); try { if (this.leased.remove(entry)) { final RouteSpecificPool<T, C, E> pool = getPool(entry.getRoute()); pool.free(entry, reusable); if (reusable && !this.isShutDown) { this.available.addFirst(entry); } else { entry.close(); } onRelease(entry); Future<E> future = pool.nextPending(); if (future != null) { this.pending.remove(future); } else { future = this.pending.poll(); } if (future != null) { this.condition.signalAll(); } } } finally { this.lock.unlock(); } }
咱们看到了释放链接时,调用 this.condition.signalAll();
signalAll() 方法的调用会唤醒全部的全部等待队列线程,虽然唤醒全部,可是仍然只有一个线程能拿到锁,其余线程仍是须要自旋等待。
signalAll() 方法源码以下:
private void doSignalAll(Node first) { lastWaiter = firstWaiter = null; do { Node next = first.nextWaiter; first.nextWaiter = null; // 信号通知 transferForSignal(first); first = next; } while (first != null); } final boolean transferForSignal(Node node) { /* * 设置node的waitStatus:Condition->0 */ if (!compareAndSetWaitStatus(node, Node.CONDITION, 0)) return false; // 加入到AQS的等待队列,让节点继续获取锁,设置前置节点状态为SIGNAL Node p = enq(node); int c = p.waitStatus; if (c > 0 || !compareAndSetWaitStatus(p, c, Node.SIGNAL)) // 调用 LockSupport 的 unpark() 方法唤醒线程 LockSupport.unpark(node.thread); return true; }
剖析完了底层代码,回过头去,咱们看下是由于调用到了 condition 的 await() 无参方法,而且一直没法得到 Http 链接,而后一直占着 tomcat 线程的坑。
getPoolEntryBlocking() 方法的最开始,有个不能忽视的一段代码:
Date deadline = null; // 链接获取超时时间参数 if (timeout > 0) { deadline = new Date (System.currentTimeMillis() + tunit.toMillis(timeout)); }
这段代码一看就是超时时间,猜想一下,代码在此处,timeout 应该就是从链接池获取链接时的等待时间。
getPoolEntryBocking() 方法的下面看到:
if (deadline != null) { success = this.condition.awaitUntil(deadline); }
若是 deadline 不为空,会调用 condtion 的 awaitUtil(deadline) 方法,awaitUtil(deadline) 发方法表示直到达到 deadline 时间还未唤醒,就会自动唤醒,加入 AQS 同步队列获取锁。
咱们能够根据堆栈信息继续往前查找调用者,看看 deadline 中的 timeout 来源。
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:191)
MainClientExec#execute() 方法部分源码:
final HttpClientConnection managedConn; try { final int timeout = config.getConnectionRequestTimeout(); managedConn = connRequest.get(timeout > 0 ? timeout : 0, TimeUnit.MILLISECONDS); } catch(final InterruptedException interrupted) { }
这里的 timeout,即 connectionRequestTimeout,正是计算 deadline 时间的 timeout 值。
印证了咱们的猜想。
初始化 HttpClient 工具的初始配置参数,并无配置 connectionRequestTimeout
这个参数的,该参数也是很关键的,若是没有设置,而且被 park 挂起的线程一直没有被 signal 唤醒,那么会一直等待下去。
因此,必须得设置这个参数。这里的 deadline 是个绝对时间,不为空时,会调用 condition 的 awaitUtil(deadline) 方法,即便没有被 signal 唤醒,也会自动唤醒,去争抢锁,而不会致使未被唤醒就一直阻塞下去。
并且这个 awaitUtil(deadline) 方法跟 awaitNanos(long nanosTimeout) 方法里的 deadline 变量设计上殊途同归。
达到了设定的超时时间,而且没有 signal 过,最终 success
变量为 false 不成功,直接 break 跳出循环,最终会抛出 TimeoutException("Timeout waiting for connection") 异常。
抛出这个异常,系统错误日志中,也就明确了是由于没法得到链接致使的。同时,也避免了一直占用着线程。
上一节,从第一段堆栈日志分析到了 Condition 并发底层源码细节。
可是这还没完,由于咱们统计 java.lang.Thread.State
中,仅分析完了WAITING (parking)
状态,问题缘由也不必定是这个状态致使的。接下来继续分析另外的「异常」线程状态 WAITING (on object monitor)
。
在 java 堆栈中 第二段关键的日志
以下:
"http-nio-8970-exec-462" #24297 daemon prio=5 os_prio=0 tid=0x00007f45b41bd000 nid=0x5f0b in Object.wait() [0x00007f446befa000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at java.net.InetAddress.checkLookupTable(InetAddress.java:1393) - locked <0x00000006c05a5570> (a java.util.HashMap) at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1310) at java.net.InetAddress.getAllByName0(InetAddress.java:1276) at java.net.InetAddress.getAllByName(InetAddress.java:1192) at java.net.InetAddress.getAllByName(InetAddress.java:1126) at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:45) at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:112) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373) at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:89) at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:660) at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:629) at org.springframework.web.client.RestTemplate.getForEntity(RestTemplate.java:329) at com.xxx.tvproxy.common.util.HttpClientUtil.getForEntity(HttpClientUtil.java:267) at com.xxx.tvproxy.common.util.HttpClientUtil.getForObject(HttpClientUtil.java:521) `` java.lang.Thread.State: WAITING (on object monitor),这样的线程状态也要引发格外的注意,监视对象锁,而且一直阻塞着线程不释放。 根据线程堆栈信息看,猜想就是跟 HttpClient 参数设置有关,咱们来分析下建立参数。 查找栈顶信息看到了有调用 Object 对象的 wait() 方法,说明是在等待另外的线程 notify 通知,但迟迟未等到,当前线程就一直处于 WAITING 状态。 继续查找是谁调用的:
at java.net.InetAddress.checkLookupTable(InetAddress.java:1393)
``
这段代码调用引发,仍是要去看下源码:
private static InetAddress[] checkLookupTable(String host) { synchronized (lookupTable) { // If the host isn't in the lookupTable, add it in the // lookuptable and return null. The caller should do // the lookup. if (lookupTable.containsKey(host) == false) { lookupTable.put(host, null); return null; } // If the host is in the lookupTable, it means that another // thread is trying to look up the addresses of this host. // This thread should wait. while (lookupTable.containsKey(host)) { try { // 对应堆栈中的 java.net.InetAddress.checkLookupTable(InetAddress.java:1393) lookupTable.wait(); } catch (InterruptedException e) { } } } // The other thread has finished looking up the addresses of // the host. This thread should retry to get the addresses // from the addressCache. If it doesn't get the addresses from // the cache, it will try to look up the addresses itself. InetAddress[] addresses = getCachedAddresses(host); if (addresses == null) { synchronized (lookupTable) { lookupTable.put(host, null); return null; } } return addresses; }
找到了是 lookupTable 对象,使用了同步块锁 synchronized,内部调用了 lookupTable 对象的 wait() 方法,就是在这里等不到通知,一直阻塞着。
这个问题代码排查一通,你是看不出什么问题来的,由于跟应用程序自己关系不大了,是由于 IPV6 致使的 JVM 线程死锁问题。
参考国外 zimbra 站点 wiki:https://wiki.zimbra.com/wiki/...
这里解释下问题产生的缘由:
应用自己在 IPv4 环境下,若是尝试使用了 IPv6 会致使一些已知问题。
当调用了 Inet6AddressImpl.lookupAllHostAddr() 方法,由于 Java 与操做系统 libc 库之间存在一个bug,当特定的竞态条件发生时,将会致使查找 host 地址动做一直无限循环下去。这种状况发生的频率很低,可是一旦发生将会致使 JVM 死锁问题,进而致使 JVM 中全部线程会被阻塞住。
根据上述分析,在 jstack 堆栈中找到了 第三段关键的堆栈日志
以下:
java.lang.Thread.State: RUNNABLE at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method) at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928) at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323) at java.net.InetAddress.getAllByName0(InetAddress.java:1276) at java.net.InetAddress.getAllByName(InetAddress.java:1192) at java.net.InetAddress.getAllByName(InetAddress.java:1126) at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:45) at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:112) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373) at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) at ... ...
如何判断操做系统是否启用了 IPv6 ?
介绍两种方式:
1)ifconfig
这个很明显就能看得出来,有 inet6 addr
字样说明启用了 IPv6。
2)lsmod
[root@BJ]# lsmod | grep ipv6 Module Size Used by ipv6 335951 73 bridge
主要看 Used 这一列,数值 70+,不支持 IPv6 环境 Used 列是 1。
通过对 java 堆栈中关键线程状态的分析,明确了问题缘由,接下来讲下问题解决方案。
第一个问题:
针对从 Http 链接池中获取不到链接时,可能使线程进入阻塞状态。
在 HttpClient 客户端初始化参数配置中增长 connectionRequestTimeout
,获取链接的超时时间,通常不建议过大,咱们设置为 500ms。
设置后,就会调用底层的 condition#awaitUtil(deadline) 方法,当线程没法被 signal 唤醒,到达了 deadline 绝对时间后,线程会自动从等待队列中被唤醒,加入到 AQS 同步队列争抢锁。
第二个问题:
针对 IPv6 致使的 JVM 进程死锁问题,有两种解决方案:
1)操做系统层面禁用 IPv6
编辑 /etc/sysctl.conf 文件
添加下面两行:
net.ipv6.conf.all.disable_ipv6 = 1 net.ipv6.conf.default.disable_ipv6 = 1
保存,执行 sysctl -p
使其生效。
运行操做系统中执行以下命令直接生效:
sysctl -w net.ipv6.conf.all.disable_ipv6=1 sysctl -w net.ipv6.conf.default.disable_ipv6=1
2)Java 应用程序层面
在应用 JVM 启动参数上添加 -Djava.net.preferIPv4Stack=true
。
从操做系统层面禁用 IPv6,若是服务器上还部署了其余应用,注意观察下,若是遇到一些问题能够借助搜索引擎查下。
咱们有不少台服务器,都是运维来维护的,因此我采用了第二种方式,直接在 JVM 上增长参数,简单方便。
最后的总结:
java 堆栈日志中两个关键的 WAITING
线程状态,先出现了 WAITING (on object monitor)
,因 IPv6 问题触发了 HttpClient 线程池全部线程阻塞。后出现了 WAITING (parking)
,Tomcat 线程接收转发请求,当请求调用到 HttpClient,因没法得到 Http 链接资源,且未设置获取链接的超时时间,形成了大量线程阻塞。
通过对上述两个问题的优化后,上线观察很长一段时间,也经历过比此次问题出现时更高的访问量,再没有出现过 JVM 线程阻塞问题。
经过网络命令行统计,基本不会出现大量的 CLOSE_WAIT
网络链接状态。
欢迎关注个人公众号,扫二维码关注得到更多精彩文章,与你一同成长~