性能监测----关于Java应用程序性能的真实故事

　 对于任何机构来说，保证企业应用程序在性能上达到高标准的两个基本要求是：具备在负载接近临界状态的情况下监测应用程序的能力；具备在故障出现时快速找出故障根本原因的能力，不管应用程序是处于QA，两阶段部署（staging），还是部署阶段。

　 　本文的故事都是真实的，文中使用的姓名均为化名。
　
　　本文是一个真正的关于Java性能问题的剧本。首先它概述了Wily企业级Java应用管理解决方案和它在部署前后性能分析中所扮演的角色。然后，我会讲述一些性能下降的事例。你将知道为什么忽略Java应用程序管理是得不偿失的。

　Wily 4解决方案

　　随着一个健康发展的机构成熟，它会自发地研究出一系列的策略和步骤来消除它所经历过?quot;混乱"状态，这些"混乱"发生在和担当关键任务的Java应用程序的性能问题作斗争的过程中。这些机构还知道低下的应用程序性能是和巨大开销紧密相关联的：IT投入收益率低下、以及在资金流和最终用户满意度方面的风险。

　　Wily 技术公司的Wily 4 解决方案允许企业在应用程序生命周期的任何阶段监测、改善、管理企业Java应用程序。

　　它提供了一种通用语言，当Java应用程序出现性能问题时，IT机构内的任何部门都可以利用它迅速地识别并修复问题。

　　有了Wily 4，IT小组能够24/7无间断地监测应用程序的业务功能，找出资金转账、费用支付、商品购买、以及其它核心用例中存在的性能瓶颈--不必修改源码，所有用例都能被映射到底层的servlets、JSP、EJB、以及实现它们的定制代码上。可定制的模版和多种集成选项使Wily 4成为主流系统管理解决方案的完美补充。Wily 4允许机构把Introscope警告发布到现有的运行故障解决途径中，警告中包含了应用程序客户功能的可用性信息（请参见图1）。

　

　　Wily 4 解决方案的关键组成部分包括：Java应用程序监视器Introscope、用于识别系统潜在内存泄漏的Introscope 泄漏监测器、和解决事务相关性能问题的Introscope事务追踪器 。Wily 4 解决方案还包含了Introscope SQL代理和Introscope PowerPacks，用于识别Java应用程序与后台支持系统连接的性能问题。

　　这些解决方案相互结合，提供了一个完整的Java环境下的"整体应用程序"视图。

　性能监测网：设定并达到性能目标

　　作为一种最佳实践，一些机构使用Wily的 Introscope来设定基准并记录应用程序关键组件的响应情况，目的是达到性能目标。企业Java应用程序的成功开发和部署应该包括持续的核心用例基线测量工作，而且在开发它们的时候就应该如此。当开发人员对应用程序进行添加和修改时，这些基线可以为评价应用程序的后续版本提供硬性的统计学评价方法。如果不仔细监测开发过程的每个步骤，最后可能会遇到很多的bug，更糟糕的是，遇到体系结构的瓶颈。如果到了两阶段提交或生产阶段再修复这些瓶颈，付出的代价将会更大。

　　如同一个优秀的侦探，一个好的基线或基准总是不断地询问相同的问题，直到得到满意的答复。这种处理鼓励一种"三思而后行"的方法，该方法多次证明自己是提高软件性能的最有效方法。

　　为了成功加载应用中的所有关键用例，应用程序必须已经实现了所有功能；一段好的性能负载生成脚本在应用程序核心功能检查方面所起的作用相当于出色的一致性检查的两倍。
　　
　　一旦应用程序开始在负载下运行，机构们就需要从功能级上不断监测它的性能，从而识别瓶颈，尤其是在产品阶段的头几个月中。

　　Wily的Introscope能够从Java度量中提取细节并转成真实描述应用程序性能的视图和报告。在最常见的宠物店例子中，度量是针对产品采购、收据返回、产品目录察看、以及库存查找等各个方面的。采用这种方法，调整一个组件的动因不再是因为它运行缓慢，而是因为发现客户收据返回所需的时间长到了让人无法接受的程度。如果没有这样的视图，你可能会浪费宝贵的开发时间在性能调整上，但这些性能对于应用程序的整体成功可能无关紧要。

　　Wily的Introscope可以报告调用数量，以及客户应用程序所有关键组件的平均、最小和最大响应时间。Introscope还能够监测并发情况（对每个方法或业务逻辑组件中线程的监测），并进行内存统计、文件和套接字i/o统计，池化资源利用情况统计（比如，MQ连接）、环境统计、等等。
　　在原型J2EE 应用程序中，充当控制器的servlet、充当模型的EJB、后台连接器 API (比如JDBC、 MQ Series等等)、以及充当视图的JSP都将被监测。机构经常采取简单的附加Introscope定制步骤，这样就可以在不改变源代码的情况下监视专有业务逻辑实现或后台连接器。例如，当Introscope在大型航空公司、电信公司遗留大型机回调、以及无数此类定制后台系统和业务逻辑中运行时，它完成了监测SABRE事务的任务。

