Oracle数据库数据恢复、性能优化»论坛 › Oracle › Oracle数据库管理 › 执行 grant statement 命令, DB hang.

0 积分	0 好友	1 主题

发消息

[SQL调优] 执行 grant statement 命令, DB hang.

1^#

发表于 2013-11-19 14:19:35 | 查看: 5186| 回复: 15

本帖最后由 hellbebe 于 2013-11-20 09:41 编辑

当时执行的sql：grant select on xxx_user.xxx_table to xxx_user;

执行以上grant statement的时候db响应特别慢（hang），发现db出现大量的等待（latch: library cache，cursor: pin S wait on X，library cache lock）。

以下是相关的AWR报告及初步分析.

Snap Id Snap Time Sessions Cursors/Session
Begin Snap: 26178 06-Nov-13 18:00:53 683 6.4
End Snap: 26179 06-Nov-13 18:30:54 683 6.4
Elapsed:      30.02 (mins)
DB Time:      24.41 (mins)

Report Summary
Cache Sizes

Begin End
Buffer Cache: 37,584M 37,584M Std Block Size: 8K
Shared Pool Size: 3,296M 3,296M Log Buffer: 14,256K
Load Profile

Per Second Per Transaction
Redo size: 5,139.67 4,518.17
Logical reads: 184.98 162.61
Block changes: 28.13 24.73
Physical reads: 0.42 0.37
Physical writes: 3.24 2.85
User calls: 154.48 135.80
Parses: 40.67 35.75
Hard parses: 0.15 0.13
Sorts: 1.54 1.36
Logons: 0.18 0.16
Executes: 45.74 40.20
Transactions: 1.14

这里看发现硬解析并不高。

% Blocks changed per Read: 15.21 Recursive Call %: 21.58
Rollback per transaction %: 0.00 Rows per Sort: 224.84
Instance Efficiency Percentages (Target 100%)

Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 99.78 In-memory Sort %: 100.00
Library Hit %: 98.42 Soft Parse %: 99.63
Execute to Parse %: 11.08 Latch Hit %: 99.84
Parse CPU to Parse Elapsd %: 11.13 % Non-Parse CPU: 32.12
Shared Pool Statistics

Begin End
Memory Usage %: 80.43 66.40
% SQL with executions>1: 99.60 98.25
% Memory for SQL w/exec>1: 92.42 87.32
Top 5 Timed Events

Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
latch: library cache 262 928 3,544 63.4 Concurrency
library cache lock 112 275 2,455 18.8 Concurrency
CPU time      144      9.8
cursor: pin S wait on X 3,927 42 11 2.9 Concurrency
cursor: pin S 40,951,979 17 0 1.2 Other

以上TOP 5 Events中，主要都是与Shared Pool相关的latch 竞争。

Time Model Statistics
Total time in database user-calls (DB Time): 1464.6s
Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
Ordered by % or DB time desc, Statistic name
Statistic Name Time (s) % of DB Time
parse time elapsed 856.54 58.48
sql execute elapsed time 418.45 28.57
DB CPU 143.67 9.81
connection management call elapsed time 108.49 7.41
PL/SQL execution elapsed time 85.23 5.82
hard parse elapsed time 1.17 0.08
hard parse (sharing criteria) elapsed time 0.24 0.02
sequence load elapsed time 0.03 0.00
hard parse (bind mismatch) elapsed time 0.01 0.00
repeated bind elapsed time 0.01 0.00
PL/SQL compilation elapsed time 0.01 0.00
failed parse elapsed time 0.00 0.00
DB time 1,464.62
background elapsed time 21.60
background cpu time 12.89

在这里可以看到SQL的parse time elapsed 占用的时间较大,但hard parse elapsed time占用时间较小，这里可以确定不是由于硬解析造成的latch竞争。

Latch Sleep Breakdown
ordered by misses desc
Latch Name Get Requests Misses Sleeps Spin Gets Sleep1 Sleep2 Sleep3
shared pool 354,362 3,068 184 2,943 0 0 0
kks stats 70,249 2,178 10 2,168 0 0 0
library cache lock 261,435 888 6 882 0 0 0
library cache 130,662 755 262 497 0 0 0
qmn task queue latch 456 130 130 0 0 0 0
session allocation 58,563 47 39 10 0 0 0
cache buffers chains 612,018 21 1 20 0 0 0
process allocation 664 10 10 0 0 0 0
KWQMN job cache list latch 43 4 4 0 0 0 0
user lock 320 2 2 0 0 0 0
slave class create 20 1 1 0 0 0 0

Library Cache Activity
"Pct Misses" should be very low
Namespace Get Requests Pct Miss Pin Requests Pct Miss Reloads Invali- dations
BODY 157 0.00 767 0.00 0 0
CLUSTER 12 0.00 23 0.00 0 0
SQL AREA 2,910 3.06 91,531 1.75 218 35,792
TABLE/PROCEDURE 563 1.95 10,571 0.29 13 0
TRIGGER 300 0.00 300 0.00 0 0

在这里可以发现SQL AREA中的无效对象较多，被Reloads 的次数也较大。

SGA breakdown difference
ordered by Pool, Name
N/A value for Begin MB or End MB indicates the size of that Pool/Name was insignificant, or zero in that snapshot
Pool Name Begin MB End MB % Diff
java free memory 16.00 16.00 0.00
large PX msg pool 1.03 1.03 0.00
large free memory 14.97 14.97 0.00
shared CCursor 303.22 213.18 -29.70
shared KTI-UNDO 48.83 48.83 0.00
shared PCursor 202.59 178.07 -12.10
shared db_block_hash_buckets 360.00 360.00 0.00
shared event statistics per sess 59.71 59.71 0.00
shared free memory 645.07 1,107.57 71.70
shared kglsim object batch 56.89 56.89 0.01
shared library cache 148.08 143.32 -3.21
shared private strands 91.58 91.58 0.00
shared sessions 34.70 34.70 0.00
shared sql area 954.64 613.50 -35.73
streams Sender info 1.36 1.36 0.00
streams free memory 31.78 31.78 0.00
buffer_cache 37,584.00 37,584.00 0.00
fixed_sga 2.08 2.08 0.00
log_buffer 13.92 13.92 0.00

以上可以看到shared的 free memory 由645.07m上升到1,107.57m。

总结下来，可以确定可能是由于过度的软解析造成Shared Pools的相关latch竞争，因为grant命令改变了对象的权限信息，导致大量的sql进行了软解析。

请各位大师，刘大指正。谢谢