ablog

不器用で落着きのない技術者のメモ

セグメントアドバイザ(AUTO_SPACE_ADVISOR_JOB)でDMLがロックされていた件

夜間バッチが終了しないので、セッション情報を見ると、別のセッションにブロックされている。

SQL> r
  1  select proc.spid ospid,
  2     ses.blocking_session block,
  3     ses.sid,
  4     ses.serial#,
  5     ses.sql_id,
  6     substr(ses.username,1,10) username,
  7     ses.status,
  8     lk.type,
  9     lk.lmode,
 10     lk.request,
 11     id1,
 12     id2,
 13     to_char(lk.ctime/60, '9990.9') lock_time,
 14     sql.hash_value,
 15     sql.address,
 16     sql.plan_hash_value,
 17     substr(sql_text,1,20) sql,
 18     substr(ses.machine,1,10) machine,
 19     substr(ses.osuser,1,10) osuser,
 20     substr(ses.program,1,10) program
 21  from v$session ses, v$process proc, v$sql sql, v$lock lk
 22     where ses.type = 'USER'
 23             and ses.paddr = proc.addr
 24             and ses.sid = lk.sid(+)
 25             and ses.sql_address = sql.address(+)
 26* order by username, machine, osuser, program

OSPID  BLOCK    SID SERIAL# USERNAME   STATUS   TY LMODE REQUEST LOCK_TIME  SQL                  
----- ------ ------ ------- ---------- -------- -- ----- ------- ---------- -------------------- 
5059     210    182   32833 SCOTT      ACTIVE   TM     1       0   483.4    INSERT /*+ PARALLEL( 
5059     210    182   32833 SCOTT      ACTIVE   TM     1       0   483.4    INSERT /*+ PARALLEL( 
5059     210    182   32833 SCOTT      ACTIVE   TM     1       0   483.4    INSERT /*+ PARALLEL( 
5059     210    182   32833 SCOTT      ACTIVE   TM     4       0   483.4    INSERT /*+ PARALLEL( 
5059     210    182   32833 SCOTT      ACTIVE   TM     4       0   483.4    INSERT /*+ PARALLEL( 
5059     210    182   32833 SCOTT      ACTIVE   TM     4       0   483.4    INSERT /*+ PARALLEL( 

...

8040            210   13879 SYS        ACTIVE   TM     3       0   471.1    alter index ... modify subpartition ... shrink space CHECK  
8040            210   13879 SYS        ACTIVE   TM     3       0   471.1    alter index ... modify subpartition ... shrink space CHECK 

OS プロセスを確認してみる。

$ ps uw -p 8040
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
oracle    8040  0.0 15.6 2252868 483696 ?      Ss   05:00   0:15 ora_j001_orcl

セッションを kill してみると、

SQL> alter system kill session '210,13879';

System altered.

ブロックしていたセッションがなくなって、待機していた処理が走りだした。

トレースファイルを見てみると、

$ pwd
/opt/app/oracle/admin/orcl/bdump
$ cat orcl_j001_8040.trc 
/opt/app/oracle/admin/orcl/bdump/orcl_j001_8040.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /opt/app/oracle/product/10.2.0/db_1
System name:    Linux
Node name:      ...
Release:        2.6.18-128.el5
Version:        #1 SMP Wed Jan 21 10:41:14 EST 2009
Machine:        x86_64
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 21
Unix process pid: 8040, image: oracle@... (J001)

*** 2010-06-12 14:16:52.325
*** ACTION NAME:(AUTO_SPACE_ADVISOR_JOB) 2010-06-12 14:16:52.324
*** MODULE NAME:(DBMS_SCHEDULER) 2010-06-12 14:16:52.324
*** SERVICE NAME:(SYS$USERS) 2010-06-12 14:16:52.324
*** CLIENT ID:() 2010-06-12 14:16:52.324
*** SESSION ID:(210.13879) 2010-06-12 14:16:52.324
error 28 in job queue process
ORA-00028: your session has been killed
OPIRIP: Uncaught error 28. Error stack:
ORA-00028: your session has been killed
ORA-00028: your session has been killed

セグメントアドバイザ(AUTO_SPACE_ADVISOR_JOB)が犯人だったようだ。
デフォルトで、SYS.MAINTENANCE_WINDOW_GROUP でスケジューリングされているので、平日の 22:00 以降、土曜日の 0:00 以降に実行される。

オフりたい場合は、

SQL> exec dbms_scheduler.disable('SYS.AUTO_SPACE_ADVISOR_JOB');

でおk。