性能测试调优分析转载Word文档下载推荐.docx

1、这里通过XXX框架可以捕获到所有业务操作的sql，以一条sql语句为例：（这里省略了sql语句）说明执行该条sql花费时间113ms。注：如果不是用XXX框架的，我们还可以通过v$sql视图来查询执行sql的时间，我们用管理员用户登录，找到这条执行的sql语句，找到字段ELAPSED_TIME，以及字段CPU_TIME，ELAPSED_TIME/（1000*1000）就是sql执行的时间，CPU_TIME/（1000*1000）就是消耗CPU的时间。需要注意的是，如果执行了多次，需要把最后一次的数值减去前一次的数值才能得到最后一次执行该sql的时间。如果单用户多次交易的时候，某条sql语句的时

2、间比较长，并且被测系统是属于一种OLTP（在线事务处理系统）系统，那么该条sql语句可以初步判断存在性能问题。因为这种系统并发数都比较多，侧重于要求数据库的快速响应，sql执行效率缓慢必然影响响应时间，最终导致用户体验的变化。初步确认了sql以后，我们需要对该条sql语句进行分析。这里主要介绍SQL_TRACE的用法。3. SQL_TRACE每次遇到sql性能非常差的时候，都恨不得进数据库看看究竟是什么原因。好在oracle提供了SQL_TRACE来跟踪sql的执行情况。分析sql的方式比较多，还有根据优化器、sql执行计划来分析。SQL_TRACE能够将sql执行的过程输出到一个trace文

3、件里面。首先设置自己定义的trace文件的标识方便查找。alter session set tracefile_identifier=mytest;然后对当前会话启动SQL_TRACE，最好不要一直打开该开关，代价比较大。alter session set sql_trace=true;然后我们执行一条sql语句。最后关闭该开关的状态。alter session set sql_trace=false;我们可以从目录%ORACLE_BASE%/diag/rdbms/orcl/orcl/trace（11g版本的路径，如果是10g的应该不一样）中找到自己定义的trace文件。原始的trace文件的

4、可读性不高，我们一般使用oracle自带的工具，tkprof来处理这个trace文件。我们可以查看tkprof的帮助。tkprof orcl_ora_3820_mytest.trc out.txt我们来看刚才生成的trace文件，头部信息描述了tkprof 的版本以及报告中一些列的含义，对于任何一条sql语句，都应该包含Parsesql分析阶段，Executesql执行阶段，Fetch数据提取阶段，横向的列如图所示，包含消耗cpu时间0.00秒，操作总耗时0.04秒，物理读取了0个数据块，没有发生current方式的读取（一般在update会发生），一共提取记录1条。Misses in lib

5、rary cache during parse: 0表示这是一次软分析（关于硬分析和软分析下面会接着谈到）Optimizer mode: ALL_ROWS表示oracle的优化器模式为ALL_ROWS。这也就是前面提到的另外的分析方式优化器。下面是sql执行的具体计划，可以看到执行计划选择的是全表扫描。经过处理以后的trace文件的确比较容易看明白，它有助于我们分析sql的性能问题。下面我通过一个trace实例来解释一下，为什么OLTP系统中需要变量绑定机制。当用户和数据库建立连接，并发送一条sql语句以后，oracle会对该sql进行hash函数运算（hash算法提供了一种快速存取数据的方法

6、，它用一种算法建立键值与真实值之间的对应关系,每一个真实值只能有一个键值，但是一个键值可以对应多个真实值，以方便存取），得到一个hash值，然后到共享池中寻找是否有匹配的hash值的sql存在，如果有，就直接使用该sql的执行计划去执行sql。如果没有，oracle就会认为这是一条新的sql语句，然后按照语法分析，语义分析，生成执行计划，执行sql这些步骤来执行最终把结果返回给用户。这些步骤也被成为硬分析，可以想象，如果减少硬分析，能够大大降低数据库花费在sql解析上的资源开销。我们先执行一条sql 1000次，比较绑定变量和不绑定变量的差异。得到结果以后，要计算实际的消耗，我们需要把OVER

