使用TProfiler分析并调优项目中的Fastjson序列化代码

新项目年后就上线了，如今业务上没什么问题，就用TProfiler作了下性能分析，果真有坑。

##1、TProfiler入门 高手请自觉略过本节。

###1.简介

TProfiler是阿里巴巴开源的一款性能分析工具。号称能够用于生产环境进行长期的性能分析。测试程序部署后，在低峰期对响应时间影响20%，在高峰期对QPS影响30%。详细介绍请见官方WIKI。

###2.简要的实现原理

TProfiler的实现基于JAVA的Instrumentation 和ASM。Instrumentation能够理解为一种虚拟机级别的AOP实现，无需对项目代码和JDK有任何改动就能够实现AOP功能。TProfiler利用Instrumentation提供的入口，调用ASM将待分析的类的字节码进行修改，加入分析记录方法。在Profiler运行时便可抽样收集到相关类方法的调用信息。使用Instrumentation时也能够经过JVMTI提供的接口实现对类的彻底控制。至于为何TProfiler会选择ASM，我想可能有两方面的考虑：

1）性能上更高效。使用JVMTI在每一个类装入时都要执行hook程序，而ASM没有明显的性能代价。

2）使用JVMTI对编程难度要求较高，要求对class文件结构和java字节码有深入了解，而ASM虽然也有一些难度，可是相对来讲仍是小一些。

###3.配置

TProfiler在使用上比较简单，在待分析的程序启动脚本中加入JVM参数

javaagent:/path/to/tprofiler.jar -Dprofile.properties=/path/to/profile.properties

并将jar包和profile.properties配置文件放置到前面指定位置就能够了。

profile.properties能够根据须要进行配置：

startProfTime = 9:00:00 开始profile的时间点
endProfTime = 11:00:00 结束profile的时间点
eachProfUseTime = 5 profile时间长度(单位秒)
eachProfIntervalTime = 50 两次profile的时间间隔(单位秒)
samplerIntervalTime = 20 两次采样的时间间隔(单位秒)
debugMode = false 是否进入调试模式
needNanoTime = false 是否须要用纳秒记录时间
ignoreGetSetMethod = true 是否忽略采集get/set方法
logFilePath = /home/admin/logs/tprofiler.log profile log的存放位置
methodFilePath = /home/admin/logs/tmethod.log method log的存放位置
samplerFilePath = /home/admin/logs/tsampler.log sampler log的存放位置
excludeClassLoader = org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader 不注入的类加载器(分号分割)
includePackageStartsWith = com.taobao 进行profile的类包名(分号分割)
excludePackageStartsWith = com.alibaba;com.taobao.forest.domain.dataobject 不进行profile的类包名(分号分割)

###4.远程操做

TProfiler支持远程操做：

远程查看状态操做:

java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient 10.232.. 端口号 status

远程开始操做:

java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient 10.232.. 端口号 start

远程中止操做:

java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient 10.232.. 端口号 stop

远程刷出方法数据:

java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient 10.232.. 端口号 flushmethod

###5.日志分析

运行采样后会生成三个文件：tsampler.log、tprofiler.log、tmethod.log。endProfTime时间到了后才会输出tmethod.log。

获得以上三个日志文件后就能够进行分析了。

分析sampler log命令: java -cp tprofiler.jar com.taobao.profile.analysis.SamplerLogAnalysis d:/tsampler.log d:/method.log d:/thread.log,会生成method.log和thread.log

分析profiler log命令: java -cp tprofiler.jar com.taobao.profile.analysis.ProfilerLogAnalysis d:/tprofiler.log d:/tmethod.log d:/topmethod.log d:/topobject.log,会生成topmethod.log和topobject.log

仍是那句话，详细介绍请见官方WIKI，:P。

##2、开始性能测试 参照第一节配置好个人jetty启动脚本jetty.sh后，使用ab进行压测

ab -n 100000 -c 500 -p post-file http://urlpath    (post-file是post发送内容)

获得日志后分析耗时最长的方法：

java -cp tprofiler.jar com.taobao.profile.analysis.ProfilerLogAnalysis /var/tprofiler/logs/tprofiler.log /var/tprofiler/logs/tmethod.log /var/tprofiler/logs/topmethod.log /var/tprofiler/logs/topobject.log

