最近项目中的消息服务做了运营商的改动,导致这个服务做了重新开发
压测脚本如下:
开启200线程压测:
tps只有200-300之间,平均耗时在700ms左右
开启500线程压测
500并发压测,发现平均耗时到了1100ms,感觉肯定存在问题,这时候tps才400多
通过打印线程的dump日志:截取部分
2019-01-17 18:05:18
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.60-b09 mixed mode):
"Attach Listener" daemon prio=10 tid=0x00007f971400d800 nid=0x24cc waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"ZodiacServer-172.20.20.115:6004-thread-1670" daemon prio=10 tid=0x00007f94f8138800 nid=0x24b2 waiting on condition [0x00007f94ca0c6000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007801d5c20> (a java.util.concurrent.locks.ReentrantLock$FairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:229)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
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:48)
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_0_Or3Plus(Logger.java:383)
at ch.qos.logback.classic.Logger.info(Logger.java:579)
at ooh.bravo.logging.slf4j.Slf4jLogger.info(Slf4jLogger.java:27)
at ooh.bravo.logging.Journal.info0(Journal.java:46)
at ooh.bravo.logging.LoggerProxy.logging(LoggerProxy.java:25)
at ooh.bravo.logging.LoggerProxy.info(LoggerProxy.java:57)
at com.neo.xnol.message.http.HttpUtil.postBody(HttpUtil.java:135)
at com.neo.xnol.message.zxsms.adapter.wxchina.WxchinaMessageChannel.doSendSms(WxchinaMessageChannel.java:97)
at com.neo.xnol.message.zxsms.adapter.wxchina.WxchinaMessageChannel.sendSingle(WxchinaMessageChannel.java:70)
at com.neo.xnol.message.zxsms.adapter.DefaultMessageChannelAdapter.sendSingle(DefaultMessageChannelAdapter.java:33)
at com.neo.xnol.message.zxsms.engine.impl.SmsMessageProcessor.process(SmsMessageProcessor.java:60)
at com.neo.xnol.message.zxsms.engine.impl.DefaultMessageDispatcher.dispatch(DefaultMessageDispatcher.java:48)
at com.neo.xnol.message.zxsms.engine.impl.DefaultMessageDispatcher$$FastClassBySpringCGLIB$$fb6cd581.invoke()
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
at com.neo.xnol.message.zxsms.baffle.aspect.BaffleAspect.execute(BaffleAspect.java:42)
at sun.reflect.GeneratedMethodAccessor278.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:620)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:609)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:68)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
at com.neo.xnol.message.zxsms.engine.impl.DefaultMessageDispatcher$$EnhancerBySpringCGLIB$$6f7ebe16.dispatch()
at com.neo.xnol.message.zxsms.facade.impl.MessageGatewayFacadeImpl.sendSingle(MessageGatewayFacadeImpl.java:49)
at ooh.bravo.zodiac.common.bytecode.Wrapper37.invokeMethod(Wrapper37.java)
at ooh.bravo.zodiac.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:26)
at ooh.bravo.zodiac.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:54)
at ooh.bravo.zodiac.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:35)
at ooh.bravo.zodiac.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:35)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.monitor.support.MonitorFilter.invoke(MonitorFilter.java:40)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.ContextFilter.invoke(ContextFilter.java:36)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.DynamicLinkTrackingFilter.invoke(DynamicLinkTrackingFilter.java:57)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.DubboProviderFilter.invoke(DubboProviderFilter.java:34)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:18)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.EchoFilter.invoke(EchoFilter.java:19)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.ProviderHandlingLoggingFilter.invoke(ProviderHandlingLoggingFilter.java:48)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.protocol.zodiac.ZodiacProtocol$1.reply(ZodiacProtocol.java:78)
at ooh.bravo.zodiac.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:59)
at ooh.bravo.zodiac.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:148)
at ooh.bravo.zodiac.remoting.transport.DecodeHandler.received(DecodeHandler.java:30)
at ooh.bravo.zodiac.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:66)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- <0x000000079e4182e8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"ActiveMQ Session Task-99" prio=10 tid=0x00007f969007d000 nid=0x24b0 waiting on condition [0x00007f94ca18a000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000790e42e98> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- None
"bravo-HikariCP connection adder" daemon prio=10 tid=0x00007f9610075800 nid=0x248e runnable [0x00007f94ca1cb000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000780150d20> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- None
"ZodiacServer-172.20.20.115:6004-thread-1669" daemon prio=10 tid=0x00007f94d40ab000 nid=0x248d waiting on condition [0x00007f94ca20b000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007801d5c20> (a java.util.concurrent.locks.ReentrantLock$FairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:229)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
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:48)
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_0_Or3Plus(Logger.java:383)
at ch.qos.logback.classic.Logger.info(Logger.java:579)
at ooh.bravo.logging.slf4j.Slf4jLogger.info(Slf4jLogger.java:27)
at ooh.bravo.logging.Journal.info0(Journal.java:46)
at ooh.bravo.logging.LoggerProxy.logging(LoggerProxy.java:25)
at ooh.bravo.logging.LoggerProxy.info(LoggerProxy.java:57)
at com.neo.xnol.message.zxsms.facade.impl.MessageGatewayFacadeImpl.sendSingle(MessageGatewayFacadeImpl.java:69)
at ooh.bravo.zodiac.common.bytecode.Wrapper37.invokeMethod(Wrapper37.java)
at ooh.bravo.zodiac.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:26)
at ooh.bravo.zodiac.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:54)
at ooh.bravo.zodiac.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:35)
at ooh.bravo.zodiac.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:35)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.monitor.support.MonitorFilter.invoke(MonitorFilter.java:40)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.ContextFilter.invoke(ContextFilter.java:36)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.DynamicLinkTrackingFilter.invoke(DynamicLinkTrackingFilter.java:57)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.DubboProviderFilter.invoke(DubboProviderFilter.java:34)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:18)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.EchoFilter.invoke(EchoFilter.java:19)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.filter.ProviderHandlingLoggingFilter.invoke(ProviderHandlingLoggingFilter.java:48)
at ooh.bravo.zodiac.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:78)
at ooh.bravo.zodiac.rpc.protocol.zodiac.ZodiacProtocol$1.reply(ZodiacProtocol.java:78)
at ooh.bravo.zodiac.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:59)
at ooh.bravo.zodiac.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:148)
at ooh.bravo.zodiac.remoting.transport.DecodeHandler.received(DecodeHandler.java:30)
at ooh.bravo.zodiac.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:66)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- <0x000000079d2cf080> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"ZodiacServer-172.20.20.115:6004-thread-1668" daemon prio=10 tid=0x00007f94d40a9000 nid=0x248c runnable [0x00007f94ca24c000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
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.htt