精算業務死鎖的具體分析

liiinuuux發表於2015-03-27
真實表名、欄位名、函式名、機器名、例項名已經替換

擷取trace檔案的片段:
trace檔案是42號程式——也就是後面的 sid 777生成的。
Instance name: PROD
Redo thread mounted by this instance: 1
Oracle process number: 42
Unix process pid: 4620, image: oracle@hostname (TNS V1-V3)

是兩個session的交叉等待。
Deadlock graph:
                       ---------Blocker(s)--------  ---------Waiter(s)---------
Resource Name          process session holds waits  process session holds waits
TX-0061001a-029a615c        42     777     X             82     163           X
TX-00620000-02e23e15        82     163     X             42     777           X

等待的行鎖情況
Rows waited on:
  Session 777: obj - rowid = 000B670F - AAC6hMAIdAACr0fAAL
  (dictionary objn - 747279, file - 541, block - 703775, slot - 11)
  Session 163: obj - rowid = 000B670F - AAC6hMAIJAAMOzeAAA
  (dictionary objn - 747279, file - 521, block - 3206366, slot - 0)

objn 747279得知,是TAB1表。死鎖的原因是兩個 session各自鎖住一行,未提交的情況下請求對方已獲得的行鎖。
10:22:06 SQL> select object_name, object_type from dba_objects where object_id = 747279;

OBJECT_NAME                    OBJECT_TYPE
------------------------------ -------------------
TAB1                           TABLE


sid 163執行的SQL SELECT FUNC2(':B3 , 86', :B2 , :B1 ) FROM DUAL
----- Information for the OTHER waiting sessions -----
Session 163:
  sid: 163 ser: 5387 audsid: 124855449 user: 117/usr
  ...
  ...
  current SQL:
  SELECT FUNC2(:B3 , '86', :B2 , :B1 ) FROM DUAL

----- End of information for the OTHER waiting sessions -----

sid 777執行的SQL
Information for THIS session:

----- Current SQL Statement for this session (sql_id=4vd948jucpdj7) -----
DELETE FROM TAB1 WHERE COL1 = :B6 AND COL2 = :B5 AND COL3 = :B4 AND COL4 = :B3 AND COL5 = :B2 AND COL6 = :B1

sid 777的call stack:
可見 163777兩個session 是執行同一個函式。
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
c0000006b13f2808      1963  function usr.FUNC2
c0000006a8debfe8       119  function usr.FUNC1

下面是程式碼裡FUNC1中呼叫FUNC2的地方。需要注意的是引數 col1和截止日期enddate 
Select FUNC2( Cursor_Col1,
                                 '86',
                                 CalDate,
                                 enddate)


出現死鎖的 delete語句的條件,正好是TAB1的主鍵 6個欄位
INDEX_OWNE TABLE_NAME          INDEX_NAME                     COLUMN_NAME   COLUMN_POSITION
---------- ------------------- ------------------------------ ------------- ---------------
usr        TAB1                PK_TAB1_NEW                    COL1                        1
usr        TAB1                PK_TAB1_NEW                    COL2                        2
usr        TAB1                PK_TAB1_NEW                    COL3                        3
usr        TAB1                PK_TAB1_NEW                    COL4                        4
usr        TAB1                PK_TAB1_NEW                    COL5                        5
usr        TAB1                PK_TAB1_NEW                    COL6                        6

這些欄位的來源,可以看出 TAB1的主鍵雖然有很多欄位,但是本質上是由 col1對應的tab2記錄,以及“提數截止日期” 這兩個因素決定的 
程式碼裡的具體過程:
先透過 col1取出tab2的資料
Cursor v_cur_col1(tCol1 xxx.Col1%Type) Is
      Select * From tab2 Where col1 = tcol1
      And .... ;
...
...
v_Row_data.Col1          := v_Row_tab2.Col1;
v_Row_data.Col2        := v_Row_tab2.Col2;
...
v_Row_data.Col3 := v_Row_tab2.Col3;
...
col4是透過col1col2獲取tab3.custno
Select xx, xx, xx, xx, xx,custno,xx
            Into v_xx,
                v_xx,
                v_xx,
                v_xx,
                v_xx,
                v_col4,
                v_xx
            From tab3
           Where col1 = v_Row_data.col1
             And insid = v_Row_tab2.col2;
