应用反应说系统慢,时间不固定,现象不知道,就是慢。无奈只好登陆系统查查看了。

查看系统上现有的快照信息

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 hh24:mi:ss') mintime,

  3  to_char(max(end_interval_time),'yyyy-mm-dd hh24: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 platforms
8 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"