前言

  一个项目在经历开发、测试、上线后,当时的用户规模还比较小,所以刚刚上线的项目一般会表现稳定。但是随着时间的推移,用户数量的增加,qps的增加等因素会造成项目慢慢表现出网页半天无响应的状况。在之前的工作中也恰巧遇到这个过程,当时对项目进行了很多性能测试和调优,今天借助博客园,将这次性能调优的过程进行整理后写成随笔,希望给广大Java后端开发的工程师提供帮助,也借此机会,对性能调优进行一些总结工作,达到备忘的目的。

测试工具与环境

性能测试工具

  • Loadrunner:一种预测系统行为和性能的负载测试工具。通过以模拟上千万用户实施并发负载及实时性能监测的方式来确认和查找问题,LoadRunner能够对整个企业架构进行测试。企业使用LoadRunner能最大限度地缩短测试时间,优化性能和加速应用系统的发布周期。 LoadRunner可适用于各种体系架构的自动负载测试,能预测系统行为并评估系统性能。
  • VisualVM:JDK的一个集成的分析工具。监控应用程序的性能和内存占用情况、监控应用程序的线程、进行线程转储(Thread Dump)或堆转储(Heap Dump)、跟踪内存泄漏、监控垃圾回收器、执行内存和CPU分析,保存快照以便脱机分析应用程序;同时它还支持在MBeans上进行浏览和操作。尽管 VisualVM自身要在JDK6以上的运行,但是JDK1.4以上版本的程序它都能被它监控。
  • Jstack:用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等。
  • Jps:是JDK 1.5提供的一个显示当前所有java进程pid的命令,简单实用,非常适合在linux/unix平台上简单察看当前java进程的一些简单情况。
  • Awr:Oracle的性能报告。

硬件环境

  192.168.19.28部署了Tomcat的web服务、通过分库将数据写入到192.168.19.34和192.168.19.35这两个不同的Oracle数据库实例中。

注册接口调优

测试场景

  使用Loadrunner模拟1000并发用户,以每10秒钟递增5个用户。

测试过程

测试现象一

  1. 刚开始tps有800左右,192.168.19.28的cpu利用率达到10%,192.168.19.34的cpu利用率达到3%,192.168.19.35的cpu利用率达到3%。
  2. 并发用户数达到80时,tps降到500,192.168.19.28的cpu利用率达到20%左右,192.168.19.34的cpu利用率达到80%,192.168.19.35的cpu利用率达到3%。
  3. 并发用户数达到100时,tps降到300,192.168.19.28的cpu利用率30%左右,192.168.19.34的cpu利用率90%以上,192.168.19.35的cpu利用率3%。
  4. 并发用户数超过200时,192.168.19.28的cpu利用率45%左右,tps稳定在150——200之间。
  根据以上观测数据,发现注册用到的数据库实例只在192.168.19.34上(由于分库的原因),所以192.168.19.35没有什么cpu的变化。但是192.168.19.34的的cpu利用率在并发用户100时,就达到90%以上,这明显是不能接受的。于是将注册服务中的数据库操作全部注掉,只保留业务逻辑,进行测试。

测试现象二

  无论并发用户是多少,直到最大的1000,tps始终稳定在1400左右,192.168.19.28的cpu利用率最大到50%,192.168.19.34的cpu利用率6%,192.168.19.35的cpu利用率3%。
  这次将注册服务中的业务逻辑注掉,只保留一条关于表t_user_info的插入操作,继续测试。

测试现象三

  1. 刚开始tps有800左右,192.168.19.28的cpu利用率10%,192.168.19.34的cpu利用率3%,192.168.19.35的cpu利用率3%。
  2. 并发用户数达到80时,tps降到600,192.168.19.28的cpu利用率20%左右,192.168.19.34的cpu利用率80%,192.168.19.35的cpu利用率3%。
  3. 并发用户数达到100时,tps降到500,192.168.19.28的cpu利用率30%左右,192.168.19.34的cpu利用率90%以上,192.168.19.35的cpu利用率3%。
  4. 并发用户数超过200时,192.168.19.28的cpu利用率45%左右,最后tps稳定在300——350。

使用VisualVM

根据以上测试数据,发现当注册接口只存在业务逻辑,不进行数据库操作时的tps正常,当操作数据库甚至只是对表t_user_info进行插入时,tps下降明显,尤其是192.168.19.34的cpu利用率达到90%以上,所以我怀疑是数据库方面的原因。为了进一步排查原因,给Tomcat增加以下Jmx配置:

JAVA_OPTS="$JAVA_OPTS -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=10207 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false"

启动VisualVM远程连接, 通过监控Tomcat内存(如图1所示),发现之前已经配置好的minor GC垃圾回收状态平稳,full GC只是在Tomcat启动时出现一次,之后再也没有出现。(可以启动jpstat服务,安装visual GC更加直观)

