ITL Waits – Changes in Recent Releases (script)

A reader of this blog, Paresh, asked me how I was able to find out the logic behind ITL waits without having access to Oracle code. My reply was: I wrote a test case that reproduce ITL waits and a piece of code that monitors them.

Since other readers might be interested, here is the shell script I wrote. Notice that it takes four parameters as input: user name, password, SID, and how long it has to wait in the monitoring phase.

#!/bin/sh

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

#
# Setup test environment
#

sqlplus -s $user/$password@$sid < $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 < l_blocking_session_prev 
         OR l_blocking_session_prev IS NULL
         OR i = c_iterations 
      THEN
        dbms_output.put_line(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 <

The outputs I got are the following:

• 10.2.0.4

000000 blocking_session=136 sleep=0
000005 blocking_session=136 sleep=6
000010 blocking_session=140 sleep=3
000015 blocking_session=152 sleep=6
000020 blocking_session=159 sleep=6
029995 blocking_session=158 sleep=29979

• 10.2.0.5

000000 blocking_session=158 sleep=0
000001 blocking_session=158 sleep=0
000002 blocking_session=152 sleep=2
000003 blocking_session=141 sleep=0
000004 blocking_session=148 sleep=0
000005 blocking_session=140 sleep=3
000007 blocking_session=158 sleep=0
000009 blocking_session=152 sleep=3
000011 blocking_session=141 sleep=3
000013 blocking_session=148 sleep=0
000015 blocking_session=140 sleep=3
000019 blocking_session=158 sleep=3
000023 blocking_session=152 sleep=6
000027 blocking_session=141 sleep=3
000031 blocking_session=148 sleep=3
000035 blocking_session=140 sleep=6
000040 blocking_session=158 sleep=3
000045 blocking_session=152 sleep=6
000050 blocking_session=141 sleep=6
000054 blocking_session=148 sleep=3
000062 blocking_session=140 sleep=9
000067 blocking_session=158 sleep=6
000072 blocking_session=152 sleep=3
000077 blocking_session=141 sleep=6
000082 blocking_session=148 sleep=6
000098 blocking_session=140 sleep=15
000103 blocking_session=158 sleep=6
000108 blocking_session=152 sleep=3
000113 blocking_session=141 sleep=6
000118 blocking_session=148 sleep=6
000149 blocking_session=140 sleep=30
000154 blocking_session=158 sleep=6
000159 blocking_session=152 sleep=6
000164 blocking_session=141 sleep=3
000169 blocking_session=148 sleep=6
000232 blocking_session=140 sleep=63
000237 blocking_session=158 sleep=6
000242 blocking_session=152 sleep=6
000247 blocking_session=141 sleep=3
000252 blocking_session=148 sleep=6
000379 blocking_session=140 sleep=129
000383 blocking_session=158 sleep=3
000388 blocking_session=152 sleep=6
000393 blocking_session=141 sleep=6
000398 blocking_session=148 sleep=3
000651 blocking_session=140 sleep=258
000656 blocking_session=158 sleep=3
000661 blocking_session=152 sleep=6
000666 blocking_session=141 sleep=6
000671 blocking_session=148 sleep=3
001177 blocking_session=140 sleep=514
001182 blocking_session=158 sleep=6
001187 blocking_session=152 sleep=3
001192 blocking_session=141 sleep=6
001197 blocking_session=148 sleep=6
014218 blocking_session=140 sleep=13184
029995 blocking_session=140 sleep=28788

• 11.1.0.6

000000 blocking_session=146 sleep=0
000005 blocking_session=146 sleep=5
000010 blocking_session=129 sleep=5
000015 blocking_session=141 sleep=5
000020 blocking_session=126 sleep=5
029995 blocking_session=132 sleep=29978

• 11.1.0.7

000000 blocking_session=136 sleep=0
000005 blocking_session=136 sleep=5
000010 blocking_session=140 sleep=5
000015 blocking_session=132 sleep=5
000020 blocking_session=131 sleep=5
029995 blocking_session=134 sleep=29979

• 11.2.0.1

000000 blocking_session=131 sleep=0
000001 blocking_session=131 sleep=1
000002 blocking_session=133 sleep=1
000003 blocking_session=196 sleep=1
000004 blocking_session=67 sleep=1
000005 blocking_session=69 sleep=1
000007 blocking_session=131 sleep=2
000009 blocking_session=133 sleep=2
000011 blocking_session=196 sleep=2
000013 blocking_session=67 sleep=2
000015 blocking_session=69 sleep=2
000019 blocking_session=131 sleep=4
000023 blocking_session=133 sleep=4
000027 blocking_session=196 sleep=4
000031 blocking_session=67 sleep=4
000035 blocking_session=69 sleep=4
000040 blocking_session=131 sleep=5
000045 blocking_session=133 sleep=5
000050 blocking_session=196 sleep=5
000054 blocking_session=67 sleep=5
000062 blocking_session=69 sleep=8
000067 blocking_session=131 sleep=5
000072 blocking_session=133 sleep=5
000077 blocking_session=196 sleep=5
000082 blocking_session=67 sleep=5
000098 blocking_session=69 sleep=16
000103 blocking_session=131 sleep=5
000108 blocking_session=133 sleep=5
000113 blocking_session=196 sleep=5
000118 blocking_session=67 sleep=5
000149 blocking_session=69 sleep=32
000154 blocking_session=131 sleep=5
000159 blocking_session=133 sleep=5
000164 blocking_session=196 sleep=5
000169 blocking_session=67 sleep=5
000232 blocking_session=69 sleep=64
000237 blocking_session=131 sleep=5
000242 blocking_session=133 sleep=5
000247 blocking_session=196 sleep=5
000252 blocking_session=67 sleep=5
000379 blocking_session=69 sleep=128
000383 blocking_session=131 sleep=5
000388 blocking_session=133 sleep=5
000393 blocking_session=196 sleep=5
000398 blocking_session=67 sleep=5
000651 blocking_session=69 sleep=256
000656 blocking_session=131 sleep=5
000661 blocking_session=133 sleep=5
000666 blocking_session=196 sleep=5
000671 blocking_session=67 sleep=5
001177 blocking_session=69 sleep=512
001182 blocking_session=131 sleep=5
001187 blocking_session=133 sleep=5
001192 blocking_session=196 sleep=5
001196 blocking_session=67 sleep=5
029995 blocking_session=69 sleep=28787