性能测试工具二（数据库性能分析与诊断工具 tell the bees）

对熟悉数据库的朋友来说，当我们出现了跟数据库相关问题的情况下，比如我们出现了性能问题或者错误，我们可以直接查找数据库的Trace文件来分析，因为这个文件会非常详细的把用户的GUI操作转换为直接SQL语句和后台SQL语句，是否走相关索引，运行涉及了那些表，出现什么问题等都会有很详细的说明。

那么这个文件的获取如果没有数据库经验的用户还是挺困难的，以Oracle数据库为例，它需要写入很长的SQL语句，那么Esri提供了一个Tell The Bees的工具来很方面的解决这个问题。

以Oracle为例，使用SQL语句获得Trace文件请参考：

在Oracle中跟踪后台所执行的SQL语句：

系统需求：

ArcGIS Desktop 10.0 or better.

.Net Runtime 3.5 or better.

 

下载完该软件，安装即可，然后在ArcMap的Arctoolbox添加该工具

从截图中我们可以看到有Start和Stop，而且支持Oracle、SQL Server、PostgreSQL三种数据库

以Oracle为例，在执行该工具之前，需要说明一下的，该工具是针对Session级别的，如果需要改动，请重新连接数据库加载数据。

而且对连接用户的权限需求为：“Alter session”,“Create Table”,“Select any dictionary”.

 

执行过程一般为首先Start Oracle Trace，然后在ArcMap做相关操作，最后Stop Oracle Trace。

 

执行完Stop Oracle Trace之后我们可以看到相关的信息

[sql] view plaincopyprint?

  <span style="font-family:'Microsoft YaHei';font-size:16px;">Executing: stop_oratrace TEST.DLTB  

  Start Time: Tue Nov 08 09:19:08 2011  

Trace file location is recorded in a table called 'draw_tyme_trace_file_name' in this users schema  

  Succeeded at Tue Nov 08 09:19:11 2011 (Elapsed Time: 3.00 seconds)</span>  

<span style="font-family:'Microsoft YaHei';font-size:16px;">Executing: stop_oratrace TEST.DLTBStart Time: Tue Nov 08 09:19:08 2011Trace file location is recorded in a table called 'draw_tyme_trace_file_name' in this users schemaSucceeded at Tue Nov 08 09:19:11 2011 (Elapsed Time: 3.00 seconds)</span>我们可以当前连接用户查看draw_tyme_trace_file_name的表，相关的Trace文件路径就存储在那里。

----------------------------------------------

获得完trace文件，大家应该对这些密密麻麻的信息看的一头雾水，也可以使用TKPROF来解释

[sql] view plaincopyprint?

  C:\Users\gis>tkprof  

  Usage: tkprof tracefile outputfile [explain= ] [table= ]  

                [print= ] [insert= ] [sys= ] [sort= ]  

    table=schema.tablename   Use 'schema.tablename' with 'explain=' option.  

    explain=user/password    Connect to ORACLE and issue EXPLAIN PLAN.  

    print=integer    List only the first 'integer' SQL statements.  

    aggregate=yes|no  

    insert=filename  List SQL statements and data inside INSERT statements.  

    sys=no           TKPROF does not list SQL statements run as user SYS.  

  record=filename  Record non-recursive statements found in the trace file.  

  waits=yes|no     Record summary for any wait events found in the trace file.  

  sort=option      Set of zero or more of the following sort options:  

    prscnt  number of times parse was called  

    prscpu  cpu time parsing  

    prsela  elapsed time parsing  

prsdsk  number of disk reads during parse  

    prsqry  number of buffers for consistent read during parse  

    prscu   number of buffers for current read during parse  

    prsmis  number of misses in library cache during parse  

    execnt  number of execute was called  

    execpu  cpu time spent executing  

    exeela  elapsed time executing  

    exedsk  number of disk reads during execute  

    exeqry  number of buffers for consistent read during execute  

    execu   number of buffers for current read during execute  

    exerow  number of rows processed during execute  

    exemis  number of library cache misses during execute  

    fchcnt  number of times fetch was called  

    fchcpu  cpu time spent fetching  

    fchela  elapsed time fetching  

    fchdsk  number of disk reads during fetch  

    fchqry  number of buffers for consistent read during fetch  

    fchcu   number of buffers for current read during fetch  

    fchrow  number of rows fetched  

    userid  userid of user that parsed the cursor  

  

  

C:\Users\gis>tkprof c:\1.trc  

output = c:\222.trc  

TKPROF: Release 11.2.0.1.0 - Development on 星期二 11月 8 09:26:33 2011  

  

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.  

