应用系统瓶颈排查和分析的思考-Arthas 实战

tech2022-10-24 101

作者 | 一啦米

【Arthas 官方社区正在举行征文活动，参加即有奖品拿~点击投稿】

背景

业务应用系统接入流程引擎来处理业务应用的流程执行，流程引擎提供多线程高性能异步化来执行流程元素的执行，但是如何设置流程引擎的线程池线程数执行，以及执行线程数和任务数，应用机器资源使用情况之间的关系如何，目前只能通过接入方的人工经验评估，比较粗泛评估，参数的合理性也很难直观的评估，现通过现有的应用系统默认的参数配置进行问题说明。

性能监控

查看 CPU 核数

应用机器的配置是 2 核 CPU 配置：

查看应用机器的负载情况

应用程序的近 15 分钟内的负载严重的超载(平均超出 CPU 执行的 10 倍之多)，应用程序对应的 CPU 和 MEM 的利用率都很高，按照本次单机模拟线上的流量（QPS：10) 不至于出现如此的负载情况吧。

查看应用机器的综合统计

CPU 运行队列中也严重的堵筛(Procs列中指标），应用的 CPU 有效利用率其实并不算太高（US+SY),但是系统出现了严重的 CS(上下文切换)，配合 BI，BO 执行，也间接反馈出一些端倪，具体反馈到应用程序中，还需要进一步分析。

查看应用服务(PID=512)的进程 CPU 执行情况

查看应用机器的磁盘 IO 使用情况

应用系统的线程统计概要

应用系统中居然有如此多的线程(1285),应用系统接入流程 SDK 中的线程池数据设置也不会超过80个线程，为何有如何大的偏差，考虑到应用系统中还存在 RPC，kafka 等相关的技术栈，对于应用系统的线程分布还需要进一步的分析。

应用系统执行 dashboard

GC 回收线程监控统计

应用系统线程执行栈的统计

阻塞线程 ThreadDump 信息

org.apache.log4j.spi.RootLogger is blocking 379 threads.

Pigeon-Server-Request-Processor-46-thread-318 Stack Trace is: java.lang.Thread.State: RUNNABLE at java.lang.Throwable.printStackTrace(Throwable.java:665)

locked <0x000000075332fde8> (a java.io.PrintWriter) at java.lang.Throwable.printStackTrace(Throwable.java:721) at org.apache.log4j.DefaultThrowableRenderer.render(DefaultThrowableRenderer.java:60) at org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInformation.java:87)locked <0x000000074ae96550> (a org.apache.log4j.spi.ThrowableInformation) at org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent.java:413) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:313) at org.apache.log4j.WriterAppender.append(WriterAppender.java:162) at com.dianping.combiz.misc.ExtendedConsoleAppender.append(ExtendedConsoleAppender.java:82) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)eliminated <0x000000075f880030> (a com.dianping.combiz.misc.ExtendedConsoleAppender) at com.dianping.combiz.misc.ExtendedConsoleAppender.doAppend(ExtendedConsoleAppender.java:75)locked <0x000000075f880030> (a com.dianping.combiz.misc.ExtendedConsoleAppender) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66) at org.apache.log4j.Category.callAppenders(Category.java:206)- locked <0x000000075ed2bd58> (a org.apache.log4j.spi.RootLogger)at org.apache.log4j.Category.forcedLog(Category.java:391)at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:576) at com.meituan.mafka.client.producer.DefaultProducerProcessor.doSend(DefaultProducerProcessor.java:832) at com.meituan.mafka.client.producer.DefaultProducerProcessor.sendMessage(DefaultProducerProcessor.java:603) at com.meituan.mafka.client.producer.DefaultProducerProcessor.sendMessage(DefaultProducerProcessor.java:584) at com.meituan.mafka.client.producer.DefaultProducerProcessor.sendMessage(DefaultProducerProcessor.java:567) at com.meituan.mafka.client.producer.DefaultProducerProcessor.sendMessage(DefaultProducerProcessor.java:562) at com.dianping.poi.flowcenter.mq.WorkflowEventMQProducer.sendSyncMessage(WorkflowEventMQProducer.java:98) at com.dianping.poi.flowcenter.WorkflowEngine.createFlowInstance(WorkflowEngine.java:642) at com.dianping.poi.flowcenter.WorkflowEngine.startWorkflow0(WorkflowEngine.java:560) at com.dianping.poi.flowcenter.WorkflowEngine.startWorkflow(WorkflowEngine.java:504) at com.dianping.poi.mainflow.clearengine.engine.create.impl.CreateWorkflowServiceImpl.createWorkflow(CreateWorkflowServiceImpl.java:66) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.createWorkflow(WorkflowBusiness.java:277) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.createWorkflow(WorkflowBusiness.java:183) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.createWorkflow(WorkflowBusiness.java:176) at com.dianping.poi.mainflow.core.business.WorkflowBusiness