7、ALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS以及OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS的时间累计起来，前者表示数据字典表的相关的信息，包含权限控制等，后者表示sql所衍生出的递归sql语句的信息。可以看到绑定变量的，整条语句执行时间为0.22+0.02=0.24秒，CPU时间0.18+0.03=0.21秒，分析次数3次，执行次数1003次。而不绑定变量的时候，整条语句执行时间为0.28+1.29=1.57秒，CPU时间0.31+1.26=1.57秒，分析次数1002次，执行次数1003次。可见绑定变量的确

8、能够带来更低的开销。（如何设计数据库中使用绑定变量也是和系统息息相关的，很多数据库问题都是在设计以后就已经存在的）4. 应用级调优分析就通常所说的三层架构来说，中间件这一层能够起到一个缓冲池的作用，如果并发用户数到3000这个数量级的时候，中间件能够控制不是所有的用户都能直接连接到数据库，当然这里的程序会快速响应用户请求，保证缓冲池的队列等待不会很久。对应用这一级别的调优，主要集中在app程序，中间件的监控，集群配置等方面。如果是发现应用级别的问题，首先要分析是配置问题，还是程序本身的问题。如果并发用户数很大，中间件的线程池最大值配置过小，会导致在请求队列堆积，表现就是线程监控视图中，请求的队

9、列堆积比较多，一般可以调整线程池最大值来解决。我们来看看weblogic的监控视图。考虑到如果为每一个请求都创建一个新线程来处理的话，那么我们难以在系统中实现足够数量的线程。不受限制的创建线程可能耗尽系统资源，因此引入了线程池。线程池的思想是在进程开始时创建一定数量的线程并将它们置入一个池（pool）中，线程在这个池中等待工作。当服务器接收到一个请求时，它就从池中唤醒一个线程（如果有可用的线程），由它来处理请求。一旦线程服务完毕，它就返回线程池等待后面的工作。线程池利用已存在的线程服务请求要比等待创建一个线程要快，并且线程池限制了线程的数量。如果怀疑是程序的问题，我们一般可以通过java自带的

10、工具来帮助分析，工具很多。这里我主要提到一个jdk1.6以后附带的jvisualvm。我们打开jdk1.6，找到并运行jvisualvm.exe。我们发现应用程序分为本地，远程两部分。本地包含本地运行的java进程，远程能够通过配置连接到远程服务器上的java进程。我们先启动一个tomcat。可以看到本地应用程序已经打开了一个带有tomcat以及进程标识id的菜单。双击打开。这里我们一般关心2个视图。监视、线程。其中监视视图比较关心垃圾回收活动（顾名思义，回收那些在程序里面不再使用到的内存空间），堆内存变化。如果在压力测试过程中，堆内存变化是一个逐渐上涨的趋势，并且经过多次手动gc回收，还是保

11、持这个趋势，说明内存泄漏的可能性很大。如果猜测有内存泄漏，可以通过分析java的heap dump。JVM （java虚拟机）记录下问题发生时系统的运行状态并将其存储在转储（dump）文件中。Heap dump就是这样一种文件形式。线程视图比较关心线程的当前执行状态，这里可以生成另一种转储文件 Java dump。Java dump，也叫做 Thread dump，是 JVM 故障诊断中最重要的转储文件之一。JVM 的许多问题都可以使用这个文件进行诊断，其中比较典型的包括线程阻塞，CPU 使用率过高，JVM Crash，堆内存不足，和类装载等问题。其中线程阻塞更加常见。线程阻塞是我们在 jav

