apache / servicecomb-java-chassis

ServiceComb Java Chassis is a Software Development Kit (SDK) for rapid development of microservices in Java, providing service registration, service discovery, dynamic routing, and service management features
Apache License 2.0
1.9k stars 808 forks source link

vertx-blocked-thread-checker出现超长时间阻塞 #3287

Open njhw12 opened 2 years ago

njhw12 commented 2 years ago

线程堆栈目前发现有两类: 1. Thread Thread[transport-vert.x-eventloop-thread-1,5,main] has been blocked for 11900 ms, time limit is 2000 ms|io.vertx.core.impl.BlockedThreadChecker io.vertx.core.VertxException: Thread blocked at sun.misc.Unsafe.unpark(Native Method) at java.util.concurrent.locks.LockSupport.unpark(LockSupport.java:141) at java.util.concurrent.locks.AbstractQueuedSynchronizer.unparkSuccessor(AbstractQueuedSynchronizer.java:662) at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1266) at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457) at java.util.concurrent.LinkedBlockingQueue.signalNotEmpty(LinkedBlockingQueue.java:176) at java.util.concurrent.LinkedBlockingQueue.offer(LinkedBlockingQueue.java:430) at org.apache.servicecomb.core.executor.LinkedBlockingQueueEx.offer(LinkedBlockingQueueEx.java:47) at org.apache.servicecomb.core.executor.LinkedBlockingQueueEx.offer(LinkedBlockingQueueEx.java:22) at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1371) at org.apache.servicecomb.core.executor.ThreadPoolExecutorEx.execute(ThreadPoolExecutorEx.java:46) at org.apache.servicecomb.core.executor.GroupExecutor.execute(GroupExecutor.java:141) at org.apache.servicecomb.common.rest.AbstractRestInvocation.scheduleInvocation(AbstractRestInvocation.java:147) at org.apache.servicecomb.common.rest.RestProducerInvocation.invoke(RestProducerInvocation.java:52) at org.apache.servicecomb.transport.rest.vertx.VertxRestDispatcher.onRequest(VertxRestDispatcher.java:219) at org.apache.servicecomb.transport.rest.vertx.VertxRestDispatcher$$Lambda$4251/1027787170.handle(Unknown Source) at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1127) at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:151) at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:133) at org.apache.servicecomb.transport.rest.vertx.RestBodyHandler$BHandler.doEnd(RestBodyHandler.java:362) at org.apache.servicecomb.transport.rest.vertx.RestBodyHandler$BHandler.end(RestBodyHandler.java:339) at org.apache.servicecomb.transport.rest.vertx.RestBodyHandler.lambda$handle$0(RestBodyHandler.java:112) at org.apache.servicecomb.transport.rest.vertx.RestBodyHandler$$Lambda$4506/2073179658.handle(Unknown Source) at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100) at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:63) at io.vertx.core.http.impl.HttpEventHandler.handleEnd(HttpEventHandler.java:76) at io.vertx.core.http.impl.Http1xServerRequest.onEnd(Http1xServerRequest.java:565) at io.vertx.core.http.impl.Http1xServerRequest.handleEnd(Http1xServerRequest.java:548) at io.vertx.core.http.impl.Http1xServerConnection$$Lambda$4509/1354880134.handle(Unknown Source) at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:71) at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:163) at io.vertx.core.http.impl.Http1xServerConnection.onEnd(Http1xServerConnection.java:189) at io.vertx.core.http.impl.Http1xServerConnection.onContent(Http1xServerConnection.java:179) at io.vertx.core.http.impl.Http1xServerConnection.handleOther(Http1xServerConnection.java:159) at io.vertx.core.http.impl.Http1xServerConnection.handleMessage(Http1xServerConnection.java:147) at io.vertx.core.net.impl.ConnectionBase.read(ConnectionBase.java:155) at io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:154) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93) at io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler.channelRead(WebSocketServerExtensionHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at io.vertx.core.http.impl.Http1xOrH2CHandler.end(Http1xOrH2CHandler.java:61) at io.vertx.core.http.impl.Http1xOrH2CHandler.channelRead(Http1xOrH2CHandler.java:38) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.lang.Thread.run(Thread.java:750)

2. Thread Thread[transport-vert.x-eventloop-thread-4,5,main] has been blocked for 12089 ms, time limit is 2000 ms|io.vertx.core.impl.BlockedThreadChecker io.vertx.core.VertxException: Thread blocked at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:817) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:460) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.lang.Thread.run(Thread.java:750)

liubao68 commented 2 years ago

看起来是排队请求太多,队列都满了。

njhw12 commented 2 years ago

这个不是排队请求过多吧,目前我们业务使用的是cse的默认配置,是无界队列 根据异常堆栈结合jdk的代码看是入队成功了,只是入队前队列为空,发送队列变为非空通知时,最后释放锁时阻塞了,而且如果怀疑是内存fullgc类的,也不该阻塞近12秒吧

lvorytower commented 2 years ago

最后有结论吧吗??

我也遇到了这个问题, 时延增加导致请求排队过多,队列阻塞。 阻塞了几百秒。 奇怪的是:后端时延恢复以后,还是继续阻塞。服务重启后,就立刻恢复了。

wyhluckydog commented 7 months ago

I also encountered the same problem, the service is restored after restart, is there a solution?

liubao68 commented 7 months ago

I also encountered the same problem, the service is restored after restart, is there a solution?

Do you have the same stack-trace?

wyhluckydog commented 7 months ago

yes

wyhluckydog commented 7 months ago

But I don't know how to deal with it. Disappointment

liubao68 commented 7 months ago

yes

Can you comment with your full stack trace? And if possible, you can try to dump the full stack with jstack.