通过日志监控并收集Java应用程序性能数据

通过日志监控并收集Java应用程序性能数据2013-09-20 IBM 商涛, 姚黎引言

系统日志是应用程序问题诊断及运行维护的重要工具。Logback、Log4j 是常用于 Java 平台的日志记录 API. 目前大部分产品只是将系统重要参数、状态的变化及异常信息通过日志输出。本文将要介绍的 Perf4j 是一款专门用于 Java 服务器端代码计时、记录日志和监控结果的开源工具包。Perf4j 对常用日志工具包进行了扩展，能够将得到的原始性能数据进行统计并发布到可定制的输出源，如控制台、日志文件、JMX 等。Perf4j 提供了多种方式与 Java 代码集成，开发和系统维人员能够灵活地将 Perf4j 的 API 嵌入到各种不同架构的应用程序中。

Perf4j 目前依托于开源项目协作平台 Codehaus 进行文档及代码管理，下一步该项目计划迁移到 Github 平台，以便更多的社区及开发人员可以参与到开发及维护中来。Perf4j 欢迎使用者提出新的功能需求并且鼓励将定制或扩展的代码贡献到 Perf4j 源码中。本文中示例代码使用的 Perf4j 版本是 0.9.16，读者需在下载类包或配置 Maven 时留意。

阅读文章之前，您要对 Java 注解、JMX、面向方面编程有一些了解。特别是 JConsole 的使用及 Spring AOP 的配置方式要较为熟悉。

文章首先阐明在何种应用场景下应优先考虑使用 Perf4j。然后是具体讲解 Pef4j 与应用程序的集成方式。最后会介绍如何将收集的数据生成便于分析的可视化图表。

应用场景

在 Java 平台上遇到性能问题时，如 CPU 占用过高、系统响应缓慢，通常的分析方法是使用 JVM 剖析工具在系统瓶颈临界点前一段时间抓取 CPU 占用分布，再对 CPU 占用率最高的几个方法排查。Perf4j 的优势在于能够持续跟踪统计所关注功能代码的执行效率，对于前后两个版本出现较大差异的方法进行深入分析，可以在开发周期中尽早发现问题。Perf4j 还可以用在产品环境中，从运营的早期开始，将其统计的数据做为系统的性能和健康指标长期监测。

首选 Perf4j 的应用场景：

Java 本地代码调用（JNI）

分布式系统、集群部署

面向服务体系结构（SOA）

远程方法调用（RMI）

开发人员必须将本地方法、远程方法及 Web services 的性能问题隔离出来，以防干扰对 Java 应用程序本身的分析。通过日志记录则是最简单的方式；采用分布式架构或集群部署的系统相对复杂，不同的网络环境、基础硬件和操作系统的差异、虚拟主机中资源与配置的差异等造成很难采用统一的工具来监测代码级别的性能指标。而日志记录则可以轻松加入到各种程序中，且是资源与时间成本最低的方式。Perf4j 提供了 CSV 格式的转换工具，开发人员可以借助第三方工具方便地将统计结果汇总分析。

集成到应用程序

下面将分两种方式具体讲述如何利用 Per4j 提供的 API。在实际的项目中，应根据现有的程序框架及监测目的灵活选择。另外，针对 WebSphere 应用服务器的自有日志系统，还必须采取额外的措施来确保 Perf4j 的正常工作。

对代码段计时

Perf4j 中 org.perf4j.StopWatch 是整个 API 中的基础工具。这是一个封装良好的计时器。可以把 StopWatch 嵌入到代码中任何地方。这种方式往往使得复杂的方法得到分解，从而有利于精确定位问题的根源。以下通过清单 1 和清单 2 来介绍其具体用法。

清单 1.StopWacth 基本用法

public static void basicStopWatch（） throws InterruptedException{// 创建 StopWacth 时开始计时，之后也可以用 stopWatch.start（） 重新设定计时开始时间点 StopWatch stopWatch = new StopWatch（"TransactionA"）;// 执行需要计时的代码 Thread.sleep（2 * 1000L）; String result = stopWatch.stop（）;System.out.print（result）; }

清单 1 中最后输出的结果示例：start[1340442785756] time[1995] tag[TransactionA]。在构造函数中设定 tag[TransactionA] 用来区分不同的业务逻辑，可以把它看成是性能分析中的事务（Transaction）。

如果需要将多段代码分开统计，可采用 LoggingStopWatch 类的 lap（）方法定义多个事务。

清单 2.LoggingStopWatch 用法

public static void loggingStopWacth（） throws InterruptedException{LoggingStopWatch stopWatch = new LoggingStopWatch（）;// 设定阈值，小于此阈值的结果将不会被记录下来 stopWatch.setTimeThreshold（1*1000L）;Thread.sleep（2 * 1000L）;// 停止当前计时，开始新的起始时间点 stopWatch.lap（"TransactionB"）;Thread.sleep（500L）;stopWatch.stop（"TransactionC"）; }