12、a 多线程编程中经常遇到的问题。由于对后端有限资源的争用以及过度同步等问题，经常会发现 Java dump 中某个资源（锁对象）下有太多的线程处于等待状态，这时候我们通常需要从以下三个方面去诊断这个问题：这个锁存在的目的是什么？有没有可能去掉这个锁或者缩小这个锁保护的范围，从而减少线程等待问题发生的几率。有哪些线程需要用到这个锁，有没有可能改用其它更好的替代方案。当前哪个线程正在持有这个锁，持有的时间是多长，有没有可能缩短持有的时间。下面通过实际测试中的dump文件来谈谈如何读懂一个dump文件。可以看到一共有4种线程的状态，WAITING，RUNNABLE，TIMED_WAITING （sl

13、eeping），BLOCKED。线程阻塞就是BLOCKED。搜索文件中BLOCKED的部分，我们可以看到其中一个：ACTIVE ExecuteThread: 91 for queue:weblogic.kernel.Default （self-tuning） daemon prio=10 tid=0x00002aaae8181000 nid=0x4849 waiting for monitor entry 0x0000000047d4d000 java.lang.Thread.State: BLOCKED （on object monitor）* 线程名称： * 线程类型：daemon * 优

14、先级：10，默认是5 * jvm线程id：jvm内部线程的唯一标识,0x00002aaae8181000 * 对应系统线程id：和top命令查看的pid对应，不过一个是10进制，一个是16 进制。0x4849 * 线程状态：BLOCKED * 起始栈地址：可以看到很多线程状态都是BLOCKED，表示当前线程A正要进入一个同步块，但是被另外一个线程B持有该锁，于是需要等待B，释放锁才有机会重新获取。用一种轻松的方式来思考锁，其实挺简单的。数据库中也存在这样的锁。为什么会有锁，打个比喻，一个java对象就像一个大房子，大门永远打开。房子里有很多房间（方法）。这些房间有上锁的和不上锁之分。房门口只放

15、着一把钥匙，这把钥匙可以打开所有上锁的房间。把所有想调用该对象方法的线程比喻成想进入这房子某个房间的人。试想如果只有一个人，肯定是不存在等待别人使用完钥匙归还的时候。如果要是很多人，势必会需要等这把钥匙归还，等钥匙还回来以后，就会有一个人优先得到钥匙。由此可以看到，锁是不可避免的，要想正确获取对象的状态，或者修改对象的状态，必须存在这样一种lock。也就意味着，锁的持有时间越久，对性能的影响也就越大，直接结果是大并发情况下，响应时间的延长。回到以前的thread dump，如果通过工具我们发现，线程阻塞比较频繁，并且持续时间很久，不妨多次收集这种转储文件，可以有效的帮助我们分析问题。我们刚才看

16、到的转储文件就是XXX测试中捕获到的，通过这些地方，我们发现了一些性能方面的问题。除了线程阻塞，我们分析dump文件还可以找到消耗CPU最多的地方。如果不是windows操作系统，可以通过top（top H）或者topas命令来查看应用程序的线程信息及占用CPU的情况。找到排序第一位的pid值，按照我们前面解释的，换算成16进制，然后在thread dump日志中搜索该数值nid就能找到耗费CPU的源代码的具体位置，可以精确到行号。另外还可以分析是否有很多thread struck在了I/O，例如：New I/O server worker #1-1 prio=10 tid=0x0000000

17、0423e0800 nid=0x5bfd runnable 0x00007f7d0a2f4000 RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait（Native Method） at sun.nio.ch.EPollArrayWrapper.poll（EPollArrayWrapper.java:215） 或者是thread struck在数据库，例如：99 daemon prio=10 tid=0x00002aaae8190800 nid=0x4857 runnable 0x0000000048554000 RUNNABLE at .Soc

18、ketInputStream.socketRead0（Native Method） at .SocketInputStream.read（SocketInputStream.java:129） at .ns.Packet.receive（Packet.java:293） at .ns.DataPacket.receive（DataPacket.java:92）等地方，便于我们定位瓶颈原因。5. DB调优分析和前面提到的SQL_TRACE不同，当我们遇到了数据库性能整体下降的时候，又没有特定的对象可以分析时，做一个Statspack报告是合适的。通过全面的检查，我们可以分析出系统瓶颈在哪儿，如果