能够发现耗时最多的居然是json序列化，抽样分析时共调用52412次，平均每次耗时809毫秒。对于这个结果比较诧异，和TProfiler系出同门的Fastjson的性能一直不错，之前开始用以前也作了很多序列化和反序列化的测试，怎么忽然就这么耗时了呢。转念一想，此次的web项目里因为须要支持客户端自定义属性获取和日期格式化，因此须要Fastjson同时进行属性的过滤（经过SerializeFilter）以及日期的自定义格式化（经过SerializeConfig自定义一个把Integer秒转换成指定格式日期的IntegerCodec）。JSON类里没有原生的同时支持这两种操做的方法，因此就在原生的JSON#toJSONString(Object object, SerializeFilter filter, SerializerFeature... features)方法的基础上加了一个参数获得了JSONUtil#toJSONString(Object object, SerializeConfig config, SerializeFilter filter ,SerializerFeature... features)。难道是这个缘由？话很少说，继续测试。

##3、Fastjson并发测试 因为怀疑新加的方法在并发下可能致使性能问题，因而比较了几种对Fastjson不一样方法的并发调用时间，怎么简单怎么来，就不用什么高大上的报表了，各位看官见笑了哈

第一列是普通的，第二列是带属性过滤的，第三列是自定义的同时支持属性过滤和日期格式化的toJSONString。其中COUNT是每一个线程执行序列化的次数。这个并发的对比测试反应的问题有两点：1）并发状况下，性能确实变差；2）一样参数对比下来耗时相差两个数量级，我修改的方法确实有问题。

##4、问题代码的review和问题解决

因而带着这两个问题，开始扒拉代码：

<!-- lang: java -->
public static String toStringWithFieldFilterAndDateFormat(Object object ,final String[] fields,SerializerFeature... features ){
	SerializeFilter filter = null;
	// 只过滤第一层属性
	if(fields != null ){
		// 得到须要过滤掉的字段
		final Set<String> tobeRemoved = getTobeRemovedFields(object,fields);
		if(toRemove != null && toRemove.size() > 0){
			// 须要过滤字段
			filter = new PropertyFilter() {
				@Override
				public boolean apply(Object object, String name, Object value) {
					// 转换日期格式
					if(toRemove.contains(name)){
						return false ;
					}
					return true;
				}
			};
		}
	}
	SerializeConfig config = new SerializeConfig();
	if(NEED_FORMAT_DATE){
		config.put(Integer.class, CustomIntegerCodec.instance);
	}
	return toJSONString(object, config, filter,features);
}

这里CustomIntegerCodec是基于IntegerCodec的Integer类序列化和反序列化器。而toJSONString(Object object, SerializeConfig config, SerializeFilter filter ,SerializerFeature... features)只是在new JSONSerializer(out)时使用了另外一个构造器new JSONSerializer(out,config)。

又看了一下Fastjson的源码，发如今SerializeConfig中对ObjectSerializer作了缓存，若是每次都传入一个新的SerializeConfig，必然每次都会进行没必要要的解析和初始化操做，占用大量的时间。问题找出来了，解决方法也很简单，只要使用一个单例或静态变量便可 private static final SerializeConfig customGlobalConfig = new SerializeConfig(); static { if(NEED_FORMAT_DATE){ customGlobalConfig .put(Integer.class, CustomIntegerCodec.instance); } } Fastjson默认的序列化方法其实也是使用的默认的静态全局实例SerializeConfig

private final static SerializeConfig globalInstance = new SerializeConfig();

修改以后进行测试

O(∩_∩)O ##5、总结 本文介绍了TProfiler性能分析方面的实际应用，能够看到经过TProfiler的分析结果，很是容易定位一些性能问题。而这些问题每每较为隐蔽，你最熟悉的地方颇有可能早就被你挖了坑。 TProfiler自己也短小精炼，若是对Instrument、ASM感兴趣、性能分析感兴趣，推荐读一读。

再给几个相关的资料，没事翻翻

深刻 Java 调试体系: 第 1 部分，JPDA 体系概览

深刻 Java 调试体系，第 2 部分: JVMTI 和 Agent 实现

Java SE 6 新特性: Instrumentation 新功能

AOP 的利器：ASM 3.0 介绍

新年快乐，羊年吉祥~咩咩