执行 grant statement 命令, DB hang

最新推荐文章于 2022-06-08 16:25:06 发布

demo1573

最新推荐文章于 2022-06-08 16:25:06 发布

阅读量528

点赞数

本文通过AWR报告分析了一个因执行Grant命令导致数据库响应缓慢的问题。通过对报告中的等待事件、闩锁睡眠分解、共享池统计数据等进行分析，确定了问题是由过度的软解析引起的相关闩锁竞争。

摘要生成于 C知道，由 DeepSeek-R1 满血版支持，前往体验 >

当时执行的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
shared pool	354,362	3,068	184	2,943
kks stats	70,249	2,178	10	2,168
library cache lock	261,435	888	6	882
library cache	130,662	755	262	497
qmn task queue latch	456	130	130	0
session allocation	58,563	47	39	10
cache buffers chains	612,018	21	1	20
process allocation	664	10	10	0
KWQMN job cache list latch	43	4	4	0
user lock	320	2	2	0
slave class create	20	1	1	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。