[20140130]關於enq TX-allocate ITL entry

 

昨天遇到一例enq TX - allocate ITL entry等待事件,就是維護人員開啟多個會話更新一個表的某個欄位,開始以為等待與undo有關,查
看才發現是"enq TX - allocate ITL entry",因為沒有業務操作,建議修改為ctas來建立新表,建立相關索引,然後改名完成操作.

實際上,一般正常的業務操作,很少遇到這個等待事件,如果出現一般是pctfree設定太小或者由於記錄程度增大,導致pctfree減少,以及塊
上事務太多而導致問題.

做一個簡單的比喻：1個資料塊相當於小區，ITL slot相當於小區的停車位，pctfree的空間相當於公共綠地。每個事務相當於小汽車，當
發生一個事務時，佔用一個itl slot，直到commit，其他事務才能使用。而當事務很多的時候，就要向pctfree區借用空間，如果由於
pctfree設定太小或者由於修改記錄導致記錄長度增加，這樣pctfree減少，如果在一個塊上有許多事務，又沒有及時提交，無法建立
itl slot時，就出現enq TX - allocate ITL entry等待事件。我以前遇到的問題是在10.2.0.4上itl solt的分配演算法存在問題,導致
很快出現長時間等待.實際上上面的操作最後變成不可能完成的業務。在10.2.0.4下出現這個問題更快，可以參考我以前寫的連結：

http://blog.itpub.net/267265/viewspace-717089/
http://blog.itpub.net/267265/viewspace-731657/

--為了加深印象,拿12c重複做一次測試看看.以下指令碼來自原作者Christian Antognini，我僅僅加入時間的輸出。

#!/bin/sh

user=$1
password=$2
sid=$3
wait=$4

#
# Setup test environment
#

sqlplus -s $user/$password@$sid <  SET ECHO OFF TERMOUT ON FEEDBACK OFF HEADING OFF
  BEGIN
    EXECUTE IMMEDIATE 'DROP TABLE t PURGE';
  EXCEPTION
    WHEN OTHERS THEN NULL;
  END;
  /
  CREATE TABLE t (n NUMBER, pad VARCHAR2(50)) PCTFREE 0 INITRANS 5 TABLESPACE users;
  INSERT INTO t SELECT rownum, rpad('*',50,'*') FROM dual CONNECT BY level <= 134 UNION ALL SELECT 135, rpad('*',48,'*') FROM dual;
  COMMIT;
  SELECT 'Setup correctly performed:', decode(count(DISTINCT dbms_rowid.rowid_block_number(rowid)),1,'YES','NO') FROM t;
END

#
# Produce ITL wait
#

for i in 1 2 3 4 5 6
do
  echo 'SET ECHO OFF TERMOUT OFF FEEDBACK OFF' > $i.$sid.sql
  if [[ $i = 6 ]]
  then
    # make sure that the other processes have locked one row
    echo 'execute dbms_lock.sleep(1)' >> $i.$sid.sql
  fi
  echo 'UPDATE t SET n = n WHERE n =' $i ';' >> $i.$sid.sql
  echo 'SET TERMOUT OFF' >> $i.$sid.sql
  if [[ $i < 6 ]]
  then
    echo 'execute dbms_lock.sleep(' $wait ')' >> $i.$sid.sql
  fi
  sqlplus -s $user/$password@$sid @$i.$sid.sql &
done

#
# Monitor ITL wait
#

sqlplus -s $user/$password@$sid <  SET SERVEROUTPUT ON ECHO OFF TERMOUT ON FEEDBACK OFF HEADING OFF
  SELECT * FROM v\$version WHERE rownum = 1;
  DECLARE
    l_waiter_session v\$session.sid%TYPE := NULL;
    l_blocking_session_curr v\$session.blocking_session%TYPE := NULL;
    l_blocking_session_prev v\$session.blocking_session%TYPE := NULL;
    l_seconds_in_wait_curr v\$session.seconds_in_wait%TYPE := NULL;
    l_seconds_in_wait_prev v\$session.seconds_in_wait%TYPE := NULL;
    c_sleep CONSTANT NUMBER := 0.1;
    c_iterations CONSTANT NUMBER := ceil(($wait-5)/c_sleep);
  BEGIN
    WHILE l_waiter_session IS NULL
    LOOP
      BEGIN
        SELECT sid INTO l_waiter_session
        FROM v\$session
        WHERE event = 'enq: TX - allocate ITL entry';
      EXCEPTION
        WHEN no_data_found THEN NULL;
      END;
    END LOOP;
    FOR i IN 1..c_iterations
    LOOP
      BEGIN
        SELECT blocking_session, seconds_in_wait INTO l_blocking_session_curr, l_seconds_in_wait_curr
        FROM v\$session
        WHERE sid = l_waiter_session;
      EXCEPTION
        WHEN no_data_found THEN NULL;
      END;
      IF l_blocking_session_curr <> l_blocking_session_prev
         OR l_blocking_session_prev IS NULL
         OR i = c_iterations
      THEN
        dbms_output.put_line(to_char(systimestamp,'HH24:MI:SS.FF')||' '||to_char((i-1)*c_sleep,'000000')||
                             ' blocking_session='||nvl(l_blocking_session_prev,l_blocking_session_curr)||
                             ' sleep='||nvl(l_seconds_in_wait_prev,l_seconds_in_wait_curr));
      END IF;
      l_blocking_session_prev := l_blocking_session_curr;
      l_seconds_in_wait_prev := l_seconds_in_wait_curr;
      dbms_lock.sleep(c_sleep);
    END LOOP;
  END;
  /
