​[20200108]線上建立索引失敗分析.txt

[20200108]線上建立索引失敗分析.txt

--//昨天上午使用online方式建立一個索引。遇到如下問題：
--//我是以sys使用者登入在伺服器登入執行的，報如下錯誤:
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 2
ORA-01031: insufficient privileges
ORA-06512: at line 13
ORA-00604: error occurred at recursive SQL level 2
ORA-01031: insufficient privileges
ORA-06512: at line 13
--//alert.log
Tue Jan 07 10:57:25 2020
online index (re)build cleanup: objn=151619 maxretry=2000 forever=0

--//索引已經建立完成，為什麼SYS_JOURNAL_151619 IOT表還在呢？
--//真心講我驚出一身汗......不過半個小時後我檢查發現SYS_JOURNAL_151619 IOT已經刪除,我建立的索引也一起消失(刪除).
--//不過我已經大概猜測問題在那裡,一定是安裝的所謂防水牆導致的問題.
--//很久以前我就在生產系統建立一個觸發器避免開發drop與truncate表，連結如下：
--// http://blog.itpub.net/267265/viewspace-1802941/ => [20150918]禁止使用者truncate以及drop表.txt
--//當時我就忽略2種情況，1.物化檢視 2.線上重建索引。
--//可以猜測我前面的問題一定是該防水牆忘記考慮線上重建索引的特殊情況有關，要建立一張IOT表。

1.環境:
> @ ver1
PORT_STRING         VERSION        BANNER
------------------- -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

2.測試分析：
--//模擬測試，其它環境沒有安裝該產品，只能找一個"無用"的小表測試看看。
> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
       208       8695 64142                    DEDICATED 83783     1200         70 alter system kill session '208,8695' immediate;

> @ 10046on 12
old   1: alter session set events '10046 trace name context forever, level &1'
new   1: alter session set events '10046 trace name context forever, level 12'

Session altered.

> CREATE INDEX XXXXXX_YYY.i_a_ZLXMID ON XXXXXX_YYY.A (ZLXMID) online;
CREATE INDEX XXXXXX_YYY.i_a_ZLXMID ON XXXXXX_YYY.A (ZLXMID) online
                                                 *
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 2
ORA-01031: insufficient privileges
ORA-06512: at line 13
ORA-00604: error occurred at recursive SQL level 2
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
ORA-01031: insufficient privileges
ORA-06512: at line 13

> @ 10046off
Session altered.

2.檢視轉儲檔案：
--//alert.log報如下錯誤：
Wed Jan 08 08:48:03 2020
online index (re)build cleanup: objn=151625 maxretry=2000 forever=0

--//檢查轉儲：
$ grep ^ERROR  /u01/app/oracle/diag/rdbms/zzzz/zzzz1/trace/zzzz1_ora_83783.trc
ERROR #140011057988888:err=1031 tim=1578444483672570
ERROR #140011057973304:err=1031 tim=1578444483672776
ERROR #140011057112832:err=604 tim=1578444483672960
ERROR #140011057597456:err=1031 tim=1578444483698394
ERROR #140011057973304:err=1031 tim=1578444483698569
ERROR #140011057112832:err=604 tim=1578444483698701
ERROR #140011057121184:err=604 tim=1578444483699455


--//檢索#140011057121184,對應執行語句。
=====================
PARSING IN CURSOR #140011057121184 len=66 dep=0 uid=5 oct=9 lid=5 tim=1578444482548443 hv=241921903 ad='1090dd180' sqlid='az8dh0w76qvvg'
CREATE INDEX XXXXXX_YYY.i_a_ZLXMID ON XXXXXX_YYY.A (ZLXMID) online
END OF STMT
PARSE #140011057121184:c=4000,e=4217,p=0,cr=4,cu=0,mis=1,r=0,dep=0,og=1,plh=1230848158,tim=1578444482548442
=====================
...

--//檢索#140011057112832,注意看下劃線,對應online建表時的建立的IOT表的drop：
=====================
PARSING IN CURSOR #140011057112832 len=50 dep=1 uid=0 oct=12 lid=0 tim=1578444482883130 hv=1150550614 ad='7f56dd7f1b58' sqlid='a94zrq12980kq'
drop table "XXXXXX_YYY"."SYS_JOURNAL_151625" purge
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
END OF STMT
PARSE #140011057112832:c=0,e=288,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1578444482883129
=====================
...

--//檢索#140011057112832.執行的應該是下劃線內容。繼續反推。
=====================
PARSING IN CURSOR #140011057973304 len=442 dep=2 uid=131 oct=47 lid=131 tim=1578444483665920 hv=3999344136 ad='1328adbc70' sqlid='14tjukmr629h8'
declare
  -- local variables here
     PRIVS_ERROR exception;         --raise error,if rule exception,will trigger privs_error
     pragma exception_init(PRIVS_ERROR,-1031);
begin
   if upper(ora_dict_obj_name) in('SCHEDULER$_PROGRAM_ARG','SCHEDULER$_JOB_ARG') then
      null;
   else
      execute immediate 'begin topacl.opacl; end;';
      ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
   end if;
exception
   when PRIVS_ERROR then
     raise;
   when others then
     null;