F a s t C l a s s B y S p r i n g C G L I B

f3bb47a4.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy

C g l i b M e t h o d I n v o c a t i o n . i n v o k e J o i n p o i n t (C g l i b A o p P r o x y . j a v a : 736) a t o r g . s p r i n g f r a m e w o r k . a o p . f r a m e w o r k . R e f l e c t i v e M e t h o d I n v o c a t i o n . p r o c e e d (R e f l e c t i v e M e t h o d I n v o c a t i o n . j a v a : 157) a t o r g . s p r i n g f r a m e w o r k . a o p . i n t e r c e p t o r . E x p o s e I n v o c a t i o n I n t e r c e p t o r . i n v o k e (E x p o s e I n v o c a t i o n I n t e r c e p t o r . j a v a : 92) a t o r g . s p r i n g f r a m e w o r k . a o p . f r a m e w o r k . R e f l e c t i v e M e t h o d I n v o c a t i o n . p r o c e e d (R e f l e c t i v e M e t h o d I n v o c a t i o n . j a v a : 179) a t o r g . s p r i n g f r a m e w o r k . a o p . f r a m e w o r k . C g l i b A o p P r o x y

DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) at com.dianping.poi.mainflow.core.business.WorkflowBusiness

E n h a n c e r B y S p r i n g C G L I B

e721a2aa.createWorkflow() at com.dianping.poi.mainflow.update.biz.business.MainUpdateFlowBusiness.update(MainUpdateFlowBusiness.java:220) at com.dianping.poi.mainflow.update.biz.business.MainUpdateFlowBusiness.update(MainUpdateFlowBusiness.java:179) at com.dianping.poi.mainflow.feedback.biz.serviceImpl.FeedbackForPoiServiceImpl.dpFeedbackBase(FeedbackForPoiServiceImpl.java:1233) at com.dianping.poi.mainflow.feedback.biz.serviceImpl.FeedbackForPoiServiceImpl.dpTerminalFeedback(FeedbackForPoiServiceImpl.java:486) at sun.reflect.GeneratedMethodAccessor144.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at com.dianping.pigeon.remoting.provider.service.method.ServiceMethod.invoke(ServiceMethod.java:193) at com.dianping.pigeon.remoting.provider.process.filter.BusinessProcessFilter.invoke(BusinessProcessFilter.java:79) at com.dianping.pigeon.remoting.provider.process.filter.BusinessProcessFilter.invoke(BusinessProcessFilter.java:34) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.GatewayProcessFilter.invoke(GatewayProcessFilter.java:242) at com.dianping.pigeon.remoting.provider.process.filter.GatewayProcessFilter.invoke(GatewayProcessFilter.java:51) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.SecurityFilter.invoke(SecurityFilter.java:31) at com.dianping.pigeon.remoting.provider.process.filter.SecurityFilter.invoke(SecurityFilter.java:15) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.GenericProcessFilter.invoke(GenericProcessFilter.java:41) at com.dianping.pigeon.remoting.provider.process.filter.GenericProcessFilter.invoke(GenericProcessFilter.java:24) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.ExceptionProcessFilter.invoke(ExceptionProcessFilter.java:44) at com.dianping.pigeon.remoting.provider.process.filter.ExceptionProcessFilter.invoke(ExceptionProcessFilter.java:27) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.ContextTransferProcessFilter.invoke(ContextTransferProcessFilter.java:43) at com.dianping.pigeon.remoting.provider.process.filter.ContextTransferProcessFilter.invoke(ContextTransferProcessFilter.java:28) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.WriteResponseProcessFilter.invoke(WriteResponseProcessFilter.java:36) at com.dianping.pigeon.remoting.provider.process.filter.WriteResponseProcessFilter.invoke(WriteResponseProcessFilter.java:26) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.TrafficRecordFilter.invoke(TrafficRecordFilter.java:34) at com.dianping.pigeon.remoting.provider.process.filter.TrafficRecordFilter.invoke(TrafficRecordFilter.java:14) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.InnerTracerFilter.invoke(InnerTracerFilter.java:29) at com.dianping.pigeon.remoting.provider.process.filter.InnerTracerFilter.invoke(InnerTracerFilter.java:15) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.MonitorProcessFilter.invoke(MonitorProcessFilter.java:101) at com.dianping.pigeon.remoting.provider.process.filter.MonitorProcessFilter.invoke(MonitorProcessFilter.java:35) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.TracerFilter.invoke(TracerFilter.java:37) at com.dianping.pigeon.remoting.provider.process.filter.TracerFilter.invoke(TracerFilter.java:15) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.filter.ProviderContextFilter.invoke(ProviderContextFilter.java:28) at com.dianping.pigeon.remoting.provider.process.filter.ProviderContextFilter.invoke(ProviderContextFilter.java:18) at com.dianping.pigeon.remoting.provider.process.ProviderProcessHandlerFactory$1.handle(ProviderProcessHandlerFactory.java:99) at com.dianping.pigeon.remoting.provider.process.threadpool.RequestThreadPoolProcessor$2.call(RequestThreadPoolProcessor.java:254) at com.dianping.pigeon.remoting.provider.process.threadpool.RequestThreadPoolProcessor