...
v_Row_data.col4 := v_col4;
...
col5 是呼叫函式時傳入的引數,具體是 FUNC1的“提數截止日期”,即enddate
v_Row_data.Col5 := enddate
...
col6寫死為1
v_Row_data.col6:= 1;

也就是說只要兩個 session在呼叫FUNC2時,傳入了相同的col1enddate,就有可能出現死鎖。
下面是 col1的具體來源。
透過 FUNC1的引數threadnumber執行緒號,從 selcol1裡取col1。這樣在併發執行的時候可以讓每個執行緒處理不同的col1。
Cursor v_Cursor_SelCol1 Is
      Select col1
        From SelCol1
       Where Default3 = Theardnumber;

因此出現死鎖的原因可能是:
1 不同Theardnumber 對應相同的 col1
2 兩個session 傳入的Theardnumber引數相同。
根據下面查詢得知,整張 selcol1表沒有重複的col1 。否定第一種可能。
11:11:41 SQL> select col1, count(*) from usr.selcol1 having(count(*) > 1) group by col1;

no rows selected


awr得知呼叫 FUNC1SQL SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), Theardnumber) FROM dual的形式
force_matching_signature17618561598766997330

下面是執行次數超過一次的
11:29:33 SQL> select sql_id, max(EXECUTIONS_TOTAL) from dba_hist_sqlstat where force_matching_signature = 17618561598766997330 and EXECUTIONS_TOTAL > 1 group by sql_id;

SQL_ID        MAX(EXECUTIONS_TOTAL)
------------- ---------------------
0dwvwdw0ds5h5                     2
0zkf60kczb79a                     3
24b81bj11mw50                     3
4xnsbjz2axhsp                     4
54n4p2s1rc1vd                     4
7kkv6zy3ndx68                     3
9q15dhs75tb4f                     3
g7thjdfqsb07w                     3


12:45:52 SQL> select distinct sql_id, dbms_lob.substr(sql_text, 100) from dba_hist_sqltext where sql_id in
12:45:52   2  (
12:45:52   3  '0dwvwdw0ds5h5',
12:45:53   4  '0zkf60kczb79a',
12:45:53   5  '24b81bj11mw50',
12:45:53   6  '4xnsbjz2axhsp',
12:45:53   7  '54n4p2s1rc1vd',
12:45:53   8  '7kkv6zy3ndx68',
12:45:53   9  '9q15dhs75tb4f',
12:45:53  10  'g7thjdfqsb07w'
12:45:53  11  )
12:45:53  12  order by 2
12:45:53  13  ;

SQL_ID
-------------
DBMS_LOB.SUBSTR(SQL_TEXT,100)
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
g7thjdfqsb07w
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '110') FROM dual

0zkf60kczb79a
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '118') FROM dual

24b81bj11mw50
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '18') FROM dual

9q15dhs75tb4f
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '32') FROM dual

0dwvwdw0ds5h5
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '36') FROM dual

4xnsbjz2axhsp
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '74') FROM dual

7kkv6zy3ndx68
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '75') FROM dual

54n4p2s1rc1vd
SELECT usr.FUNC1('0','0',to_date('2015-03-07','YYYY-MM-DD'), '78') FROM dual


8 rows selected.

上面的統計資料是 312號以後的。
如果這些執行次數超過一次的 sql的執行時間有相互重疊時間段,尤其是歷史執行計劃中 selcol1既有走全表,又有走索引的,返回資料的順序不一致,就很有可能出現死鎖。
11:21:03 SQL> select snap_id, end_interval_time from dba_hist_snapshot where snap_id = (
12:57:21   2  select min(snap_id) from dba_hist_sqlstat where sql_id in
12:57:22   3  (
12:57:22   4  '0dwvwdw0ds5h5',
12:57:22   5  '0zkf60kczb79a',
12:57:22   6  '24b81bj11mw50',
12:57:22   7  '4xnsbjz2axhsp',
12:57:22   8  '54n4p2s1rc1vd',
12:57:22   9  '7kkv6zy3ndx68',
12:57:22  10  '9q15dhs75tb4f',
12:57:22  11  'g7thjdfqsb07w'
12:57:22  12  ))
12:57:23  13  ;

   SNAP_ID END_INTERVAL_TIME
---------- ---------------------------------------------------------------------------
     51955 2015-03-12 04:00:13

