excel导出使用arthas动态追踪方法调用耗时后性能优化的过程
目录一、背景二、发现问题1、本地调试1.1安装启动arthas1.2代码逻辑分析及初步优化1.3使用arthas追踪耗时情况并进一步优化2、服务器调试2.1、测试一使用arthas查看修改后的代码是否生效2.2、测试二使用arthas追踪耗时情况2.3、结论三、解决问题1、原来数据写入excel的方法2、修改成使用fastexcel四、总结一、背景1、用户反应某个报表导出时等待很久也没有导出来我F12查看导出接口在1.5min的时间请求被取消后端服务器的网关如Nginx、Apache或后端应用本身可能设置了90秒的超时用户一直等待也没有导出文件所以需要优化导出逻辑加快导出时间。二、发现问题1、本地调试1.1安装启动arthas1、下载地址https://arthas.aliyun.com/arthas-boot.jarLinux 下载 curl -O https://arthas.aliyun.com/arthas-boot.jar2、启动java -jar arthas-boot.jar3、选择目标应用id回车4、执行tarce命令 -n 5 表示最多捕获5次方法调用使用–skipJDKMethod false包含基础库调用耗时,还可以添加这个参数’#cost500’表示只显示超过500毫秒的。trace 全类名 方法名-n5--skipJDKMethodfalsemybatis sql 打印watchorg.apache.ibatis.executor.SimpleExecutordoQuery {params[0].resource,params[0].id,params[4].sql,params[4].parameterObject,returnObj,throwExp} params[0].id.contains(namespace.id)-x3调用TreadLocal中的remove方法watch 全类名*{params, 全类名方法名()}-s-b关于arthas的命令可以安装idea插件arthas idea选中方法名称鼠标右键Arthas Command中可以选择相应的命令可以复制出来直接使用1.2代码逻辑分析及初步优化从代码看有三个主要逻辑第一个使用远程调用的方式获取数据大概12万条第二个是循环获取数据对某个字段进行国际化如下图第三个是把数据写入excel方法。通过打断点发现在第二个逻辑国际化方法中阻塞时间很久所以决定先优化国际化的逻辑放弃循环结果集改为改成了sql关联国际化表的形式。1.3使用arthas追踪耗时情况并进一步优化解决完字段国际化后重新看一下耗时情况。从耗时情况分析远程获取数据方法占用主要时间所以需要优化查询逻辑经过查看sql执行计划extra 中useing filesort没有在排序字段上创建索引导致创建索引后重新看耗时时间获取数据缩短到50s。数据写入到excel耗时13s左右。总耗时63s左右小于90s本地可以正常导出。2、服务器调试本地调试好以后本以为问题就解决了但是发布到生产服务器后导出还是1.5min后取消了没有什么效果所以在生产服务器上进行了两个测试。arthas下载命令curl -O https://arthas.aliyun.com/arthas-boot.jar然后启动和选择目标服务进入arthas终端2.1、测试一使用arthas查看修改后的代码是否生效在arthas终端中执行jad 全类名反编码查看代码是否修改后的逻辑,我发现代码已经是修改后的。2.2、测试二使用arthas追踪耗时情况执行trace 全类名 方法名 -n 5 --skipJDKMethod false后在生产上执行导出2.3、结论通过上面结果可以发现73.86%耗时的是把数据写入excel的方法。所以优化重点是数据写入excel。三、解决问题1、原来数据写入excel的方法循环遍历所有的数据如果数据是实体类对象则使用反射的方式获取对象中的属性值这里有多少数据量就会使用几次反射反射开销很大。2、修改成使用fastexcelFastExcel 使用了缓存避免重复使用反射方法获取属性值提高了性能。还有就是字段国际化可以使用处理器进行处理自定义了I18nCellWriteHandler处理器所以sql中关联表国际化的逻辑去掉了。这个是优化后的追踪方法调用耗时情况数据写入excel速度显著提高耗时32秒左右总耗时54秒左右。ReflectionBeanMap 核心实现如下initPropertyDescriptors 初始化属性描述符缓存getValue时从缓存中获取PropertyDescriptor反射调用 getter 方法。publicclassReflectionBeanMapTimplementsBeanMapT{privatefinalClassTbeanClass;privatefinalMapString,PropertyDescriptorpropertyDescriptors;privatefinalBeanMapConfigconfig;publicReflectionBeanMap(ClassTbeanClass){this(beanClass,BeanMapConfig.defaultConfig());}publicReflectionBeanMap(ClassTbeanClass,BeanMapConfigconfig){this.beanClassbeanClass;this.configconfig;this.propertyDescriptorsinitPropertyDescriptors(beanClass);}/** * 初始化属性描述符缓存 */privateMapString,PropertyDescriptorinitPropertyDescriptors(ClassTbeanClass){try{BeanInfobeanInfoIntrospector.getBeanInfo(beanClass,Object.class);PropertyDescriptor[]descriptorsbeanInfo.getPropertyDescriptors();MapString,PropertyDescriptorresultnewLinkedHashMap();for(PropertyDescriptordescriptor:descriptors){// 过滤掉没有 getter 方法的属性if(descriptor.getReadMethod()!null){result.put(descriptor.getName(),descriptor);}}returnCollections.unmodifiableMap(result);}catch(IntrospectionExceptione){thrownewRuntimeException(Failed to introspect bean: beanClass.getName(),e);}}/** * 获取属性值 - 核心反射调用 */OverridepublicObjectgetValue(Tbean,StringpropertyName){if(beannull){returnnull;}PropertyDescriptordescriptorpropertyDescriptors.get(propertyName);if(descriptornull){if(config.isIgnoreMissingProperties()){returnnull;}thrownewIllegalArgumentException(Property propertyName not found in beanClass.getName());}MethodreadMethoddescriptor.getReadMethod();if(readMethodnull){if(config.isIgnoreMissingGetters()){returnnull;}thrownewIllegalArgumentException(No getter method for property propertyName in beanClass.getName());}try{// 反射调用 getter 方法returnreadMethod.invoke(bean);}catch(IllegalAccessException|InvocationTargetExceptione){thrownewRuntimeException(Failed to get value for property propertyName from beanClass.getName(),e);}}/** * 设置属性值 */OverridepublicvoidsetValue(Tbean,StringpropertyName,Objectvalue){if(beannull){return;}PropertyDescriptordescriptorpropertyDescriptors.get(propertyName);if(descriptornull){if(config.isIgnoreMissingProperties()){return;}thrownewIllegalArgumentException(Property propertyName not found in beanClass.getName());}MethodwriteMethoddescriptor.getWriteMethod();if(writeMethodnull){if(config.isIgnoreMissingSetters()){return;}thrownewIllegalArgumentException(No setter method for property propertyName in beanClass.getName());}try{// 类型转换和反射调用 setter 方法ObjectconvertedValueconvertValue(value,descriptor.getPropertyType());writeMethod.invoke(bean,convertedValue);}catch(IllegalAccessException|InvocationTargetExceptione){thrownewRuntimeException(Failed to set value for property propertyName in beanClass.getName(),e);}}/** * 获取所有属性名 */OverridepublicSetStringgetPropertyNames(){returnpropertyDescriptors.keySet();}/** * 获取属性类型 */OverridepublicClass?getPropertyType(StringpropertyName){PropertyDescriptordescriptorpropertyDescriptors.get(propertyName);returndescriptor!null?descriptor.getPropertyType():null;}/** * 值类型转换 */privateObjectconvertValue(Objectvalue,Class?targetType){if(valuenull){returnnull;}// 如果类型匹配直接返回if(targetType.isInstance(value)){returnvalue;}// 使用配置的转换器进行类型转换returnconfig.getTypeConverter().convert(value,targetType);}}我写了一个便于理解的例子publicclassTest{publicstaticvoidmain(String[]args)throwsException{ListBaseUserlistnewArrayList();//添加模拟数据for(inti0;i10000000;i){BaseUserbaseUser1newBaseUser();baseUser1.setActiveFlag(i);list.add(baseUser1);}longstartTimeSystem.currentTimeMillis();/** * description 原来的反射方式 */for(BaseUseritem:list){Classclitem.getClass();FieldnameFieldcl.getDeclaredField(activeFlag);nameField.setAccessible(true);nameField.get(item);}//打印耗时时间longendTimeSystem.currentTimeMillis();longexecutionTimeendTime-startTime;System.out.println(原来的反射方法执行时间(executionTime)毫秒);longstartTime1System.currentTimeMillis();/** * description 优化后的反射方式 */ClassclBaseUser.class;Methodmethodcl.getMethod(getActiveFlag);for(BaseUseritem:list){method.invoke(item);}//打印耗时时间longendTime1System.currentTimeMillis();longexecutionTime1endTime1-startTime1;System.out.println(修改后的反射方法执行时间(executionTime1)毫秒);}}执行结果原来的反射方法执行时间1041毫秒 修改后的反射方法执行时间170毫秒四、总结1、本地优化了sql和结果集中字段国际化逻辑在本地导出速度得到很大的提高但是发版到生产环境后数据写入excel逻辑是耗时的主要原因通过arthas实际的监控了每个方法的耗时情况方便线上问题解决。2、对于本地和线上的差异我猜测是线上和本地jvm版本与启动参数不一样导致差异。