19、瓶颈出在sql上面，我们就能获取相应的sql，通过SQL_TRACE来分析。oracle Statspack从Oracle8.1.6被引入，马上成为DBA和Oracle专家用来诊断数据库性能的强有力工具。通过Statspack我们可以很容易的确定Oracle数据库的瓶颈所在，记录数据库性能状态，也可以使远程技术人员迅速了解的的数据库运行状况。所以，了解和使用Statspack 对于DBA来说至关重要。它的原理是1、运行oracle自带脚本，生成一系列的统计表。2、生成快照，采样（运行statspack.snap可生成快照，一般通过自动任务生成快照）3、根据快照生成报告。除了statspack，

20、oracle10g以后都提供一个AWR报告，它是oracle自动采集的，采集周期为1小时，不需要人工干预，收集的信息和statspack非常像，很多时候选择哪种方式都可以。AWR可以通过10g以后的oracle DBconsole去生成。如何安装statspack，这里简单的介绍一下，有兴趣的同事可以通过查阅资料更深入的了解和实践。首先检查oracle系统参数，job_queue_process：为了能够建立自动任务，执行数据收集，此参数必须大于0；timed_statistics，设置为true，使收集的时间信息存储在V$sessstats和V$sysstats等动态性能视图中。如果是9i以

21、后版本可以以oradba的身份登录。sqlplus / as sysdba。首先创建表空间create tablespace perfstat datafile D:*oradataorclperstat.orasize 100m extent management local;空间视实际情况而定，如果只是学习使用，不需要那么大，实际生产环境下，可以设置大一些。毕竟Statspack的报表数据还是相当占空间的。然后运行脚本%oracle_home%rdbmsadminspcreate.sql，安装statspack，根据提示输入密码，表空间，临时表空间，安装完成，查看lis后缀的日志文件确认是

22、否有错误。select dt.table_name from dba_tables dt where dt.owner=PERFSTAT可以查看采样数据存储的表格。下一步我们测试statspack，刚才如果create的时候，默认修改了当前的连接用户为perfstat，运行statspack.snap可以产生系统快照，运行两次，产生两次快照。execute statspack.snap;然后执行脚本%oracle_home%rdbmsadminspreport.sql就可以生成基于两个时间点的报告。如果一切正常，可以在运行批处理的目录下查看生成的报告文件。生成了statspack报告，我们就可

23、以开始分析了。需要提醒的是，真正看懂这样一份报告，并不需要知道所有指标的含义，最好能够了解oracle内部的运行机制，理解的越深，判断数据库性能也就越准确。这里只能谈谈我的一些理解和思路，供大家思考。我们来看一份报告例子。对于我们现在已有的系统来说，绝大多数都是属于OLTP系统（在线事务处理系统）,sql执行非常密集，我们不妨关注以下2个指标，Library Hit,Buffer Hit,前面一个体现了共享池命中率，如果很多SQL不能重用，需要重复解析的话，会大大降低系统的性能。后面一个体现了sql需要的数据块是否能够保留在内存中，这样执行效率要比从磁盘读取数据要高很多。我们来看报告第一部分，

24、主要是数据库和实例的信息，然后是采集周期里面系统的信息。这里有一个数值，DB time: 表示用户操作花费时间，判断一下，在收集周期里面，用户时间占用的比率，然后结合top5来分析。Load Profile描述了数据库资源负载的明细列表。可以通过字面含义来理解它们。这里我们可以关注下，物理读写，逻辑读写，硬分析次数等指标。Redo size是日志的生成量，分为每秒和每事务所产生的，通常在很繁忙的系统中日志生成量可能达到上百k，甚至几百k.逻辑读一般发生在内存中，和物理读是区别对待的。硬分析次数前面已经提到了。Instance Efficiency Indicators表示内存效率的统计信息，对