下面是同一條 SQL由不同session執行的情況,標紅的是時間上有重合的。 其中就包括 trace中的777 163
13:15:25 SQL> select session_id, sql_id, min(sample_time), max(sample_time)
13:15:26   2  from dba_hist_active_sess_history
13:15:26   3  where dbid = 2127610945
13:15:26   4  and instance_number = 1
13:15:26   5  and snap_id > 51953
13:15:26   6  and sql_id in
13:15:26   7  (
13:15:26   8  '0dwvwdw0ds5h5',
13:15:26   9  '0zkf60kczb79a',
13:15:26  10  '24b81bj11mw50',
13:15:27  11  '4xnsbjz2axhsp',
13:15:27  12  '54n4p2s1rc1vd',
13:15:27  13  '7kkv6zy3ndx68',
13:15:27  14  '9q15dhs75tb4f',
13:15:27  15  'g7thjdfqsb07w'
13:15:27  16  )
13:15:27  17  group by session_id, sql_id
13:15:27  18  order by 2, 3
13:15:27  19  ;

SESSION_ID SQL_ID        MIN(SAMPLE_TIME)          MAX(SAMPLE_TIME)
---------- ------------- ------------------------- --------------------------
       466 0dwvwdw0ds5h5 2015-03-19 19:22:17       2015-03-21 18:15:24
       701 0dwvwdw0ds5h5 2015-03-23 09:30:24       2015-03-24 12:38:32
       388 0zkf60kczb79a 2015-03-12 20:11:50       2015-03-14 03:01:01
       619 0zkf60kczb79a 2015-03-19 16:54:39       2015-03-22 12:20:59
       548 0zkf60kczb79a 2015-03-19 17:06:16       2015-03-22 06:52:14
      1156 0zkf60kczb79a 2015-03-20 01:21:01       2015-03-22 15:54:56
        80 24b81bj11mw50 2015-03-12 22:15:14       2015-03-14 16:08:00
     1084 24b81bj11mw50 2015-03-19 22:24:15       2015-03-23 05:13:51
       850 24b81bj11mw50 2015-03-20 03:43:46       2015-03-23 00:20:17
       854 24b81bj11mw50 2015-03-20 08:55:01       2015-03-23 03:21:45
       851 4xnsbjz2axhsp 2015-03-12 06:57:08       2015-03-14 02:00:55
       469 4xnsbjz2axhsp 2015-03-19 18:06:32       2015-03-22 14:31:57
       852 4xnsbjz2axhsp 2015-03-20 13:27:54       2015-03-22 13:18:44
       933 4xnsbjz2axhsp 2015-03-20 20:59:03       2015-03-22 15:53:26
      1081 54n4p2s1rc1vd 2015-03-13 11:05:42       2015-03-15 10:42:54
       700 54n4p2s1rc1vd 2015-03-19 18:53:40       2015-03-23 04:07:12
      1007 54n4p2s1rc1vd 2015-03-20 06:16:37       2015-03-23 01:43:57
       313 54n4p2s1rc1vd 2015-03-20 11:07:41       2015-03-23 00:18:06
       851 7kkv6zy3ndx68 2015-03-14 07:25:49       2015-03-16 08:22:17
         8 7kkv6zy3ndx68 2015-03-19 23:22:50       2015-03-22 08:45:51
       392 7kkv6zy3ndx68 2015-03-20 00:47:01       2015-03-22 11:30:39
       625 7kkv6zy3ndx68 2015-03-20 09:56:38       2015-03-22 13:14:31
       774 9q15dhs75tb4f 2015-03-17 22:03:30       2015-03-19 21:39:19
       393 9q15dhs75tb4f 2015-03-20 17:56:14       2015-03-23 03:58:47
       313 9q15dhs75tb4f 2015-03-23 11:14:36       2015-03-23 18:23:51
       159 g7thjdfqsb07w 2015-03-12 22:56:08       2015-03-14 22:43:15
      777 g7thjdfqsb07w 2015-03-19 20:30:28       2015-03-22 21:19:50
       163 g7thjdfqsb07w 2015-03-19 21:27:11       2015-03-22 21:42:33
      1160 g7thjdfqsb07w 2015-03-20 08:36:51       2015-03-22 20:58:17

29 rows selected.

  

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/26239116/viewspace-1476280/,如需轉載,請註明出處,否則將追究法律責任。

相關文章