图1 VisualVM远程监控Tomcat

  通过转储Tomcat线程(使用Jps和Jstack,VisualVM转储Tomcat线程没有反应),发现有大量的有关logback线程的阻塞。内容如下:

 tid=0x00007fdbe48c4000 nid=0x7217 waiting for monitor entry [0x00007fdb743d5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:)
- waiting to lock <0x00000007c01ed840> (a ch.qos.logback.core.spi.LogbackLock)
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:)
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:)
at ch.qos.logback.classic.Logger.)
at com.uuzz.los.gateway.web.controller.RequestProcessorSupport.readHead(RequestProcessorSupport.java:)
at com.uuzz.los.gateway.web.controller.RequestProcessorSupport.process(RequestProcessorSupport.java:)
at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:)
at java.lang.reflect.Method.invoke(Method.java:)
at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.doInvokeMethod(HandlerMethodInvoker.java:)
at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:)
at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:)
at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:)
at java.lang.Thread.run(Thread.java:)
由此可见是logback的日志输出对文件写锁导致。最后将logback改为异步方式,此阻塞再没有出现。
但是依然有大量的CobarSqlMapClientTemplate执行的线程等待,具体如下:
 tid=0x00007f2580897000 nid=0x7e1b waiting on condition [0x00007f24e3933000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x0000000788b82410> (a java.util.concurrent.CountDownLatch$Sync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:)
at com.alibaba.cobar.client.support.execution.DefaultConcurrentRequestProcessor.process(DefaultConcurrentRequestProcessor.java:)
at com.alibaba.cobar.client.CobarSqlMapClientTemplate.executeInConcurrency(CobarSqlMapClientTemplate.java:)
at com.alibaba.cobar.client.CobarSqlMapClientTemplate.queryForObject(CobarSqlMapClientTemplate.java:)
at com.alibaba.cobar.client.CobarSqlMapClientTemplate.queryForObject(CobarSqlMapClientTemplate.java:)
at com.alibaba.cobar.client.CobarSqlMapClientTemplate.queryForObject(CobarSqlMapClientTemplate.java:)
at com.uuzz.los.account.dao.impl.UserInfoDaoImpl.getSequence(UserInfoDaoImpl.java:)
at com.uuzz.los.account.service.impl.AbstractUserInfoService.insertUserInfoAndUserDetail(AbstractUserInfoService.java:)
at com.uuzz.los.account.service.impl.AbstractUserInfoService$.doInTransaction(AbstractUserInfoService.java:)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:)
at com.uuzz.los.account.service.impl.AbstractUserInfoService.register(AbstractUserInfoService.java:)
at com.uuzz.los.gwservice.service.standard.impl.UserServiceClientImpl.register(UserServiceClientImpl.java:)
at com.uuzz.los.gateway.facade.impl.standard.UserRegisterFacadeImpl.perform(UserRegisterFacadeImpl.java:)
at com.uuzz.los.gateway.facade.impl.standard.UserRegisterFacadeImpl.perform(UserRegisterFacadeImpl.java:)
at com.uuzz.los.gateway.facade.impl.BusinessFacadeSupport.handleResponse(BusinessFacadeSupport.java:)
at com.uuzz.los.gateway.facade.impl.BusinessFacadeSupport.doBusiness(BusinessFacadeSupport.java:)
at com.uuzz.los.gateway.facade.impl.BusinessFacadeSupport.doBusiness(BusinessFacadeSupport.java:)
at com.uuzz.los.gateway.web.controller.RequestProcessorSupport.process(RequestProcessorSupport.java:)
at sun.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:)
at java.lang.reflect.Method.invoke(Method.java:)
at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.doInvokeMethod(HandlerMethodInvoker.java:)
at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:)
at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:)
at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:)
at java.lang.Thread.run(Thread.java:)

可见是数据库资源阻塞引起。

使用AWR

  最后结合Oracle导出的AWR执行报告,发现SQL软解析为0.43,SQL硬解析为0.01,逻辑读85020.13,物理读0.01,物理写6.83,事务回滚率0.00%,缓存命中率100%,执行计划的Library命中率99.99%,内存排序100.00%,软解析99.18%。说明程序中的SQL没有硬编码,缓存利用率高,如图2所示。

图2  AWR执行报告部分内容一

最后查看Top 5 Timed Events,如图3所示。

图3  AWR执行报告中占用时间最长的事件

发现等待耗时排在第一的是log file sync ,正常情况下,应当是CPU time排第一。结合之前登陆接口中的insert语句,可以知道产生大量的commit的事务,产生大量的日志写。日志写由于系统原因,并发操作缓慢,最终导致插入缓慢。由运维DBA解决日志写的慢等待问题后,性能大幅提升。

如需转载,请标明本文作者及出处——作者:jiaan.gja,本文原创首发:博客园,原文链接:http://www.cnblogs.com/jiaan-geng/p/5093133.html