C:\Users\gis>tkprofUsage: tkprof tracefile outputfile [explain= ] [table= ] [print= ] [insert= ] [sys= ] [sort= ] table=schema.tablename Use 'schema.tablename' with 'explain=' option. explain=user/password Connect to ORACLE and issue EXPLAIN PLAN. print=integer List only the first 'integer' SQL statements. aggregate=yes|no insert=filename List SQL statements and data inside INSERT statements. sys=no TKPROF does not list SQL statements run as user SYS. record=filename Record non-recursive statements found in the trace file. waits=yes|no Record summary for any wait events found in the trace file. sort=option Set of zero or more of the following sort options: prscnt number of times parse was called prscpu cpu time parsing prsela elapsed time parsing prsdsk number of disk reads during parse prsqry number of buffers for consistent read during parse prscu number of buffers for current read during parse prsmis number of misses in library cache during parse execnt number of execute was called execpu cpu time spent executing exeela elapsed time executing exedsk number of disk reads during execute exeqry number of buffers for consistent read during execute execu number of buffers for current read during execute exerow number of rows processed during execute exemis number of library cache misses during execute fchcnt number of times fetch was called fchcpu cpu time spent fetching fchela elapsed time fetching fchdsk number of disk reads during fetch fchqry number of buffers for consistent read during fetch fchcu number of buffers for current read during fetch fchrow number of rows fetched userid userid of user that parsed the cursorC:\Users\gis>tkprof c:\1.trcoutput = c:\222.trcTKPROF: Release 11.2.0.1.0 - Development on 星期二 11月 8 09:26:33 2011Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.我没有添加其他Option选项，大家可以自己测试，我们打开解析转换好的新文件

[sql] view plaincopyprint?

  TKPROF: Release 11.2.0.1.0 - Development on 星期一 11月 7 11:37:34 2011  

    

  Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.  

    

  Trace file: c:\1.trc  

Sort options: default  

    

  ********************************************************************************  

  count    = number of times OCI procedure was executed  

cpu      = cpu time in seconds executing   

elapsed  = elapsed time in seconds executing  

disk     = number of physical reads of buffers from disk  

query    = number of buffers gotten for consistent read  

current  = number of buffers gotten in current mode (usually for update)  

rows     = number of rows processed by the fetch or execute call  

********************************************************************************  

  

SQL ID: 3nkd3g3ju5ph1  

Plan Hash: 2853959010  

select obj#,type#,ctime,mtime,stime, status, dataobj#, flags, oid$, spare1,   

  spare2   

from  

 obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null   

  and linkname is null and subname is null  

  

  

call     count       cpu    elapsed       disk      query    current        rows  

------- ------  -------- ---------- ---------- ---------- ----------  ----------   

Parse        7      0.00       0.00          0          0          0           0  

Execute    129      0.03       0.04          0          0          0           0  

Fetch      129      0.00       0.17         37        510          0         123  

------- ------  -------- ---------- ---------- ---------- ----------  ----------   

total      265      0.03       0.22         37        510          0         123  

  

Misses in library cache during parse: 1  

Misses in library cache during execute: 1  

Optimizer mode: CHOOSE  

Parsing user id: SYS   (recursive depth: 1)  

  

Rows     Row Source Operation  

-------  ---------------------------------------------------   

      0  TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=1 pw=0 time=0 us cost=4 size=83 card=1)  

      0   INDEX RANGE SCAN I_OBJ2 (cr=3 pr=1 pw=0 time=0 us cost=3 size=0 card=1)(object id 37)  

  

  

Elapsed times include waiting on following events:  

  Event waited on                             Times   Max. Wait  Total Waited  

  ----------------------------------------   Waited  ----------  ------------   

  db file sequential read                        37        0.05          0.15  

********************************************************************************  

SQL ID: 82b9x84vs49nr  

Plan Hash: 1388734953  

Select 'SQL TRACE STARTED   

FROM  

 GEOPROCESSING' as NOTE from DUAL  

  

  

call     count       cpu    elapsed       disk      query    current        rows  

------- ------  -------- ---------- ---------- ---------- ----------  ----------   

Parse        3      0.00       0.07          1          3          0           0  

Execute      3      0.00       0.00          0          0          0           0  

Fetch        3      0.00       0.00          0          0          0           3  

------- ------  -------- ---------- ---------- ---------- ----------  ----------   

total        9      0.00       0.07          1          3          0           3  

  

Misses in library cache during parse: 3  

Optimizer mode: ALL_ROWS  

Parsing user id: 93    

  

Rows     Row Source Operation  

-------  ---------------------------------------------------   

      1  FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)  

Elapsed times include waiting on following events:  

  Event waited on                             Times   Max. Wait  Total Waited  

  ----------------------------------------   Waited  ----------  ------------   

  SQL*Net message to client                       6        0.00          0.00  

  SQL*Net message from client                     6        8.69         14.20  

********************************************************************************  