end ddltrigger;
END OF STMT
PARSE #140011057973304:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,plh=0,tim=1578444483665919
=====================

--//檢索#140011057597456.
=====================
PARSING IN CURSOR #140011057597456 len=24 dep=3 uid=131 oct=47 lid=131 tim=1578444483696683 hv=3607719169 ad='bc6b6ae8' sqlid='5rnd92rbhkv81'
begin topacl.opacl; end;
~~~~~~~~~~~~~~~~~~~~~~~~~~
END OF STMT
PARSE #140011057597456:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=0,dep=3,og=1,plh=0,tim=1578444483696682
.....

--//檢索#140011057112832
=====================
PARSING IN CURSOR #140011057112832 len=51 dep=1 uid=0 oct=3 lid=0 tim=1578444482553998 hv=1523794037 ad='a9c9c4a0' sqlid='b1wc53ddd6h3p'
select audit$,options from procedure$ where obj#=:1
END OF STMT
PARSE #140011057112832:c=0,e=146,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1578444482553996
=====================

--//檢索#140011057973304,看上面已有。

--//檢索#140011057988888
=====================
PARSING IN CURSOR #140011057988888 len=24 dep=3 uid=131 oct=47 lid=131 tim=1578444483666187 hv=3607719169 ad='bc6b6ae8' sqlid='5rnd92rbhkv81'
begin topacl.opacl; end;
END OF STMT
PARSE #140011057988888:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=3,og=1,plh=0,tim=1578444483666186
=====================

--//最後定位在這裡,實際上看這段程式碼就能定位問題，：
=====================
PARSING IN CURSOR #140011029948560 len=264 dep=4 uid=131 oct=47 lid=131 tim=1578444483672031 hv=3329427850 ad='1c3004660' sqlid='fnvv73z3762ca'
begin
              if ( NVL(SYS_CONTEXT('USERENV','IP_ADDRESS'),'127.0.0.1') in ('192.168.xxx.xxx','192.168.yyy.yyy' ....) ) then
                 topacl.evalresult:=true;
              else
                 topacl.evalresult:=false;
              end if;
            end;
END OF STMT
PARSE #140011029948560:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=4,og=1,plh=0,tim=1578444483672030
EXEC #140011029948560:c=0,e=49,p=0,cr=0,cu=0,mis=0,r=1,dep=4,og=1,plh=0,tim=1578444483672137
CLOSE #140011029948560:c=0,e=1,dep=4,type=3,tim=1578444483672170
CLOSE #140011057124224:c=0,e=2,dep=4,type=3,tim=1578444483672216
EXEC #140011057988888:c=4000,e=6315,p=5,cr=13,cu=0,mis=0,r=0,dep=3,og=1,plh=0,tim=1578444483672539
ERROR #140011057988888:err=1031 tim=1578444483672570
CLOSE #140011057988888:c=0,e=13,dep=3,type=0,tim=1578444483672716
EXEC #140011057973304:c=4000,e=6656,p=5,cr=13,cu=2,mis=0,r=0,dep=2,og=1,plh=0,tim=1578444483672758
ERROR #140011057973304:err=1031 tim=1578444483672776
CLOSE #140011057973304:c=0,e=20,dep=2,type=1,tim=1578444483672860
EXEC #140011057112832:c=682897,e=789725,p=79,cr=1533,cu=44,mis=0,r=0,dep=1,og=4,plh=0,tim=1578444483672905
ERROR #140011057112832:err=604 tim=1578444483672960
CLOSE #140011057112832:c=0,e=3,dep=1,type=0,tim=1578444483673629
online index (re)build cleanup: objn=151625 maxretry=2000 forever=0
=====================

> select NVL(SYS_CONTEXT('USERENV','IP_ADDRESS'),'127.0.0.1') from dual ;
NVL(SYS_CONTEXT('USERENV','IP_ADDRESS'),'127.0.0.1')
----------------------------------------------------
127.0.0.1

--//僅僅IP在特定範圍內的主機才可能執行這樣的操作，昏竟然把127.0.0.1排除在外，而且開發明顯忽略一個因素online建立索引結束要有1個drop的操作。
--//也就是這樣的維護操作僅僅特定的IP地址發起才能完成。

--//實際上如果這時執行刪除索引操作會報：
ORA-08104: this index object 151625 is being online built or rebuilt。

--//等一段時間SYS_JOURNAL_151625 IOT表就刪除了，對應建立的索引也消失了。

3.找一個在特定範圍內IP的主機測試：
> CREATE INDEX XXXXXX_YYY.i_a_ZLXMID ON XXXXXX_YYY.A (ZLXMID) online;
Index created.

> drop index XXXXXX_YYY.i_a_ZLXMID ;
Index dropped.

--//完全沒有問題。這樣的防水牆有點那個，特定的IP如果是內部人員很容易獲得,僅僅一個IP再知道口令，就可以做....
--//很明顯這樣的安全產品測試非常不嚴謹，純粹騙人的東西。

--//如果沒有網路連線，無法幹活了嗎？我們自己不懂，實施人員不會不知道嗎？

--//順便說一下上的這個東西，CPU消耗很大，我們這裡符合至少增加40%，如果你的應用是頻繁登入與退出，消耗更大。