cursor: pin S wait on X数据库缓慢
应用反应说系统慢，时间不固定，现象不知道，就是慢。无奈只好登陆系统查查看了。
查看系统上现有的快照信息
SQL> col mintime for a30
SQL> col maxtime for a30
SQL>
SQL> select min(snap_id) minid, max(snap_id) maxid,
2 to_char(min(begin_interval_time),'yyyy-mm-dd hh34:mi:ss') mintime,
3 to_char(max(end_interval_time),'yyyy-mm-dd hh34:mi:ss') maxtime
4 from dba_hist_snapshot;
根据快照信息，我们来查看一下对应的等待事件分类情况
SQL> 1 select wait_class_id,wait_class, count(*) cnt
2 from dba_hist_active_sess_history
3 where snap_id between 78303 and 78472
4 group by wait_class_id, wait_class
5* order by 3
WAIT_CLASS_ID WAIT_CLASS CNT
------------- -------------------- ----------
2723168908 Idle 2
4166625743 Administrative 6
2000153315 Network 538
4217450380 Application 829
3290255840 Configuration 4128
4108307767 System I/O 9234
1893977003 Other 11043
3386400367 Commit 26802
1740759767 User I/O 28076
375421
3875070507 Concurrency 888984
11 rows selected.
查看具体的等待事件情况
SQL> select event_id, event, count(*) cnt
2 from dba_hist_active_sess_history
3 where snap_id between 78303 and 78472
4 and wait_class_id=3875070507
5 group by event_id, event
6 order by 3;
EVENT_ID EVENT CNT
---------- ---------------------------------------------------------------- ----------
877525844 cursor: mutex X 1
86156091 os thread startup 6
1242501677 latch: library cache pin 7
1714089451 row cache lock 7
2952162927 library cache load lock 10
2802704141 library cache pin 22
2032051689 latch: library cache lock 45
1117386924 latch: row cache objects 60
1394127552 latch: In memory undo latch 68
2779959231 latch: cache buffers chains 873
2161531084 buffer busy waits 4286
916468430 library cache lock 4549
2696347763 latch: shared pool 12360
589947255 latch: library cache 12718
1729366244 cursor: pin S wait on X 853972
查找出pin S wait on X对应的SQL
SQL> select sql_id, count(*) cnt
from dba_hist_active_sess_histo 2 ry
where snap_id between 78303 and 3 78472
4 and event_id in (1729366244)
5 group by sql_id
having count(*)> 6 100
order by 7 2 desc;
SQL_ID CNT
------------- ----------
0nuvj12m3ryvy 853880
接着上面的查询我们可以从awr历史信息里找到这些sql语句主要在等待那些对象：
SQL> select owner,current_obj#,object_name,object_type, count(*) cnt
2 from dba_hist_active_sess_history a, dba_objects b
3 where snap_id between 78303 and 78472
4 and event_id in (1729366244)
5 and sql_id in ('0nuvj12m3ryvy')
6 and a.current_obj#=b.object_id
7 group by owner,current_obj#,object_name,object_type
8 having count(*) > 10
9 order by 5 desc;
OWNER CURRENT_OBJ# OBJECT_NAME OBJECT_TYPE CNT
---------- ------------ ------------------------------ ------------------- ----------
SETTLE 49326 T_OPERATE_LOG TABLE 654899
SYS 73541 LOG$INFORMATION TABLE 16337
SETTLE 48117 G_MENU_RIGHT TABLE 9684
SETTLE 141993 CONFIG_UNIX INDEX 9567
SETTLE 136520 T_MANAGE_WARN_CONFIG TABLE 9565
SETTLE 51955 T_BILL_LOG TABLE 9520
SETTLE 48128 G_ROLE TABLE 9458
下面确认等待的数据库是否过于集中，也就是确认是否存在热块儿问题：
SQL> select current_file#,current_block#, count(*) cnt
2 from dba_hist_active_sess_history
3 where snap_id between 78303 and 78472
4 and event_id in (1729366244)
and sql_id in ('0nuvj12m3ryv 5 y')
6 and current_obj# in (49326,48117,141993,136520,51955,48128)
7 group by current_file#, current_block#
8 having count(*)>50
9 order by 3;
CURRENT_FILE# CURRENT_BLOCK# CNT
------------- -------------- ----------
9 4436 9458
276 839623 9500
246 857417 9520
276 839495 9521
2 532140 9565
55 1153960 9567
276 840134 9648
25 739537 9684
275 906620 9687
276 838125 15128
276 843388 15131
275 906533 15138
275 904906 15180
275 904851 15186
275 902677 15210
276 845366 15210
275 909383 15216
275 902396 15220
275 905990 15333
275 909920 15422
276 840809 15427
276 845296 15451
275 906837 15454
276 843996 15777
276 837403 15778
275 908047 15784
275 906933 15813
275 909489 15813
275 903374 15814
276 844903 15886
276 841993 15925
275 907463 15942
276 839733 15944
275 905797 15944
275 908458 15944
276 838802 15948
276 843290 15950
275 905767 16209
275 909728 16213
275 904723 16262
275 908888 16263
276 844986 16275
276 844862 16347
275 906325 16394
275 904842 16403
275 908197 24737
276 841357 25472
47 rows selected.
网上也有另外一种思路，是根据MOS上面的
How to Determine the Blocking Session for Event: 'cursor: pin S wait on X' (Doc ID 786507.1)
Cursor: pin S wait on X
Cursor: pin S wait on X
当一个session为一个与pin相关的共享操作（such as executing a cursor）请求一个mutex时,该session会有Cursor: pin S wait on X等待事件。
但是该mutex不能被授权，因为该mutex正在被其他session以排他模式持有（比如 parsing the cursor）
v$session or v$session_wait中的p2raw列 给出了 cursor: pin S wait on X等待事件的阻塞者session（持有者session）
按照MOS文档方法，我们查看一下
SQL> select p2raw from v$session where event = 'cursor: pin S wait on X';
P2RAW
----------------
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
000001B200000000
--参数说明P1 Hash value of cursor P2 Mutex value 64 bit platforms8 bytes are used.Top 4 bytes hold the session id (if the mutex is held X)Bottom 4 bytes hold the ref count (if the mutex is held S). 32 bit platforms 4 bytes are used.Top 2 bytes hold the session id (if the mutex is held X) Bottom 2 bytes hold the ref count (if the mutex is held S). P3 Mutex where (an internal code locator) OR'd with Mutex Sleeps我们的操作系统是64位的。所以我们可以将查询结果000001B200000000前八位000001B2进行换算10进制得出结果434。
当然也可以用命令来换算一下
SQL> select p2raw,to_number(substr(to_char(rawtohex(p2raw)),1,8),'XXXXXXXX') sid
2 from v$session
3 where event = 'cursor: pin S wait on X';
P2RAW SID
---------------- ----------
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
000001B200000000 434
我们尝试看看能不能找到block session会话关系
SQL> select p1, p2raw, count(*) from v$session
where event ='cursor: pin S 2 wait on X'
and wait_time = 0
3 4 group by p1, p2raw;
P1 P2RAW COUNT(*)
---------- ---------------- ----------
2788948862 000001B200000000 59
--参数说明
p1 = the mutex Id
This has the same definition as v$mutex_sleep_history.mutex_identifier
p2raw = holding Session Id | Ref Count
The most significant bytes always store the Holding Session Id (Holding SId).
The least significant bytes always store the Ref Count.
SQL> select sid,serial#,SQL_ID,BLOCKING_SESSION,BLOCKING_SESSION_STATUS,EVENT
2 from v$session where SID=434;
SID SERIAL# SQL_ID BLOCKING_SESSION BLOCKING_SE EVENT
---------- ---------- ------------- ---------------- ----------- ----------------------------------------------------------------
434 34745 0nuvj12m3ryvy UNKNOWN single-task message
SQL> select sid,serial#,SQL_ID,BLOCKING_SESSION,BLOCKING_SESSION_STATUS,EVENT
2 from v$session where event ='cursor: pin S wait on X'
3 ;
SID SERIAL# SQL_ID BLOCKING_SESSION BLOCKING_SE EVENT
---------- ---------- ------------- ---------------- ----------- ----------------------------------------------------------------
332 59875 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
333 27868 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
350 54031 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
365 5053 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
383 61654 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
392 13286 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
415 10261 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
442 8546 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
444 20213 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
452 18561 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
480 14834 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
484 12814 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
497 27271 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
519 18389 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
521 10435 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
533 36612 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
561 37558 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
579 24259 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
588 30464 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
589 12607 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
594 43683 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
606 720 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
612 1150 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
628 42806 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
635 13159 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
637 47496 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
655 48974 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
660 5891 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
682 6519 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
711 46117 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
716 14265 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
720 4766 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
723 61645 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
724 17910 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
729 9951 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
752 28924 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
753 12049 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
761 64354 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
839 33810 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
843 6215 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
867 7396 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
871 58051 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
880 17967 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
884 22198 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
902 65183 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
907 65065 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
914 35470 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
928 63975 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
949 42782 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
950 4799 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
951 17067 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
952 36283 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
954 17638 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
992 8218 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
999 63310 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
1006 48986 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
1028 45586 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
1043 53471 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
1082 13982 0nuvj12m3ryvy UNKNOWN cursor: pin S wait on X
59 rows selected.
遇到了bug了。因为当前系统version count并不高。
SQL> select sql_id,version_count from v$sqlarea where version_count> 100 order by 2 desc ;
no rows selected
发生cursor: pin S wait on X原因
Frequent Hard Parses
If the frequency of Hard Parsing is extremely high, then contention can occur on this pin.
High Version Counts
When Version counts become excessive, a long chain of versions needs to
be examined and this can lead to contention on this event
Known bugs
Bug 5907779 - Self deadlock hang on "cursor: pin S wait on X" (typically from DBMS_STATS) [ID 5907779.8]
Bug 7568642: BLOCKING_SESSION EMPTY FOR "CURSOR: PIN S WAIT ON X"
