一个插入数据性能低下案例处理
最后更新时间:2021年07月27日 人气:...

一、现象

  因种种问题导致地方法院上传的十几万裁判文积压,wcm无法发布,使用Dataexchange每天导入的数据量由原先的6w下降到2-3w,并且插入一条数据的时间在1-2s之间。


二、问题分析

  根据客户提供的信息,首先想到的问题解决步骤:


1、获取javacore信息

  获取javacore信息可以看到当前wcm线程都在干什么,是不是由于Dataexchange批量推送数据导致wcm所在tomcat线程压力过大。

  获取javacore信息的方法可参考:TRSWCM应用出现问题怎么办之javacore

(注意:在linux下有时候kill -3不一定能够获取得到javacore信息,这时候需要使用jstack pid去获取)

关于javacore的分析:

  一般就是隔一段时间获取一次javacore信息,观察线程状态是否有所改变,是否有一些执行比较慢,阻塞的线程,在结合具体情况分析代码。

  但从获取得到的javacore信息来看,发布线程ThreadPool$Worker$这是发布线程,都是等待状态,没有一个是正在运行的,表明当前的发布速度是没有问题的。

  通过发布监控看了一下他们的发布性能,基本上发布一个细缆页面也都是在0.1s这样。

  再看看tomcat线程数(http-port-Processor)这样的线程,也就在25个这样,那么可以看出DataExchange并没有说并发量很大的给wcm推送文章。

  后来了解到他们的代码是采用单线程推送数据的,因为他们曾经也尝试过直接调用wcm的服务推送数据,但是由于用户上线网站时间比较集中,并发量很大,很容易导致wcm系统缓慢。

  因此用户自己写了一个缓冲池,用于缓存上下线网站的请求,采用单线程24小时调用Dataexchange给wcm推送数据,根据他们打出的调试信息来看每次调用wcm的保存文档接口,都会消耗2s以上


2、生成oracle的awr报告:

  如何生成awr分析报告:http://wiki.trs.org.cn/pages/viewpage.action?pageId=14189637

  可以看到数据库基本上没什么压力,从top sql语句上看也没有看到有执行时间特别长的语句,但是有一条updata语句执行了7s但是是在14小时内才执行了一次而已,所以当时分析的时候就直接把这句语句的影响给忽略掉了,认为系统执行插入操作和这个Updata语句没什么关系,跟何况是14小时内才执行一次而已。(其实这正是问题所在)

  1、2步骤基本上是解决效率问题的一般步骤,服务cpu消耗性能问题,基本上可以从javacore信息看出,数据库压力可以通过awr报告看出。

  但是经过1、2步骤,当时却犯难了,既没有得到一个准确的性能消耗很大的sql语句,也没有得到任何关于wcm消耗很大的线程相关的数据。

三、深入wcm数据库缓冲池

  这个时候我们可以尝试打开一下数据库缓冲池,观察一下wcm每条语句具体的执行效率。

  如何打开数据库连接池执行sql堆栈:参考wiki:http://wiki.trs.org.cn/pages/viewpage.action?pageId=11343533。并且给BaseObj添加了一些调试信息,重新部署到wcm中,并设置其log4j调试状态为debug,再执行导出操作。

从catalina.out和TRSWCMLog.log日志文件中可以看到这样的语句:

UPDATE WCMCHNLDOC SET DocForm=1 WHERE DocId=4770951 use time=1334

  基本上执行这样的语句都是1334ms也就是说基本上这个语句执行的时间都是 1s多以上,性能应该就是消耗在这里了这个update语句是由wcm监听器 执行了updata语句,并且每一条记录都会updata一次,并不是根据是否有图片才更新。

DocForm=1 文字类型

DocForm=2  图片类型 

 if (nDocType == Document.DOC_TYPE_FILE) {
    String sFileName = document.getPropertyAsString("DOCFILENAME");
    nDocForm = analyzeExt(sFileName);
 } else if (nDocType == Document.DOC_TYPE_HTML) {
    // 对html型,解析dochtmlcon判断
    String sHtmlCon = document.getHtmlContent();
    nDocForm = analyzeDocForm(sHtmlCon);
 } else {
    // 对其他类型,默认返回文本型
    nDocForm = Document.DOC_FORM_LITERY;
 }

  而基本上执行的updata语句都是在1.5s以上,所以问题就出现在这里了,每次执行保存操作都触发了DocumentLCListenerForDocForm监听器去执行updata操作而这个updata的操作是耗时的,消耗事件1.5s以上。

再来看一下这个语句:UPDATE WCMCHNLDOC SET DocForm=1 WHERE DocId=4770951 use time=1334

条件 where DocId = 4770951就这样的一个条件。应该是走了全表扫描了。这个时候就要获取一些这个语句的执行计划。发现果然是全表扫描。


热门评论