springcloud服务假死
记一次springcloud服务假死排查过程
前段时间一直在排查线上服务的假死问题，首先，我们服务用的是springcloud微服务架构，注册中心是eureka，每个微服务都2个实例的，由于一个服务实例假死导致网关负载到假死的那个实例从而导致访问超时，先说说假死的服务处于什么状态吧，这个服务仍然会向注册中心发送心跳，浏览器打开http://172.18.44.120:8761/eureka/instances/cloud-service-recommender-172.18.44.128:6002查看实例状态
这个心跳时间一直有变化的，也没有什么异常信息，内存也正常，但是我出注册中心把这个服务强制下线之后，这个服务不会重新注册上去，而在com.netflix.discovery.DiscoveryClient的源码（这个是eureka服务发现的一个客户端），它里面有个renew（）方法，是向注册中心发送心跳进行续约操作的代码
/**
* Renew with the eureka service by making the appropriate REST call
*/
boolean renew() {
EurekaHttpResponse<InstanceInfo> httpResponse;
try {
httpResponse = eurekaTransport.registrationClient.sendHeartBeat(instanceInfo.getAppName(), instanceInfo.getId(), instanceInfo, null);
logger.debug(PREFIX + "{} - Heartbeat status: {}", appPathIdentifier, httpResponse.getStatusCode());
if (httpResponse.getStatusCode() == 404) {
REREGISTER_COUNTER.increment();
logger.info(PREFIX + "{} - Re-registering apps/{}", appPathIdentifier, instanceInfo.getAppName());
long timestamp = instanceInfo.setIsDirtyWithTime();
boolean success = register();
if (success) {
instanceInfo.unsetIsDirty(timestamp);
}
return success;
}
return httpResponse.getStatusCode() == 200;
} catch (Throwable e) {
logger.error(PREFIX + "{} - was unable to send heartbeat!", appPathIdentifier, e);
return false;
}
}
由上面的代码我们可以看到续约的流程是发送心跳（发送服务的appName和instanceId等）给eureka server ，而eureka server 会返回传过来的instanceId也就是这个服务实例是否在注册列表存在的信息，如果不存在会返回404，就会进去上面代码的if语句中 里面主要有个register（）的方法，这个是eureka服务注册的一个方法，也就是说如果我强制服务下线，过30秒（服务默认向eureka server 发送心跳的时间）被下线服务会调用register（）把自己重新注册回eureka server
我们开始怀疑是不是这里出了什么问题，但是没什么收获
我们又想到可能是tomcat线程池满了，查了下服务的当前线程数，卡在了200多不动了，正好符合，因为我们设置的tomcat maxThreads:200 ，那是什么原因造成线程一直不卡着不动呢，我们通过jdk的工具jstack
在服务器上运行命令jstack -l pid > xxx.log 把这个服务的线程信息dump出来分析
"http-nio-7001-exec-207" #1229 daemon prio=5 os_prio=0 tid=0x00007f3b600a2000 nid=0x4da waiting on condition [0x00007f3a9205c000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000d09d4120> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:210)
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:398)
at ch.qos.logback.classic.Logger.info(Logger.java:583)
at com.tgw360.service.impl.WelfareServiceImpl.autoWelfare(WelfareServiceImpl.java:199)
at com.tgw360.service.impl.WelfareServiceImpl$$FastClassBySpringCGLIB$$82ad2726.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:669)
at com.tgw360.service.impl.WelfareServiceImpl$$EnhancerBySpringCGLIB$$f7e7edd5.autoWelfare(<generated>)
at com.tgw360.controller.WelfareController.autoWelfare(WelfareController.java:111)
at sun.reflect.GeneratedMethodAccessor177.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
- locked <0x00000000d3cbdb18> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- <0x00000000d3cadcc8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
从上面的线程信息可以看到 当前线程处于等待状态，parking to wait for <0x00000000d09d4120> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) 意思就说等待获取<0x00000000d09d4120>（对象地址），我们搜索发现200多个线程都处于同一个状态，等待获取这个锁对象，通过这个信息我们继续往下看，是哪一步操作呢，定位到at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:210)
protected void subAppend(E event) {
if (!isStarted()) {
return;
}
try {
// this step avoids LBCLASSIC-139
if (event instanceof DeferredProcessingAware) {
((DeferredProcessingAware) event).prepareForDeferredProcessing();
}
// the synchronization prevents the OutputStream from being closed while we
// are writing. It also prevents multiple threads from entering the same
// converter. Converters assume that they are in a synchronized block.
lock.lock();
try {
writeOut(event);
} finally {
lock.unlock();
}
} catch (IOException ioe) {
// as soon as an exception occurs, move to non-started state
// and add a single ErrorStatus to the SM.
this.started = false;
addStatus(new ErrorStatus("IO failure in appender", this, ioe));
}
}
这个是日志输出相关的代码，真相马上就要出现了
上网百度了下 发现logback1.1.11版本有死锁问题https://www.jianshu.com/p/3d04d2114abf，由于我们用的springboot1.5.6，看了下logback版本，确实是1.1.11，我们打印日志用的是同步的方式没有采用异步，所以导致tomcat线程都卡在打日志的步骤出不来，知道了原因马上把日志的版本做个升级，升级到1.2.3，并采用异步的方式打印日志。配上一份logback-spring.xml配置
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<springProperty scope="context" name="springAppName" source="spring.application.name"/>
<springProperty scope="context" name="hostName" source="eureka.instance.hostname"/>
<springProperty scope="context" name="Port" source="server.port"/>
<!-- 日志在工程中的输出位置 -->
<property name="LOG_FILE" value="${BUILD_FOLDER:-build}/${springAppName}"/>
<!-- 控制台的日志输出样式 -->
<property name="CONSOLE_LOG_PATTERN"
value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr([${springAppName:-},%X{X-B3-TraceId:-},%X{X-B3-SpanId:-},%X{X-Span-Export:-}]){yellow} %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>
<!-- 控制台Appender -->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<!-- Minimum logging level to be presented in the console logs-->
<level>debug</level>
</filter>
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
<charset>utf8</charset>
</encoder>
</appender>
<!-- Appender to log to file -->
<!--<appender name="flatfile" class="ch.qos.logback.core.rolling.RollingFileAppender">-->
<!--<file>${LOG_FILE}</file>-->
<!--<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">-->
<!--<fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.gz</fileNamePattern>-->
<!--<maxHistory>7</maxHistory>-->
<!--</rollingPolicy>-->
<!--<encoder>-->
<!--<pattern>${CONSOLE_LOG_PATTERN}</pattern>-->
<!--<charset>utf8</charset>-->
<!--</encoder>-->
<!--</appender>-->
<!-- 为logstash输出的json格式的Appender -->
<!--<appender name="logstash" class="ch.qos.logback.core.rolling.RollingFileAppender">-->
<!--<file>${LOG_FILE}.json</file>-->
<!--<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">-->
<!--<fileNamePattern>${LOG_FILE}.json.%d{yyyy-MM-dd}.gz</fileNamePattern>-->
<!--<maxHistory>7</maxHistory>-->
<!--</rollingPolicy>-->
<!--<encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">-->
<!--<providers>-->
<!--<timestamp>-->
<!--<timeZone>UTC</timeZone>-->
<!--</timestamp>-->
<!--<pattern>-->
<!--<pattern>-->
<!--{-->
<!--"severity": "%level",-->
<!--"service": "${springAppName:-}",-->
<!--"trace": "%X{X-B3-TraceId:-}",-->
<!--"span": "%X{X-B3-SpanId:-}",-->
<!--"exportable": "%X{X-Span-Export:-}",-->
<!--"pid": "${PID:-}",-->
<!--"thread": "%thread",-->
<!--"class": "%logger{40}",-->
<!--"rest": "%message"-->
<!--}-->
<!--</pattern>-->
<!--</pattern>-->
<!--</providers>-->
<!--</encoder>-->
<!--</appender>-->
<appender name="KAFKA" class="com.github.danielwegener.logback.kafka.KafkaAppender">
<encoder class="com.github.danielwegener.logback.kafka.encoding.PatternLayoutKafkaMessageEncoder">
<layout class="net.logstash.logback.layout.LogstashLayout">
<customFields>{"host":"${hostName}","port":"${Port}"}</customFields>
</layout>
</encoder>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<!-- Minimum logging level to be presented in the console logs-->
<level>info</level>
</filter>
<topic>cloud-logs</topic>
<keyingStrategy class="com.github.danielwegener.logback.kafka.keying.RoundRobinKeyingStrategy"/>
<deliveryStrategy class="com.github.danielwegener.logback.kafka.delivery.AsynchronousDeliveryStrategy"/>
<producerConfig>bootstrap.servers=172.18.44.120:9092,172.18.44.81:9092,172.18.44.123:9092</producerConfig>
<producerConfig>acks=1</producerConfig>
<producerConfig>linger.ms=100</producerConfig>
</appender>
<appender name="ASYNC-CONSOLE" class="ch.qos.logback.classic.AsyncAppender">
<!--默认是false，代表在队列放满的情况下是否卡住线程。也就是说，如果配置neverBlock=true，当队列满了之后，后面阻塞的线程想要输出的消息就直接被丢弃，从而线程不会阻塞。这个配置用于线程很重要，不能卡顿，而且日志又不是很重要的场景，因为很有可能会丢日志。-->
<neverBlock>true</neverBlock>
<!-- 默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志，为了不丢失日志.故设置为0 -->
<discardingThreshold>0</discardingThreshold>
<!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
<queueSize>256</queueSize>
<!-- 添加附加的appender,最多只能添加一个 添加多个只会生效第一个-->
<appender-ref ref ="CONSOLE"/>
</appender>
<root level="info">
<appender-ref ref="ASYNC-CONSOLE"/>
<appender-ref ref="KAFKA"/>
<!--<appender-ref ref="logstash"/>-->
<!--<appender-ref ref="flatfile"/>-->
</root>
</configuration>
现在我们回顾下之前注册中心出现的奇怪的现象，我们看下
我们线上开启的是info日志 所以第一行日志不会打印，也就不会阻塞，也就是说发心跳续约服务的代码不会有问题，但是当我们从注册中心强制下线服务后，服务会走if语句里面，大家看到这行info（）代码了吗，没错，就是卡在这里，所以服务不会重新注册到eureka server，到此所有的问题都能解释的通了。
解决了这个还没完，因为线上不只一个服务假死，我们按照上面的流程把服务的线程dump出来分析：
"http-nio-9029-exec-47" #206 daemon prio=5 os_prio=0 tid=0x00007f0d1401b000 nid=0xde waiting on condition [0x00007f0cbb5f2000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000083bbd858> (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:377)
at org.apache.http.pool.AbstractConnPool.access$200(AbstractConnPool.java:67)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:243)
- locked <0x0000000084c197d8> (a org.apache.http.pool.AbstractConnPool$2)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:191)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:276)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:263)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
at com.tgw360.common.HttpClientUtils.doGet(HttpClientUtils.java:101)
at com.tgw360.service.impl.HxAdClickInfoServiceImpl.call2TouTiao(HxAdClickInfoServiceImpl.java:77)
at com.tgw360.service.impl.HxAdClickInfoServiceImpl.appGetAdClickInfo(HxAdClickInfoServiceImpl.java:60)
at com.tgw360.controller.HxAdClickInfoController.AppHxClickWithState(HxAdClickInfoController.java:182)
at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
- locked <0x0000000084c37428> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- <0x0000000084cc3480> (a java.util.concurrent.ThreadPoolExecutor$Worker)
这个又是另个死锁问题，这个就不说这么详细，最后排查发现是因为写的httpClientUtils工具类出的问题
public static String doGet(String url, Map<String, String> param, Map<String, String> requestHead) {
String result = "";
CloseableHttpResponse response = null;
CloseableHttpClient httpclient = null;
try {
String params = toHttpGetParams(param);
httpclient = getHttpClient();
URI uri = new URIBuilder(url + "?" + params).build();
// 创建http GET请求
HttpGet httpGet = new HttpGet(uri);
httpGet.setConfig(requestConfig());
if (null != requestHead) {
for (Map.Entry<String, String> entry : requestHead.entrySet()) {
String key = entry.getKey();
String value = entry.getValue();
httpGet.addHeader(key, value);
}
}
response = httpclient.execute(httpGet);
Integer statusCode = response.getStatusLine().getStatusCode();
String string = statusCode.toString();
if (string.startsWith("2")) {
result = EntityUtils.toString(response.getEntity(), CHARSET_UTF_8);
}
// result = decodeData(result);
} catch (Exception e) {
logger.error("httpclient doGet 异常", e);
}
return result;
}
由于try-catch少了一步
finally {
try {
if (response != null) {
response.close();
}
} catch (IOException e) {
logger.error("httpclient doGet close response 异常", e);
}
}
没有关闭连接导致连接池一直没有可用的连接，tomcat线程就阻塞在这里获取连接，我们的最大连接数设置是50，但是这个服务在线上运行了几个月了，如果是这个原因不应该早就出现了吗，后来发现EntityUtils.toString(response.getEntity(), CHARSET_UTF_8);这段代码里面有做关闭操作，也就是说如果请求正常的话是不会发生这种问题的，那就说得通了，为了这个我还自己特意测试了下，用ab并发500请求访问测试服务不存在的资源，返回404，结果发现和线上的情况完全吻合，然后就关闭下连接就好了~~