　　来自应用程序的数据可以被记录到CSV平面文件和主流数据库中，或者被直接集成到负载生成工具中。

　　每个客户都可以选择最适合自己需求的数据记录和分析方法。写入文件的数据可以按照配置好的文件容量限制被自动取得，这有助于报告和清除的脚本自动化。一些常用数据库也包含了能够获取可用脚本的示例数据。

　　本文余下的部分将着重阐述一些使用Introscope的真实案例。

　"重要的Sleep"

　　费城，星期一，多云而且寒冷。我值白班。客户是一个保险公司，他们的应用程序正在进行两阶段部署。

　　我们监测的程序被称为AUDIT，它是一个遗留绿屏应用程序的Web前端。
　
　　客户的保险代理们使用该应用程序建立新的保险单。AUDIT主要使用CICS作为它的后端数据，并根据同样已经使用了30年的遗留存储过程来进行新的处理，然后把它们解析成JSP。页面被设计成在1-2秒内载入，但每次请求都需要花掉7-8秒。来自CICS的数据表明所有的请求都已经被迅速地处理了。那么问题出在哪里呢？我们需要迅速查清原因。

　　运行在应用程序的数据对象解析程序之上的Wily Introscope定制追踪器显示：每个事务需要进行50-60次调用，而且每次调用的响应时间恰好都是100毫秒。对数据对象构造过程的调查揭示了开发人员的占位逻辑。

　　每个对象需要一个唯一ID。因此构造函数中编写了一个100毫秒的sleep，目的是通过调用系统时钟产生唯一的时间戳。

　结局： 开发人员不再远程设定sleep时间。

　 "缺陷Bean的冒险"

　　德克萨斯，周二的下午。我和一个客户在一起，这个客户费劲地试验了几个月想要解决应用程序的性能问题。当我向Watson博士征求意见时，他用一个core dump作为回答。

　　在产品阶段，因为响应时间过慢本例中的应用程序可能将会失去30%的用户采购。很多请求难以置信地需要运行两分钟以上，然后就超时了。Introscope很快就在一个方法中发现了性能瓶颈，该方法是用来为采购单条目计算销售税的。仅一行的Introscope配置就足以跟踪本例中被实现的全部业务逻辑接口。
　
　　通过进一步检查，我们发现该方法使用Runtime.exec调用了一个新的JVM。在进程之外，这个新的JVM计算单个条目的销售税，然后把结果输出到系统输出上。应用服务器耐心地等待这个输出，然后，对每个条目重复同样的事情。在正常负载情况下，多达50-60个JVM被同时启动和关闭，而每个都需要大约20-40秒的等待时间。

　　我们发现：丢失的事务都是具有多个采购条目的事务，为什么呢？某个开发人员被指派使用包含了EJB接口的第三方税率计算软件来完成销售税的计算，但他却无法把该软件载入到服务器的上下文中。没有办法，他只好求助于软件的示例代码，于是他把例子改写成一段脚本，该脚本传递适当的参数给命令行程序并且在系统输出上生成结果。<BR><BR><B>结局：</B>嫌疑人的发现证明了Perl脚本语言的清白。嫌疑人被开除了。本例子结束。

　"然后，什么都没有了（JDBC游标）”

　　那天是星期三，我距历史上著名的波士顿公共绿地不远。在长时间的载入测试过程中，我的客户总是会用尽所有JDBC游标和MQ Series连接。Wily的 Introscope对分配和回收这些资源的语句进行了监测。借助Introscope的Blame特性，该团队迅速找出了错误的EJB：在高负载情况下，应用程序抛出了异常，结果略过了重要的关闭调用，它们本应该被包含在最后执行的程序块中从而保证资源的释放。

　　结局： 现在，丢失的"关闭"已经被安全地放到了最后的程序块之后。

　"关于同步问题的求救"
　　星期四，我的狗狂叫。喝完了第五杯咖啡，我出门了。

　　Wily的Introscope测出一个专用后台系统的平均事务响应时间是10秒钟。