25、于OLTP来说，尽可能都接近100%，原因前面已经说过了。如果哪项数值过低，就要做相应的分析研究。Top 5 Timed Events一般是我每次重点关注的地方，也是我认为最主要的地方。如果这一部分显示前五位的等待事件，并没有占用很长时间，说明系统状态看起来很好。那么我们可能需要多采集一些时间段的数据来分析了。那么结合我们的top 5的等待事件，我们可以来衡量不同等级的top sql:1.消耗最多CPU的（逻辑IO比较多的）2.导致过多物理I/O的（物理IO比较多的）3.执行次数较频繁的（Execution次数比较多的）4.执行时间较长的（Elapse time比较长的）先看看我的机器上采集的

26、结果。control file sequential read control file single write ：控制文件连续读/控制文件单个写对单个控制文件I/O 存在问题时，这两个事件会出现。如果等待比较明显，检查单个控制文件，看存放位置是否存在I/O 瓶颈。control file parallel write：当server 进程更新所有控制文件时，这个事件可能出现。如果等待很短，可以不用考虑。如果等待时间较长，检查存放控制文件的物理磁盘I/O 是否存在瓶颈。以XXX测试为例，我当时采集的是AWR报告中的一部分，和statspack基本一致，可以看到排名第一位的是顶级 SQL 语句

27、。不得不说oracle的分析报告非常智能，非常明细，能够帮助我们迅速找到问题，配合DBA来调优。前面这些内容是报告中最重要的部分，虽然不同的系统生成的报告都会不一样，但是解决问题的思路是一样的，根据前面的一手信息，我们能够了解到等待时间很长的事件，再去其他的部分查找原因。下面简单说说后面报告的含义，Statistic表示各种操作占用数据库的时间比例，接下来是等待事件的明细，主要用来配合前面的top5事件来分析。等待事件（Wait Events）是Oracle中比较复杂难懂的概念。Oracle 的等待事件是衡量Oracle 运行状况的重要依据及指标。等待事件很多这里不一一赘述。常见的等待事件，一

28、般都有对应的分析手段，大家可以参考oracle的资料学习。这里我们根据XXX测试中的实例来分析。可以看到排名第二位的事件是等待 日志文件同步 事件消耗了大量数据库时间。英文翻译就是log file sync: 日志文件同步。当一个用户提交或回滚数据 时，LGWR （Log Writer）将session 会话的重做由redo buffer 写入到重做日志中。log file sync 必须等待这一过程成功完成（Oracle 通过写redo log file 保证commit 成功的数据不丢失），这个事件说明提交可能过于频繁。为了减少这种等待事件，可以尝试每次提交更多的记录，将重做日志置于较快的

29、磁盘上。SQL统计信息一共有以下几部分。SQL ordered by Elapsed time按照sql执行时间从长到短的排序，SQL ordered by CPU表示按照消耗CPU排序。SQL ordered by Gets表示sql获取内存块的数量，SQL ordered by Reads表示执行物理读的信息，SQL ordered by Executions表示执行次数，SQL ordered by Parse Calls表示sql被分析的次数。Sql的统计信息不能孤立的来看待，而是要结合top5事件来分析。如果是sql排名第一位，我们就能通过sql统计信息辅助分析了。SQL统计信息是一个很好的补充。对于OLTP系统来说，即使是软分析，也不能过多，依旧会消耗很多内存资源。如果top5事件中出现了很频繁的sql分析相关的Latch争用，就可以来这里确认哪些sql分析很频繁。Latch和锁起始还是有区分的，Latch更多的是等待，而锁更多的是阻塞。Latch是oracle为了保护内存结构而发明的。Latch一般出现在这样的情况。一个数据块被一个会话读取到内存中，与此同时另外一个会话也要读取这个数据块，为了保持数据一致性，通过Latch来控制。由Latch引发的问题比较多，除了未绑定变量外，还有一种情况是，重复执行的sql频繁访问一些相同的数据，因此可以将这些