ASH报告实验
ASH 报告的作用：
利用 ASH 报告可以分析持续时间通常只有几分钟的瞬间性能问题, 根据各种维度（如 time、session、module、action 或 sql_id )或这些维度的组合进行确定范围或目标的性能分析.
瞬间性能问题持续的时间非常短，不会出现在Automatic Database Diagnostics Monitor (ADDM) 分析中。ADDM 尝 试在分析期间根据问题读 DB time 的影响报告重大的性能问题。如果某个特定的问题持续的时间非常短暂，则该问题 的严重性可能就被均匀化，或因分析期间产生的其他性能问题而减小。因此，在 ADDM 中可能找不到该问题的记录。
ADDM 是否捕获某个性能问题，取决于该问题的持续时间与 AWR 快照之间的间隔的时间比。 如果性能问题持续的时间与快照间隔比非常大，则 ADDM 将捕获该问题。例如，如果快照间隔设为 1 小时，而性能问
题持续了 30 分钟，则该问题就不会被视为瞬间性能问题，因为其持续时间与快照间隔比较大，很可能被 ADDM 捕获 到。
如果某个性能问题只持续 2 分钟，该问题可能就是一个短暂的性能问题，因为其持续时间与快照间隔的比例非常小， 不会出现在 ADDM 发现的问题当中。比如，如果用户通知您系统在晚上 10 点到 10 点过 10 分之间非常慢，而 ADDM 分析 的时段在晚上 10 点到 11 点之间，并且未显示任何性能问题，则可能发生了短暂的性能问题，在用户所报告的10分钟 时段内只持续了数分钟。
本实验的目的： 初步理解ASH报告
本实验的环境： 笔记本电脑上的EBS12.1.3 虚拟机（32位）
本实验的过程： 1、登录EBS，查询出一张客户=ABC Corporation Asia 的销售订单，在订单行上添加一行，新增3个AS54888的订购；然后保存；（这个过程在打开虚拟机首次执行时大约耗时10分钟；以后第二次会快很多，当我们这里就是研究第一次的ASH报告）；
2、然后运行ASH报告，时间间隔为10分钟；
3、然后查看并分析ASH报告；
1、登录EBS，查询出一张客户=ABC Corporation Asia 的销售订单，在订单行上添加一行，新增3个AS54888的订购；然后保存；
2、运行ASH报告：
3、然后查看并分析ASH报告；
[oracle@syfdemo ~]$ more ashrpt_1_0212_1111.txt
ASH Report For VIS/VIS
DB Name DB Id Instance Inst Num Release RAC Host
———— ———– ———— ——– ———– — ————
VIS 280232500 VIS 1 11.1.0.7.0 NO syfdemo.ml.c
CPUs SGA Size Buffer Cache Shared Pool ASH Buffer Size
—- —————— —————— —————— ——————
2 1,501M (100%) 992M (66.1%) 432M (28.8%) 4.0M (0.3%)
Analysis Begin Time: 12-Feb-14 11:01:41
Analysis End Time: 12-Feb-14 11:11:46
Elapsed Time: 10.1 (mins)
Begin Data Source: V$ACTIVE_SESSION_HISTORY
End Data Source: V$ACTIVE_SESSION_HISTORY
Sample Count: 311
Average Active Sessions: 0.51
Avg. Active Session per CPU: 0.26
Report Target: None specified
Top User Events DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Avg Active
Event Event Class % Event Sessions
———————————– ————— ———- ———-
db file sequential read User I/O 64.31 0.33
CPU + Wait for CPU CPU 17.36 0.09
db file parallel read User I/O 6.75 0.03
log file sync Commit 2.89 0.01
————————————————————-
//// 上面这一节列出 来自用户进程的，占采样会话活动比例最高的一些等待事件； 这里例子中比例最高的等待事件是 数据库文件的顺序读； 说明最大的问题是IO；
Top Background Events DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Avg Active
Event Event Class % Activity Sessions
———————————– ————— ———- ———-
control file parallel write System I/O 3.22 0.02
CPU + Wait for CPU CPU 2.57 0.01
log file parallel write System I/O 2.25 0.01
————————————————————-
//// 上面这一节列出 来自后台进程的，占采样会话活动比例最高的一些等待事件； 最高的是控制文件的并行读，3.22% ；
Top Event P1/P2/P3 Values DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Event % Event P1 Value, P2 Value, P3 Value % Activity
—————————— ——- —————————– ———-
Parameter 1 Parameter 2 Parameter 3
————————– ————————– ————————–
db file sequential read 64.31 "1","593","1" 0.32
file# block# blocks
db file parallel read 6.75 "3","89","89" 0.64
files blocks requests
control file parallel write 3.22 "3","3","3" 2.89
files block# requests
log file sync 2.89 "9474","0","0" 1.29
buffer# NOT DEFINED NOT DEFINED
log file parallel write 2.25 "1","2","1" 0.64
files blocks requests
————————————————————-
//// 上面这一节列出 占采样会话活动比例最高的一些等待事件（按等待时间 %Event排序）； 并细分出每种等待事件中P1/P2/P3 三种子类型值；
比如 db file sequential read 64.31 "1","593","1" 0.32
file# block# blocks
表示 db file sequential read 是等待最严重的事件， 其中单个文件读发生了1次，单个Block读发生了593次，多个Block一起读发生了1次？
Top Service/Module DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Service Module % Activity Action % Action
————– ———————— ———- —————— ———-
VIS e:ONT:frm:OEXOEORD 69.77 ONT/ORDER_MGMT_SUP 69.77
SYS$BACKGROUND UNNAMED 7.72 UNNAMED 7.72
VIS frmweb@syfdemo.ml.com (T 6.11 UNNAMED 6.11
fnd.framework.service.lo 5.79 6882 5.79
e:ONT:wf:OEOL 3.86 ONT/ORDER_MGMT_SUP 3.86
————————————————————-
//// 上面这一节列出 占采样会话活动比例最高的一些服务和模块； 这里例子显示在这10分钟内，主要活动来自于销售订单Form;
Top Client IDs DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Avg Active
Client ID % Activity Sessions
————————————————– ———- ———-
User Program Service
————— ——————————— ——————–
OPERATIONS 76.53 0.39
APPS frmweb@syfdemo.ml.com (TNS V1-V3) VIS
OPERATIONS 5.79 0.03
APPS JDBC Thin Client VIS
————————————————————-
//// 上面这一节列出 占采样会话活动比例最高的客户端信息； 这里例子显示在这10分钟内，主要活动来自于ERP用户OPERATIONS , 对应的数据库用户是APPS， 使用的程序是Form;
Top SQL Command Types DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> ‘Distinct SQLIDs’ is the count of the distinct number of SQLIDs
with the given SQL Command Type found over all the ASH samples
in the analysis period
Distinct Avg Active
SQL Command Type SQLIDs % Activity Sessions
—————————————- ———- ———- ———-
SELECT 83 35.05 0.18
UPDATE 1 7.07 0.04
PL/SQL EXECUTE 10 6.75 0.03
INSERT 5 1.61 0.01
————————————————————-
//// 上面这一节列出 占采样会话活动比例最高的SQL语句类型； 这里例子显示在这10分钟内，主要活动来自于SELECT查询;
Top Phases of Execution DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Avg Active
Phase of Execution % Activity Sessions
—————————— ———- ———-
SQL Execution 85.85 0.44
PLSQL RPC 75.88 0.39
Hard Parse 17.68 0.09
Parse 17.68 0.09
PLSQL Compilation 14.15 0.07
————————————————————-
//// 上面这一节列出 占采样会话活动比例最高的SQL语句执行阶段； 这里例子显示在这10分钟内，主要SQL语句阶段来自于执行。 SQL的解析都是硬解析？；
^LTop SQL with Top Events DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Sampled #
SQL ID Planhash of Executions % Activity
———————– ——————– ——————– ————–
Event % Event Top Row Source % RwSrc
—————————— ——- ——————————— ——-
2r68fjxqkmpt8 732202868 0 6.75
db file parallel read 6.43 ** Row Source Not Available ** 6.43
UPDATE OE_ORDER_LINES SET ACCOUNTING_RULE_ID = :B341 , ACCOUNTING_RULE_DURATION
= :B340 , CALCULATE_PRICE_FLAG = :B339 , ACTUAL_ARRIVAL_DATE = :B338 , ACTUAL_SH
IPMENT_DATE = :B337 , AGREEMENT_ID = :B336 , ARRIVAL_SET_ID = :B335 , ATO_LINE_I
D = :B334 , ATTRIBUTE1 = :B333 , ATTRIBUTE10 = :B332 , ATTRIBUTE11 = :B331 , ATT
gdnwgx9fcxggr N/A 1 3.22
db file sequential read 3.22 ** Row Source Not Available ** 3.22
begin OE_SHIPPING_WF.START_SHIPPING (:v1, :v2, :v3, :v4, :v5); end;
8k76jah7wnp6t 2273136528 6 1.93
db file sequential read 1.29 TABLE ACCESS – BY INDEX ROWID 0.64
select prompt, description from fnd_menu_entries_tl where menu_id = :1 and entry
_sequence = :2 and language = :3
bs4bnjpfdnpn2 2066941791 4 1.29
db file sequential read 0.96 TABLE ACCESS – BY INDEX ROWID 0.96
select function_name, context_dependence, maintenance_mode_support, parame
ters, type, web_agent_name, web_host_name, web_html_call, web_icon, form_i
d from fnd_form_functions where function_id = :1
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的事件，以及导致该事件的SQL语句；这里的例子显示，这10分钟内等待时间最长的事件是 db file parallel read ； 而该事件主要是由于 “更新订单行”的SQL语句导致的。
Top SQL with Top Row Sources DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Sampled #
SQL ID PlanHash of Executions % Activity
———————– ——————– ——————– ————–
Row Source % RwSrc Top Event % Event
—————————————- ——- ———————– ——-
2r68fjxqkmpt8 732202868 0 6.75
** Row Source Not Available ** 6.75 db file parallel read 6.43
UPDATE OE_ORDER_LINES SET ACCOUNTING_RULE_ID = :B341 , ACCOUNTING_RULE_DURATION
= :B340 , CALCULATE_PRICE_FLAG = :B339 , ACTUAL_ARRIVAL_DATE = :B338 , ACTUAL_SH
IPMENT_DATE = :B337 , AGREEMENT_ID = :B336 , ARRIVAL_SET_ID = :B335 , ATO_LINE_I
D = :B334 , ATTRIBUTE1 = :B333 , ATTRIBUTE10 = :B332 , ATTRIBUTE11 = :B331 , ATT
gdnwgx9fcxggr N/A 1 3.22
** Row Source Not Available ** 3.22 db file sequential read 3.22
begin OE_SHIPPING_WF.START_SHIPPING (:v1, :v2, :v3, :v4, :v5); end;
8k76jah7wnp6t 2273136528 6 1.93
INDEX – UNIQUE SCAN 0.96 db file sequential read 0.64
select prompt, description from fnd_menu_entries_tl where menu_id = :1 and entry
_sequence = :2 and language = :3
bs4bnjpfdnpn2 2066941791 4 1.29
TABLE ACCESS – BY INDEX ROWID 1.29 db file sequential read 0.96
select function_name, context_dependence, maintenance_mode_support, parame
ters, type, web_agent_name, web_host_name, web_html_call, web_icon, form_i
d from fnd_form_functions where function_id = :1
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的SQL语句及其执行计划，如果是SELECT查询语句，列出详细的执行计划信息，用以了解那部分的SQL执行导致了最主要的问题；这里的例子显示，这10分钟内更新语句和API执行是导致 db file parallel read 这个等待最严重事件的罪魁祸首，但没有显示执行计划 ；而第三句SELECt倒是显示了 对fnd_menu_entries_tl 表的 Index Unique Scan 占据了 db file parallel read 这个等待最严重事件的0.96%；
Top SQL using literals DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
No data exists for this section of the report.
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的 使用了常量的SQL语句，我们可以看看如果存在使用常量的SQL语句，那么可以考虑使用绑定变量来改进； 本例中没有发现使用常量的SQL语句。
Top Parsing Module/Action DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
Module Action % Activ Event
—————————— ——————————– ——- ——–
e:ONT:frm:OEXOEORD ONT/ORDER_MGMT_SUPER_USER 16.08 db file
ONT/ORDER_MGMT_SUPER_USER db file
ONT/ORDER_MGMT_SUPER_USER CPU + Wa
frmweb@syfdemo.ml.com (TNS V1- 1.29 db file
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的,用在解析SQL语句上的模块。
Top PL/SQL Procedures DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> ‘PL/SQL entry subprogram’ represents the application’s top-level
entry-point(procedure, function, trigger, package initialization
or RPC call) into PL/SQL.
-> ‘PL/SQL current subprogram’ is the pl/sql subprogram being executed
at the point of sampling . If the value is ‘SQL’, it represents
the percentage of time spent executing SQL for the particular
plsql entry subprogram
PLSQL Entry Subprogram % Activity
—————————————————————– ———-
PLSQL Current Subprogram % Current
—————————————————————– ———-
APPS.OE_OE_FORM_LINE.VALIDATE_AND_WRITE 18.01
SQL 17.04
APPS.OE_OE_FORM_LINE.CHANGE_ATTRIBUTE 16.40
SQL 15.43
APPS.OE_OE_FORM_HEADER.PROCESS_OBJECT 9.00
SQL 8.04
APPS.OE_ATP.ATP_CHECK 4.18
SQL 3.86
APPS.OE_OE_FORM_LINE.DEFAULT_ATTRIBUTES 3.86
SQL 3.86
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的PLSQL程序。其中，PLSQL Entry Subprogram是PLSQL的入口程序，PLSQL Current Subprogram 是当前执行的子程序，如果PLSQL Current Subprogram =SQL； 那么%Current 表示的是为当前子程序执行SQL的百分比时间。
Top Java Workload DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
No data exists for this section of the report.
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的JAVA 程序, 本例中没有出现；
^LTop Sessions DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> ‘# Samples Active’ shows the number of ASH samples in which the session
was found waiting for that particular event. The percentage shown
in this column is calculated with respect to wall clock time
and not total database activity.
-> ‘XIDs’ shows the number of distinct transaction IDs sampled in ASH
when the session was waiting for that particular event
-> For sessions running Parallel Queries, this section will NOT aggregate
the PQ slave activity into the session issuing the PQ. Refer to
the ‘Top Sessions running PQs’ section for such statistics.
Sid, Serial# % Activity Event % Event
————— ———- —————————— ———-
User Program # Samples Active XIDs
——————– —————————— —————— ——–
362,34551 79.74 db file sequential read 57.88
APPS frmweb@syfdemo…m (TNS V1-V3) 180/605 [ 30%] 4
CPU + Wait for CPU 14.79
46/605 [ 8%] 1
db file parallel read 6.75
21/605 [ 3%] 1
286, 239 5.79 db file sequential read 4.18
APPS JDBC Thin Client 13/605 [ 2%] 0
CPU + Wait for CPU 1.61
5/605 [ 1%] 0
390, 1 3.54 control file parallel write 3.22
SYS oracle@syfdemo.ml.com (CKPT) 10/605 [ 2%] 0
279, 4765 2.89 db file sequential read 2.25
APPS frmweb@syfdemo…m (TNS V1-V3) 7/605 [ 1%] 0
391, 1 2.25 log file parallel write 2.25
SYS oracle@syfdemo.ml.com (LGWR) 7/605 [ 1%] 0
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的会话；
Top Blocking Sessions DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> Blocking session activity percentages are calculated with respect to
waits on enqueues, latches and "buffer busy" only
-> ‘% Activity’ represents the load on the database caused by
a particular blocking session
-> ‘# Samples Active’ shows the number of ASH samples in which the
blocking session was found active.
-> ‘XIDs’ shows the number of distinct transaction IDs sampled in ASH
when the blocking session was found active.
Blocking Sid (Inst) % Activity Event Caused % Event
——————– ———- —————————— ———-
User Program # Samples Active XIDs
——————– —————————— —————— ——–
391, 1( 1) 2.89 log file sync 2.89
SYS oracle@syfdemo.ml.com (LGWR) 7/605 [ 1%] 0
————————————————————-
//// 上面这一节列出 占采样会话活动比例最高的 阻塞其他会话的会话； 本例中这个会话的Session id 是391, XIDS =0 表示在采样期间，受影响的事务处理储量为0；
^LTop Sessions running PQs DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
No data exists for this section of the report.
————————————————————-
//// 上面这一节列出 占采样会话活动等待事件比例最高的 运行并行查询的会话； 本例中没有；
Top DB Objects DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> With respect to Application, Cluster, User I/O and buffer busy waits only.
Object ID % Activity Event % Event
————— ———- —————————— ———-
Object Name (Type) Tablespace
—————————————————– ————————-
67932 7.07 db file parallel read 6.43
ONT.OE_ATTACHMENT_RULES (TABLE) APPS_TS_SEED
34881 5.47 db file sequential read 5.47
APPLSYS.FND_PROFILE_OPTIONS (TABLE) APPS_TS_SEED
1231012 4.82 db file sequential read 4.50
APPLSYS.FND_PROFILE_OPTION_VALUES_U1 (INDEX) APPS_TS_TX_IDX
68069 3.54 db file sequential read 3.54
ONT.OE_ORDER_LINES_ALL (TABLE) APPS_TS_TX_DATA
34805 2.57 db file sequential read 2.57
APPLSYS.FND_NEW_MESSAGES_PK (INDEX) APPS_TS_SEED
————————————————————-
//// 上面这一节列出 占采样会话活动事件比例最高的事件所涉及的数据库对象；
Top DB Files DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> With respect to Cluster and User I/O events only.
File ID % Activity Event % Event
————— ———- —————————— ———-
File Name Tablespace
—————————————————– ————————-
7 18.97 db file sequential read 12.54
/d01/oracle/VIS/db/apps_st/data/reference3.dbf APPS_TS_SEED
db file parallel read 6.43
30 11.25 db file sequential read 11.25
/d01/oracle/VIS/db/apps_st/data/reference2.dbf APPS_TS_SEED
45 5.47 db file sequential read 5.47
/d01/oracle/VIS/db/apps_st/data/reference1.dbf APPS_TS_SEED
118 3.86 db file sequential read 3.86
/d01/oracle/VIS/db/apps_st/data/tx_data32.dbf APPS_TS_TX_DATA
70 2.89 db file sequential read 2.57
/d01/oracle/VIS/db/apps_st/data/tx_idx8.dbf APPS_TS_TX_IDX
————————————————————-
//// 上面这一节列出 占采样会话活动事件比例最高的事件所涉及的数据库文件；
Top Latches DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
No data exists for this section of the report.
————————————————————-
//// 上面这一节列出 占采样会话活动事件比例最高的事件所涉及的数据库latch（闩锁）；
Latch（闩锁）是简单的，低层次的序列化机制来保护共享数据结构在系统全局区（SGA）。例如，Latch保护用户当前访问的数据库和数据结构描述缓冲区高速缓存中的块的列表。一个服务器或后台进程获取一个锁存器，它在很短的时间，而操纵或在看这些结构中的一个。Latch的实现是依赖于操作系统，特别是关于一个进程是否以及如何长期等待Latch。
^LActivity Over Time DB/Inst: VIS/VIS (Feb 12 11:01 to 11:11)
-> Analysis period is divided into smaller time slots
-> Top 3 events are reported in each of those slots
-> ‘Slot Count’ shows the number of ASH samples in that slot
-> ‘Event Count’ shows the number of ASH samples waiting for
that event in that slot
-> ‘% Event’ is ‘Event Count’ over all ASH samples in the analysis period
Slot Event
Slot Time (Duration) Count Event Count % Event
——————– ——– —————————— ——– ——-
11:01:41 (19 secs) 6 db file sequential read 4 1.29
CPU + Wait for CPU 2 0.64
11:02:00 (1.0 min) 36 db file sequential read 28 9.00
CPU + Wait for CPU 6 1.93
db file parallel read 1 0.32
11:03:00 (1.0 min) 46 db file sequential read 27 8.68
CPU + Wait for CPU 13 4.18
control file parallel write 6 1.93
11:04:00 (1.0 min) 30 db file sequential read 21 6.75
CPU + Wait for CPU 6 1.93
control file parallel write 1 0.32
11:05:00 (1.0 min) 40 db file sequential read 30 9.65
CPU + Wait for CPU 9 2.89
db file scattered read 1 0.32
11:06:00 (1.0 min) 57 db file parallel read 20 6.43
db file sequential read 20 6.43
CPU + Wait for CPU 10 3.22
11:07:00 (1.0 min) 33 db file sequential read 27 8.68
CPU + Wait for CPU 5 1.61
control file parallel write 1 0.32
11:08:00 (1.0 min) 54 db file sequential read 43 13.83
CPU + Wait for CPU 10 3.22
control file parallel write 1 0.32
11:09:00 (1.0 min) 6 log file sync 5 1.61
log file parallel write 1 0.32
11:10:00 (1.0 min) 2 log file parallel write 1 0.32
log file sync 1 0.32
11:11:00 (46 secs) 1 CPU + Wait for CPU 1 0.32
————————————————————-
//// 上面这一节把采样会话活动期间分成十份； 第1份和第十分通常是时间零头；中间八份的时间是均等的；
本例中，蓝色部分是第八份，这一份时间内进行54次采样，等待数据库文件的顺序读事件发生43次，占总采用时间期间事件总数的13.83%；
End of Report
[oracle@syfdemo ~]$
参考： http://www.cnblogs.com/sqlite3/archive/2011/05/26/2568146.html
http://blog.itpub.net/35489/viewspace-609528
Oracle 官方文档 <oracle 11g performance tunning guider>
关于作者:
| 昵称:Jack.shang 档案信息:jack.shang 一位从技术走向管理，再从管理走向市场的普通行者 联系方式:你可以通过syfvb@hotmail.com联系作者 点击查看Jack.shang发表过的所有文章... 本文永久链接： http://blog.retailsolution.cn/archives/3497 |
对本文的评价:
Good write-up, I am normal visitor of one抯 site, maintain up the excellent operate, and It’s going to be a regular visitor for a lengthy time.
wayfarer ou new wayfarer http://www.arthotelitalia.it/fr/rayban-fr-56avWso8bp1570.html
Hi, i believe that i saw you visited my blog thus i got here to 搟go back|return} the favor?I’m attempting to in finding things to enhance my site!I suppose its adequate to use some of your ideas!!
ビジネス スーツケース 人気 http://www.ebz-alexandersbad.de/SansoniteJP/samsonite_654.html
I抳e learn some good stuff here. Certainly worth bookmarking for revisiting. I surprise how much effort you place to create this kind of great informative web site.
isabel marant etoile maxi dress http://fujisanstarch.com/team/isabel-full-1423.html
I抳e read some excellent stuff here. Certainly price bookmarking for revisiting. I wonder how so much attempt you place to make one of these fantastic informative website.
herve leger perfume 4u online games http://abc.idaily.vn/systems/herve_c_2194.html