2 . c a l l (R e q u e s t T h r e a d P o o l P r o c e s s o r . j a v a : 243) a t j a v a . u t i l . c o n c u r r e n t . F u t u r e T a s k . r u n (F u t u r e T a s k . j a v a : 266) a t j a v a . u t i l . c o n c u r r e n t . T h r e a d P o o l E x e c u t o r . r u n W o r k e r (T h r e a d P o o l E x e c u t o r . j a v a : 1142) a t j a v a . u t i l . c o n c u r r e n t . T h r e a d P o o l E x e c u t o r

Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Locked ownable synchronizers:<0x00000007ab2b6228> (a java.util.concurrent.ThreadPoolExecutor$Worker)

Pigeon 阻塞线程 ThreadDump 信息

priority:5 - threadId:0x00007fa599636000 - nativeId:0x2ec8 - nativeId (decimal):11976 - state:BLOCKED stackTrace: java.lang.Thread.State: BLOCKED (on object monitor) at deps.redis.clients.util.RedisInputStream.ensureFill(RedisInputStream.java:207) at deps.redis.clients.util.RedisInputStream.readByte(RedisInputStream.java:47) at deps.redis.clients.jedis.Protocol.process(Protocol.java:204) at deps.redis.clients.jedis.Protocol.read(Protocol.java:271) at deps.redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:305) at deps.redis.clients.jedis.Connection.getBinaryBulkReply(Connection.java:236) at deps.redis.clients.jedis.BinaryJedis.hget(BinaryJedis.java:788) at deps.redis.clients.jedis.BinaryJedisCluster$13.execute(BinaryJedisCluster.java:202) at deps.redis.clients.jedis.BinaryJedisCluster$13.execute(BinaryJedisCluster.java:199) at deps.redis.clients.jedis.JedisClusterCommand.runWithRetries(JedisClusterCommand.java:64) at deps.redis.clients.jedis.JedisClusterCommand.runBinary(JedisClusterCommand.java:41) at deps.redis.clients.jedis.BinaryJedisCluster.hget(BinaryJedisCluster.java:199) at com.dianping.squirrel.client.impl.redis.RedisStoreClientImpl $41 . e x c u t e (R e d i s S t o r e C l i e n t I m p l . j a v a : 1022) a t c o m . d i a n p i n g . s q u i r r e l . c l i e n t . i m p l . A b s t r a c t S t o r e C l i e n t$ MonitorCommand.run(AbstractStoreClient.java:1066) at com.dianping.squirrel.client.impl.redis.RedisStoreClientImpl.hget(RedisStoreClientImpl.java:1018) at com.dianping.poi.mainflow.core.redisdao.TimestampRedisDao.getUpdateTime(TimestampRedisDao.java:18) at com.dianping.poi.mainflow.common.RefreshableCache.checkUpdate(RefreshableCache.java:99)