TKPROF: Release 11.2.0.1.0 - Development on 星期一 11月 7 11:37:34 2011Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.Trace file: c:\1.trcSort options: default********************************************************************************count = number of times OCI procedure was executedcpu = cpu time in seconds executing elapsed = elapsed time in seconds executingdisk = number of physical reads of buffers from diskquery = number of buffers gotten for consistent readcurrent = number of buffers gotten in current mode (usually for update)rows = number of rows processed by the fetch or execute call********************************************************************************SQL ID: 3nkd3g3ju5ph1Plan Hash: 2853959010select obj#,type#,ctime,mtime,stime, status, dataobj#, flags, oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname is null and subname is nullcall count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse 7 0.00 0.00 0 0 0 0Execute 129 0.03 0.04 0 0 0 0Fetch 129 0.00 0.17 37 510 0 123------- ------ -------- ---------- ---------- ---------- ---------- ----------total 265 0.03 0.22 37 510 0 123Misses in library cache during parse: 1Misses in library cache during execute: 1Optimizer mode: CHOOSEParsing user id: SYS (recursive depth: 1)Rows Row Source Operation------- --------------------------------------------------- 0 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=1 pw=0 time=0 us cost=4 size=83 card=1) 0 INDEX RANGE SCAN I_OBJ2 (cr=3 pr=1 pw=0 time=0 us cost=3 size=0 card=1)(object id 37)Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ db file sequential read 37 0.05 0.15********************************************************************************SQL ID: 82b9x84vs49nrPlan Hash: 1388734953Select 'SQL TRACE STARTED FROM GEOPROCESSING' as NOTE from DUALcall count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse 3 0.00 0.07 1 3 0 0Execute 3 0.00 0.00 0 0 0 0Fetch 3 0.00 0.00 0 0 0 3------- ------ -------- ---------- ---------- ---------- ---------- ----------total 9 0.00 0.07 1 3 0 3Misses in library cache during parse: 3Optimizer mode: ALL_ROWSParsing user id: 93 Rows Row Source Operation------- --------------------------------------------------- 1

FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 6 0.00 0.00 SQL*Net message from client 6 8.69 14.20********************************************************************************
我只是截取了部分信息，我们可以看到，我们在执行每一步SQL的效率相应都可以看到，那么我们就根据这些信息进行相关的优化和管理。

****************************************************************************************************

那么对SQL Server其实也是一样的，不过SQL Server在获得Trace信息比较简单，用户也可以利用SQL Server Profiler来监听信息  参考：http://blog.csdn.net/linghe301/article/details/6669138

使用SQL Server时注意：

[sql] view plaincopyprint?

  <span style="font-family:'Microsoft YaHei';font-size:16px;">Executing: start_sqltrace sde.SDE.dltb c:\11.trc  

  Start Time: Mon Nov 07 11:56:45 2011  

  Underlying DBMS error [Microsoft SQL Server Native Client 10.0: 您没有运行   

    

  'SP_TRACE_CREATE' 的权限。]  

  Failed to execute (start_sqltrace).  

  Failed at Mon Nov 07 11:56:45 2011 (Elapsed Time: 0.00 seconds)</span>  

<span style="font-family:'Microsoft YaHei';font-size:16px;">Executing: start_sqltrace sde.SDE.dltb c:\11.trcStart Time: Mon Nov 07 11:56:45 2011Underlying DBMS error [Microsoft SQL Server Native Client 10.0: 您没有运行 'SP_TRACE_CREATE' 的权限。]Failed to execute (start_sqltrace).Failed at Mon Nov 07 11:56:45 2011 (Elapsed Time: 0.00 seconds)</span>

其他工具说明

[sql] view plaincopyprint?

  Draw Tyme  

  This tool generates a .csv file that contains layer draw time information.  It draws extents that are determined by the features of a “driving” featureclass.  This tool can be useful for finding layers that contribute to slow drawing at different scales.  The .csv  can be conveniently analyzed in Excel or similar spreadsheet programs.  

Draw TymeThis tool generates a .csv file that contains layer draw time information. It draws extents that are determined by the features of a “driving” featureclass. This tool can be useful for finding layers that contribute to slow drawing at different scales. The .csv can be conveniently analyzed in Excel or similar spreadsheet programs.

[sql] view plaincopyprint?

  B-boxer  

  B-boxer can be used to generate a “driving” featureclass for “Draw Tyme”.  It requires an input point featureclass.  That featureclass can be created with the “Create Random Points” tool.  Together these tools allow you to generate random extents within an area of interest at scales of interest.  B-boxer also outputs the extent information to a .csv file.  The .csv file can be adapted for use in tools like Jmeter and StresStimulus (Internet application load testing tools).  

B-boxerB-boxer can be used to generate a “driving” featureclass for “Draw Tyme”. It requires an input point featureclass. That featureclass can be created with the “Create Random Points” tool. Together these tools allow you to generate random extents within an area of interest at scales of interest. B-boxer also outputs the extent information to a .csv file. The .csv file can be adapted for use in tools like Jmeter and StresStimulus (Internet application load testing tools).

[sql] view plaincopyprint?

  Export Group Layers  

  “Draw Tyme” will only generate layer draw time information for layers at the root level of the table of contents.  Therefore, group layers are not very compatible with “Draw Tyme”.  You can “flatten-out” the group layers from a given document to a directory of .lyr files with this tool.  Essentially, it takes the visibility and scale dependency from the top-most (root) containing group layers and applies them to the bottom-most (leaf) layers, exporting them to .lyr files.  You can then make a new mxd from these .lyrs.  This mxd will have the same drawing behaviors as the