　　但在10个并发用户的负载测试中，该后台系统的平均事务响应时间却在90-100秒之间。这很有意思，显然后台系统并没有并发地处理请求。通过在调用中使用并发度量，我们迅速地找出了缺陷：九个并发的用户线程在对后台系统的调用中等待，只有一个线程真正在处理任务。
　
　　Wily 并发度量可以捕获以下问题：误把synchronized关键字放到class而不是method符号上、应该有10个实例的资源池仅有一个实例、需要被远程访问的服务器失去了响应。在这种情况下，应用程序无法处理意外的后台系统故障，因此会花掉数分钟或是数小时的时间，从而导致本该在几秒钟之内返回结果的调用过期。并发是从应用程序中找出此类缺陷的一个快速而容易的方法，它使我们可以以更优雅的方式在产品阶段轻松地处理类似的故障。

　结局： 应用程序以及它的所有者在产品阶段工具方面正处于低潮。

　"Maltese 结果集"

　　今天是周五，我在亚特兰大。街道上与其说有很多树，不如直接说有很多桃树。

　　这个客户在大型数据库结果集上遇到了麻烦。

　　因为没有构建一个这样的策略：它保证查询能够被限制，并且以合理的增幅被发放，我的客户在应用服务器内部引起了一个"pig in the python"内存故障。错误的搜索或是查找导致了JVM在GC内存栈上到处横行。应用服务器费力地按照数据库给出的样子读入结果集，这样做最严重的副作用就是给应用程序其他事务响应带来了严重的外部破坏。

　　通过指出数据库查询响应时间和"往返"响应时间不一致，Wily的Introscope SQL代理立即诊断出了故障。后一个度量包含了结果集关闭之前用掉的所有系统时钟时间，但是前者仅包含了捕获数据库回应所花费的时间。往返响应次数和相应的度量之间存在很大的分歧。当然，这种度量只有从应用服务器内部才能捕获。

　结局： 开发团队进行了必要的修改。现在该应用程序被彻底改造了，并在社会中发挥着自己的作用。

　"谋杀JDBC Express"

　   我自愿周六在旧金山工作。最后一个客户访问了Vegas之后，我需要加班了。

　　我不知道自己的JDBC灾难离结束还有多远。客户已经大概知道了如何调整关键数据库事务的响应时间--JDBC语句被测出大概平均需要10毫秒，大多数在上下1毫秒内浮动。

　　那些超出范围的事务是怎么回事呢？我对应用程序使用了Introscope 事务追踪器，并且记录到了在标准负载下出现的一个30毫秒的事务。

　　在以前，没有任何整合工具可以帮助用户找到"有罪的"方法。现在，事务追踪器调用图形，利用Introscope自动除去无关的数据，使客户能够看清森林里的每一棵树：一个单独的事务引发了差不多4000条JDBC语句。即便数据库响应迅速，这么多的查询也足以造成故障。

　　事务追踪器的分析表明：每个校验方法负责处理六条来自调用的JDBC语句--对该方法的调用在每个事务中占据了几乎40%的JDBC 语句。开发团队进行了少量的修改--不到一天的工作量--使用缓冲策略来实现这些校验。CPU占用和处理时间都降下来了；生产率得到了提高。

　结局： 数据库得到了完全的修复，但是从那以后，这个开发团队就被指定开发Swing了。

　"知道得过多的Vector" 星期六的晚上，漫长一周的结束。城市的灯光透过浓雾射了出来。当我正在倒一杯黑麦威士忌的时候，电话铃响了。
　
　　这个客户拥有一个基于J2EE的贸易系统架构，其中的调用是直接针对EJB远程接口的。几个月前，他们更换了JMS实现，现在遇到了CPU过载和生产率下降的问题。"GC Heap Bytes in Use"伴随着每个事务不断地出现，并最终导致了内存不足异常。
　
　　开发团队试验了所有常用的整合工具（profiling tool），但没有一个能够发现泄漏的根源。（请参见图3）

　   
　　

　　Wily Introscope泄漏监测器很快就发现在一个Vector中存在反常增长--该Vector仅仅是应用程序使用的45000种数据结构中的一种。存在问题的Vector中含有事务标识符，它为快速回滚进行临时缓冲。当应用程序中事务数量增长的时候，Vector也随之增加。当对Vector 调用"contain"的时候，新的JMS实现引起了一个出乎意料的结果。这个错误说明，调用"contain"导致了每个事务都增加了条目，而新增事务又会引起Vector的增长。

　结局：

　　讨厌的Vector现在已经被Victor这个名字取代，而且它正良好地运行在佛罗里达的目击者保护程序中。<BR>结束了长长的告别，我走进夜色之中。我不知道下一个案例将会在哪里发生。

　作者简介
　　Dave Martin是Wily技术公司的一位系统工程师。他曾经为很多企业客户工作过，主要工作是鉴别并修正Java应用程序的性能问题。作为Wily技术公司的一位前软件开发人员，Dave具备广泛的J2EE体系结构、软件系统设计和实现方面的知识。

原文转自：http://www.ltesting.net