END

#
# Cleanup
#

for i in 1 2 3 4 5 6
do
  rm $i.$sid.sql
done

sleep 5

sqlplus -s $user/$password@$sid <  SET ECHO OFF TERMOUT ON FEEDBACK OFF HEADING OFF
  DROP TABLE t PURGE;
END

exit 0

--結果如下：
[oracle11g@hisdg IP=40 ~/test1 18]$ . itl.sh scott tiger ztest 1300

Setup correctly performed: YES

Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
09:32:55.610000000  000000 blocking_session=127 sleep=0
09:32:56.611000000  000001 blocking_session=127 sleep=1
09:32:57.611000000  000002 blocking_session=256 sleep=1
09:32:58.611000000  000003 blocking_session=18 sleep=1
09:32:59.611000000  000004 blocking_session=126 sleep=1
09:33:00.611000000  000005 blocking_session=368 sleep=1
09:33:02.611000000  000007 blocking_session=127 sleep=2
09:33:04.611000000  000009 blocking_session=256 sleep=2
09:33:06.611000000  000011 blocking_session=18 sleep=2
09:33:08.612000000  000013 blocking_session=126 sleep=2
09:33:10.612000000  000015 blocking_session=368 sleep=2
09:33:14.612000000  000019 blocking_session=127 sleep=4
09:33:18.612000000  000023 blocking_session=256 sleep=4
09:33:22.612000000  000027 blocking_session=18 sleep=4
09:33:26.613000000  000031 blocking_session=126 sleep=4
09:33:30.613000000  000035 blocking_session=368 sleep=4
09:33:35.613000000  000040 blocking_session=127 sleep=5
09:33:40.613000000  000045 blocking_session=256 sleep=5
09:33:45.615000000  000050 blocking_session=18 sleep=5
09:33:50.615000000  000055 blocking_session=126 sleep=5
09:33:58.615000000  000063 blocking_session=368 sleep=8
09:34:03.616000000  000068 blocking_session=127 sleep=5
09:34:08.616000000  000073 blocking_session=256 sleep=5
09:34:13.616000000  000078 blocking_session=18 sleep=5
09:34:18.617000000  000083 blocking_session=126 sleep=5
09:34:34.620000000  000099 blocking_session=368 sleep=16
09:34:39.621000000  000104 blocking_session=127 sleep=5
09:34:44.621000000  000109 blocking_session=256 sleep=5
09:34:49.623000000  000114 blocking_session=18 sleep=5
09:34:54.625000000  000119 blocking_session=126 sleep=5
09:35:26.627000000  000151 blocking_session=368 sleep=32
09:35:31.628000000  000156 blocking_session=127 sleep=5
09:35:36.628000000  000161 blocking_session=256 sleep=5
09:35:41.628000000  000166 blocking_session=18 sleep=5
09:35:46.629000000  000171 blocking_session=126 sleep=5
09:36:50.632000000  000235 blocking_session=368 sleep=64
09:36:55.633000000  000240 blocking_session=127 sleep=5
09:37:00.634000000  000245 blocking_session=256 sleep=5
09:37:05.634000000  000250 blocking_session=18 sleep=5
09:37:10.634000000  000255 blocking_session=126 sleep=5
09:39:18.644000000  000383 blocking_session=368 sleep=128
09:39:23.644000000  000388 blocking_session=127 sleep=5
09:39:28.645000000  000393 blocking_session=256 sleep=5
09:39:33.647000000  000398 blocking_session=18 sleep=5
09:39:38.651000000  000403 blocking_session=126 sleep=5
09:43:54.671000000  000659 blocking_session=368 sleep=256
09:43:59.672000000  000664 blocking_session=127 sleep=5
09:44:04.672000000  000669 blocking_session=256 sleep=5
09:44:09.672000000  000674 blocking_session=18 sleep=5
09:44:14.673000000  000679 blocking_session=126 sleep=5
09:52:46.709000000  001191 blocking_session=368 sleep=512
09:52:51.710000000  001196 blocking_session=127 sleep=5
09:52:56.710000000  001201 blocking_session=256 sleep=5
09:53:01.712000000  001206 blocking_session=18 sleep=5
09:53:06.712000000  001211 blocking_session=126 sleep=5
09:54:30.618000000  001295 blocking_session=368 sleep=84

--很明顯如果我檢測時間更長的話（我僅僅檢測1300秒），後面不是sleep ＝84。可以發現12c下與11.2.0.3的測試一樣。
偽碼如下：（來自）
iteration = 0
LOOP
  iteration++
  FOR i IN itl.FIRST..itl.LAST
  LOOP
    EXIT WHEN itl(i) IS FREE
    IF i <> itl.LAST
    THEN WAIT ON itl(i) FOR min(power(2,iteration-1),5) SECONDS
    ELSIF iteration <= 10
    THEN WAIT ON itl(i) FOR power(2,iteration-1) SECONDS
    ELSE WAIT ON itl(i) FOREVER
    END IF
  END LOOP
  EXIT WHEN free_itl_found
END LOOP