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

新项目年后就上线了，现在业务上没什么问题，就用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@H_502_75@

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

profile.properties可以根据需要进行配置：

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,会@L_313_57@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。

参照第一节配置好我的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)@H_502_75@方法的基础上加了一个参数得到了JSONUtil#toJSONString(Object object,serializeConfig config,serializerFeature... features)@H_502_75@。难道是这个原因？话不多说，继续测试。

@H_618_42@三、Fastjson并发测试

由于怀疑新加的方法在并发下可能导致性能问题，于是比较了几种对Fastjson不同方法的并发调用时间，怎么简单怎么来，就不用什么高大上的报表了，各位看官见笑了哈

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);
}

private static final serializeConfig customGlobalConfig = new serializeConfig();
static {
    if(NEED_FORMAT_DATE){
        customGlobalConfig .put(Integer.class,CustomIntegerCodec.instancE);
    }
}