locked <0x00000007623197a0> (a com.dianping.poi.mainflow.core.cache.FlowTemplateRuleCache) at com.dianping.poi.mainflow.common.RefreshableCache.getValue(RefreshableCache.java:53) at com.dianping.poi.mainflow.common.RefreshableCache.getValue(RefreshableCache.java:43) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.getTemplateRule(WorkflowBusiness.java:160) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.setTemplateByWorkflow(WorkflowBusiness.java:134) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.createWorkflow(WorkflowBusiness.java:253) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.createWorkflow(WorkflowBusiness.java:183) at com.dianping.poi.mainflow.core.business.WorkflowBusiness.createWorkflow(WorkflowBusiness.java:176) at com.dianping.poi.mainflow.core.business.WorkflowBusiness

F a s t C l a s s B y S p r i n g C G L I B

f3bb47a4.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy

C g l i b M e t h o d I n v o c a t i o n . i n v o k e J o i n p o i n t (C g l i b A o p P r o x y . j a v a : 736) a t o r g . s p r i n g f r a m e w o r k . a o p . f r a m e w o r k . R e f l e c t i v e M e t h o d I n v o c a t i o n . p r o c e e d (R e f l e c t i v e M e t h o d I n v o c a t i o n . j a v a : 157) a t o r g . s p r i n g f r a m e w o r k . a o p . i n t e r c e p t o r . E x p o s e I n v o c a t i o n I n t e r c e p t o r . i n v o k e (E x p o s e I n v o c a t i o n I n t e r c e p t o r . j a v a : 92) a t o r g . s p r i n g f r a m e w o r k . a o p . f r a m e w o r k . R e f l e c t i v e M e t h o d I n v o c a t i o n . p r o c e e d (R e f l e c t i v e M e t h o d I n v o c a t i o n . j a v a : 179) a t o r g . s p r i n g f r a m e w o r k . a o p . f r a m e w o r k . C g l i b A o p P r o x y

DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) at com.dianping.poi.mainflow.core.business.WorkflowBusiness

E n h a n c e r B y S p r i n g C G L I B

2 . c a l l (R e q u e s t T h r e a d P o o l P r o c e s s o r . j a v a : 243) a t j a v a . u t i l . c o n c u r r e n t . F u t u r e T a s k . r u n (F u t u r e T a s k . j a v a : 266) a t j a v a . u t i l . c o n c u r r e n t . T h r e a d P o o l E x e c u t o r . r u n W o r k e r (T h r e a d P o o l E x e c u t o r . j a v a : 1142) a t j a v a . u t i l . c o n c u r r e n t . T h r e a d P o o l E x e c u t o r

Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Locked ownable synchronizers: - <0x0000000735ab3bc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

问题说明

通过对应用系统的模拟上线应用运行状态分析，目标找出系统的瓶颈点，以及通过对应用系统的资源使用情况来评估应用系统的相关参数设置是否合理；如何根据应用系统的运行时的性能监控，动态的评估应用系统潜在的瓶颈点，以及预测此瓶颈点对应用的影响，是否可以动态的调配相关应用参数，来自适用应用系统性能，充分利用应用系统资源(CPU,Memory,IO)等，结合应用系统的任务使用特性(CPU 密集型，IO 密集型，MiX 混合性）以及多个线程池任务执行特性，是否能够动态预测。

Arthas 征文活动火热进行中

Arthas 官方正在举行征文活动，如果你有：

使用 Arthas 排查过的问题对 Arthas 进行源码解读对 Arthas 提出建议不限，其它与 Arthas 有关的内容

欢迎参加征文活动，还有奖品拿哦~点击投稿

“阿里巴巴云原生关注微服务、Serverless、容器、Service Mesh 等技术领域、聚焦云原生流行技术趋势、云原生大规模的落地实践，做最懂云原生开发者的公众号。”

最新回复(0)