记一次Web服务的性能调优的更多相关文章

  1. web移动端性能调优及16ms优化

    本文只是一个索引,收集了网络上大部分关于调试及优化方面的文章,从中挑选了一些比较好的文章分享给大家. 移动端性能不及桌面浏览器性能的10分之1,特别是在android设备良莠不齐的情况下,性能显得尤为 ...

  2. web前端性能调优(二)

    项目经过第一波优化之后APP端已基本已经符合我们的要求了,但是TV端还是反应比较慢,页面加载和渲染都比较慢了一点,我觉的还是有必要在进行一些优化,经过前面的优化,我们的优化空间已经小了一部分,不过还是 ...

  3. 性能调优之提高 ASP.NET Web 应用性能的 24 种方法和技巧

    性能调优之提高 ASP.NET Web 应用性能的 24 种方法和技巧   poptest是国内唯一一家培养测试开发工程师的培训机构,以学员能胜任自动化测试,性能测试,测试工具开发等工作为目标.如果对 ...

  4. web前端性能调优

    最近2个月一直在做手机端和电视端开发,开发的过程遇到过各种坑.弄到快元旦了,终于把上线了.2个月干下来满满的的辛苦,没有那么忙了自己准备把前端的性能调优总结以下,以方便以后自己再次使用到的时候得于得心 ...

  5. 记一次sql server 性能调优,查询从20秒至2秒

    一.需求 需求很简单,就是需要查询一个报表,只有1个表,数据量大约60万左右,但是中间有些逻辑. 先说明一下服务器配置情况:1核CPU.2GB内存.机械硬盘.Sqlserver 2008 R2.Win ...

  6. iOS-------应用性能调优的25个建议和技巧

    性能对 iOS 应用的开发尤其重要,如果你的应用失去反应或者很慢,失望的用户会把他们的失望写满App Store的评论.然而由于iOS设备的限制,有时搞好性能是一件难事.开发过程中你会有很多需要注意的 ...

  7. iOS应用性能调优建议

    本文来自iOS Tutorial Team 的 Marcelo Fabri,他是Movile的一名 iOS 程序员.这是他的个人网站:http://www.marcelofabri.com/,你还可以 ...

  8. iOS应用性能调优的25个建议和技巧

    本文来自iOS Tutorial Team 的 Marcelo Fabri,他是Movile的一名 iOS 程序员.这是他的个人网站:http://www.marcelofabri.com/,你还可以 ...

  9. Advacned Puppet: Puppet Master性能调优

    本文是Advanced Puppet系列的第一篇:Puppet master性能调优,谈一谈如何优化和提高C/S架构下master端的性能. 故事情节往往惊人地类似:你是一名使用Puppet管理线上业 ...

随机推荐

  1. ImportError: No module named &#39;requests&#39;

    补充说明: 当前环境是在windows环境下 python版本是:python 3.4. 刚开始学习python,一边看书一边论坛里阅读感兴趣的代码, http://www.oschina.net/c ...

  2. 响应式web设计总结

    简单来说响应式是针对不同的屏幕的大小,比如电脑电脑.Pad设备上,屏幕比较宽的,就可以一行放多个Div.到了手机上,或者Pad竖着拿的的时候,一行就只放1到2个Div就差不多了.这样在移动设备上,无论 ...

  3. MVP模式(Android)

    以前在写项目的时候,没有过多考虑架构模式的问题,因为之前一直做J2EE开发,而J2EE都是采用MVC模式进行开发的,所以在搭建公司项目的时候,也是使用类似MVC的架构(严格来讲,之前的项目还算不上MV ...

  4. iOS 隐藏键盘的几种常见方法

    1.设置return key,然后为Did End On Exit事件添加响应方法,并在方法内添加代码:[self.textfieldName resignFirstResponder]. 2.将背景 ...

  5. discuz sphinx全文检索搜索引擎方案

    基于discuz的索引配置文件,这个配置文件比较灵活,可以根据不同的需求来配置 # # linuxTone full index search configure file # source lt_p ...

  6. RxJava学习入门

    RxJava是什么 一个词:异步. RxJava 在 GitHub 主页上的自我介绍是 "a library for composing asynchronous and event-bas ...

  7. vs2003打包

    怎样将.Net程序部署到没有安装.Net Framwork的机器上? 部署在.Net 平台下开发的应用程序,需要安装安装对应版本的.Net Framwork,而Vsual Studio 2003并没有 ...

  8. Java里的File I/O

    Java的输入流主要由:InputStream和Reader作为基类,把持久化数据读入内存.输出流由OutputStream和Write类作为父类. 其中读如内存的时候,不可能一下去全读进去,需要一个 ...

  9. 一个漂亮灵活的PHP图片验证码

    <?php class Imagecode{ private $width ; private $height; private $counts; private $distrubcode; p ...

  10. IOS 视图控制对象生命周期-init、viewDidLoad、viewWillAppear、viewDidAppear、viewWillDisappear等的区别及用途

    iOS视图控制对象生命周期-init.viewDidLoad.viewWillAppear.viewDidAppear.viewWillDisappear.viewDidDisappear的区别及用途 ...