ITPub博客

首页 > 数据库 > Oracle > 执行 grant statement 命令, DB hang

执行 grant statement 命令, DB hang

原创 Oracle 作者:lucyne 时间:2015-08-20 14:11:24 0 删除 编辑
当时执行的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进行了软解析。


Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> set lines 120
SQL> select session_id,sql_id,session_type,session_state,event
  2    from v$active_session_history
  3   where sample_time >=
  4         to_date('2013-11-06 18:02:00', 'yyyy-mm-dd hh24:mi:ss')
  5     and sample_time <=
  6         to_date('2013-11-06 18:09:00', 'yyyy-mm-dd hh24:mi:ss')
  7     and event is not null
  8     and event in ('latch: library cache',
  9                   'cursor: pin S wait on X',
10                   'library cache lock');

SESSION_ID SQL_ID        SESSION_TY SESSION EVENT
---------- ------------- ---------- ------- ----------------------------------------------------------
  5843     ff9yk9p2xgqqj     FOREGROUND     WAITING     latch: library cache         
  5864     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  5877     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6017     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6188     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6238     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  6501     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  5843     ff9yk9p2xgqqj     FOREGROUND     WAITING     latch: library cache         
  5864     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  5877     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6017     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6188     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6238     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  6501     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  5843     ff9yk9p2xgqqj     FOREGROUND     WAITING     latch: library cache         
  5864     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  5877     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6188     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6238     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  5843     ff9yk9p2xgqqj     FOREGROUND     WAITING     latch: library cache         
  5864     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  5877     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6188     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6238     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  5843     ff9yk9p2xgqqj     FOREGROUND     WAITING     latch: library cache         
  5864     2fry4cd25dnbx     FOREGROUND     WAITING     cursor: pin S wait on X         
  6238     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  6238     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  5823     cpj497kjx0dya     FOREGROUND     WAITING     latch: library cache         
  5843     cpj497kjx0dya     FOREGROUND     WAITING     library cache lock     5851     17875
  5864     2fry4cd25dnbx     FOREGROUND     WAITING     latch: library cache         
  5877     2fry4cd25dnbx     FOREGROUND     WAITING     library cache lock     5851     17875
  6017                                        FOREGROUND     WAITING     latch: library cache         
  6047     cpj497kjx0dya     FOREGROUND     WAITING     library cache lock     5851     17875
  6061                                        FOREGROUND     WAITING     latch: library cache         
  6110     ff9yk9p2xgqqj     FOREGROUND     WAITING     library cache lock     5851     17875    
  6261     cdmx52fnhqc8v     FOREGROUND     WAITING     library cache lock     5851     17875
  6293     cpj497kjx0dya     FOREGROUND     WAITING     latch: library cache         
  6349     6uhqu7cj1mkhm     FOREGROUND     WAITING     library cache lock     5851     17875
  6360     b99w0dykagkhc     FOREGROUND     WAITING     latch: library cache         
  6375     b99w0dykagkhc     FOREGROUND     WAITING     latch: library cache         
  6421     cpj497kjx0dya     FOREGROUND     WAITING     library cache lock     5851     17875
  6471     cpj497kjx0dya     FOREGROUND     WAITING     library cache lock     5851     17875
  6530                                        FOREGROUND     WAITING     latch: library cache         
  6533     bus6ugbbxm8n0     FOREGROUND     WAITING     library cache lock     5851     17875
  5823     cpj497kjx0dya     FOREGROUND     WAITING     latch: library cache         
  5843     cpj497kjx0dya     FOREGROUND     WAITING     library cache lock     5851     17875
  5877     2fry4cd25dnbx     FOREGROUND     WAITING     library cache lock     5851     17875
  6047     cpj497kjx0dya     FOREGROUND     WAITING     library cache lock     5851     17875
  6061                                        FOREGROUND     WAITING     latch: library cache         
  6110     ff9yk9p2xgqqj     FOREGROUND     WAITING     library cache lock     5851     17875
     
      
select sql_id, sql_text
  from v$sqlarea
where sql_id = 'ff9yk9p2xgqqj'
union all
select sql_id, sql_text
  from v$sqlarea
where sql_id = '2fry4cd25dnbx'
union all
select sql_id, sql_text from v$sqlarea where sql_id = '1wpryzh4nhudp';
sql_id                                    sql_text
---------------------------------------------------------------------
ff9yk9p2xgqqj     INSERT INTO bb_INFO (........) VALUES(:B9 ,:B8 ,:B7 ,:B6 ,1,:B5 , :B4 ,:B3 ,:B2 ,:B1 )
2fry4cd25dnbx     select ......   from bb_login t, bb_info t2 where t.uin = t2.uin and t2.uin = :1
1wpryzh4nhudp     select ......  from bb_info  where uin = :1 

运行以上sql查询sql text ,都是和grant 相关对象的select 语句,PROCEDURE 程序。


sys@ACCDB0> select owner, object_name, last_ddl_time
  2    from dba_objects
  3   where object_name = upper('user_certification_info');

OWNER                          OBJECT_NAME                    LAST_DDL_TIME
------------------------------ ------------------------------ -------------------
bb00                          bb_INFO        2013-11-06 18:03:12
bb02                         bb_INFO        2013-11-06 18:07:04
bb04                          bb_INFO        2013-11-06 18:08:28

也可以看出当对objects执行grant命令后,其实是对此objects执行了DDL。

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/26390465/viewspace-1777471/,如需转载,请注明出处,否则将追究法律责任。

上一篇: 搭建物理DataGuard
请登录后发表评论 登录
全部评论
. . 一个 DBA. . .

注册时间:2012-01-06

  • 博文量
    84
  • 访问量
    742458