BTrace
想象一下,如果能收集JVM当前的任何信息,那么你感兴趣的信息有哪些?我猜想问题列表会将因人而异,因情形而异。就个人来说,我通常感兴趣的是以下的问题:
①程序对堆、非堆、永久保存区(Permanent Generation),以及JVM包含的不同内存池(新生对象区、长期对象区、存活空间等)的内存使用情况
②当前程序的线程数量,以及哪种类型线程正在被使用(单独计数)
③JVM的CUP负载
④系统平均负载/系统CPU使用总和
⑤对程序中的某些类和方法,我需要了解它们被调用次数,各自平均执行时间和整体平均时间
⑥对SQL调用的调用计数及执行次数
⑦对硬盘和网络操作的调用计数及执行次数
利用BTrace可以采集到所有以上信息,你可以使用BTrace脚本定义需要采集的数据。方便的是,BTrace脚本就是普通Java类,包含一些特殊注解来定义BTrace在什么地方及如何跟踪你的程序。BTrace脚本会被BTrace编译器-btracec编译成标准的.class文件。
BTrace脚本包含许多部分,正如下图所示。如果需要了解下图脚本的详细内容,请点击该链接或访问BTrace项目网站。
由于BTrace仅仅是一个代理,记录结果后,它的任务就算完成了。除了文本输出,BTrace并不具备动态展现被收集信息的功能。缺省情况下,BTrace脚本输出结果将在btrace.class文件所在位置生成一个名为BTrace脚本名.class.btrace的text文件。
我们可以通过给BTrace设置一个额外参数,让它按某时间间隔循环记录日志。切记,它最多能在100个日志文件间循环,当达到*.class.btrace.99,它将覆盖*.class.btrace.00文件。若让循环间隔在一个合理数字(如,每7.5秒)内,你就有充足时间来处理这些输出。只要在java代理的输入参数中加上fileRollMilliseconds=7500,就可以实现日志循环。
BTrace一大缺点是它比较原始,难以定义它的输出格式。你也许非常希望有一种更好的方式来处理BTrace的输出和数据,比如可以用一种一致的图形用户界面来展示。你可能还需要比较不同时间点的数据和超出阈值能发送警告。一个新的开源工具EurekaJ,就此应运而生。
▲图9:激活方法分析时必需的BTrace脚本
EurekaJ
我最初开发EurekaJ是在2008年。那时,我正在寻找一种具有我需要功能的开源剖析器,但没有找到。于是,我开始开发自己的工具。开发过程中,我涉猎了大量不同的技术并参考了许多架构模型,直到EurekaJ第一个版本发布。你可以从项目网站上了解更多的EurekaJ历史,查看源代码或下载并试着安装自己的版本。
EurekaJ提供了两个主要应用:
一个基于java的管理器程序,可以接收传入的统计数据并一致地以可视化视图展现出来
一个解析BTrace输出的代理程序,将其转化为JSON格式并输入到EurekaJ管理程序的REST接口
EurekaJ接受两种类型的输入数据格式。EurekaJ代理期望BTrace脚本的输出被格式化为逗号分隔的文件(这点在BTrace中可很容易做到),而EurekaJ管理程序期望它的输入符合它的JSON REST接口格式。这意味着你能通过代理程序或直接经由REST接口来传递度量数据。
借助EurekaJ管理程序,我们可以在一张图上分组显示多个统计数据、可以定义阈值和给接收者发出警报。我们还可以方便的查看收集到的实时数据或历史数据。
所有收集到的数据排序成一种逻辑树结构,其结构由BTrace脚本作者指定。我建议BTrace脚本的作者对相关统计数据分组,这样,当它们显示在EurekaJ中时会更容易理解和观察。例如,我个人喜欢对统计数据进行如下的逻辑分组:
▲图10:EurekaJ演示程序的统计分组示例
图例
一种需要采集的重要信息是程序运行时的平均系统负载。要是你正面对一个运行缓慢的程序,那么缺陷可能并不在程序自身,而是隐藏到应用驻留的主机某处。我曾经在调试运行缓慢的应用时偶尔发现,真正的根源是病毒扫描程序。如果不进行测量分析,这种事情会很难被发现。考虑到这一点,我们需要能够在一张图中显示系统平均负载和进程加载后产生的负载。下图显示了一个运行EurekaJ 演示程序的Amazon EC2虚拟服务器的2小时平均负载(该应用登录的用户名和密码都是‘user’)。
▲图11:显示平均系统负载的EurekaJ图表
图中,黄色和红色的线条表示警戒阈值。一旦图形超过黄线的次数超过预设的最小警戒次数时,则测量结果到达“警告”状态。类似,若突破红线,测量结果就到达“危险”或“错误”状态。每当发生状态转换,EurekaJ都会发送一封邮件给之前注册的收件人。
在上面的情形中,好像有周期性的事件每20分钟发生一次,从平均负载图上显示的波峰可以看到这一点。首先你要确定的是这个波峰确实由你的程序产生,而非其他原因。我们也可以通过测量进程的CPU负载来确认这点。在EurekaJ树菜单中,选择两个测量点后,两个图表结果会一起快速成像显示出来,其中一个位于另一个下面。
▲图12:同时显示多个图表
在上面的例子中,我们清楚地看到进程CUP占用和系统负载存在必然的联系。
许多应用需要在程序无响应或不可用时及时发出警告。下图是一个Confluence(Atlassian的企业级Wiki软件)的例子。这个例子中,程序内存占用快速上升,直到产生程序内存溢出。这时,Confluence无法处理接收到的请求,同时日志文件记录了各种奇怪的错误。
你可能希望当程序运行导致内存溢出时,程序能立刻抛出一个OOME(内存溢出错误),然而,事实上JVM不会抛出OOME直到它发觉垃圾回收过于缓慢。结果,程序没有完全崩溃,又过了2小时,Java仍然没有抛出OutOfMemoryError,甚至两小时后程序依然在“运行”(意味着JVM进程仍然在运行)。显然,这时任何进程监测工具都不能发现程序已经“停止”。
▲图13:EurekaJ堆图显示内存溢出错误的一种可能情形
注意最后几个小时的执行情况,图表揭示了下面的度量指标。
▲图14:前面图表放大后的效果
EurekaJ使我们可以设置程序的堆内存警告,个人建议最好如此。若程序持续占用堆内存超过95%-98%(取决于堆的大小),几乎可以肯定,程序存在内存问题,要么用–Xmx参数为程序分配更多的堆,要么优化程序使其使用更少内存。同时,EurekaJ未来版本计划增加统计数据不足的警报。
最后的图表示例展示了一个包含4个不同程序内存使用的图表组。这种类型的图表组可方便用来比较一个程序不同部分的、或甚至不同程序之间、服务器之间的数据。下图的这4个程序有不同的内存需求和内存占用模式。
如下图示,不同程序有不同的内存曲线。这些曲线非常依赖一些实际情况,比如使用的架构、缓存数量、用户数、程序负载等。我希望通过下图说明你需要掌握程序在正常和高负载下执行情况的重要性,因为这将直接关系到如何定义报警阈值。
▲图15:EurekaJ图组会将图像彼此叠加在一起