增量資料丟失的原因分析（二)

今天處理的一個問題比較繞，花費了我不少的時間來分析，當然最後發現是拜拜忙碌一場空,還是有一些歷史原因。
大體的環境情況如下，有一臺線上庫OLTP,其中也有會自己的儲存過程，job,結合起來處理一些資料，當然作為統計系統而言，目前有兩套統計系統STATDB1，STATDB2，都喲裇相關業務的劃分，兩者會有一些交集。
開發的同學找到我說，統計庫STATDB2 有一張表，發現最近兩天的資料沒有更新，當然開發的同學無從查起，就想讓我幫忙看看，現在還是流行逆性工程，所以這個工作就義不容辭交給了我。
我大體梳理了一下，這個表的資料是每天會更新一次，資料庫裡存在一個儲存過程，裡面是資料增量的一些邏輯，然後透過scheduler job來排程。
原以為看看儲存過程，簡單理一理邏輯就可以把資料補上了，但是一看自己也被驚到了，裡面的邏輯竟然一環扣一環，大體是下面的情況。


根據STATDB2裡面的儲存過程的表述，表TABLE的資料會參考STATDB1裡面的表TABLE的資料，兩者是透過db link依賴。
而STATDB1裡面的表TABLE資料是依賴於OLTP的資料，也就是說OLTP裡面的資料才是真正的源頭，流經STATDB1，STATDB2
看起來還是蠻有挑戰，所以我就一層一層的開始解析，但是發現琢磨了一番，自己是實在看不明白了，因為資料的流動情況我自己都說服不了自己，感覺缺少了一些東西。
STATDB2的儲存過程是下面的內容，透過一個cursor來從STATDB1裡面取得前一天的增量資料，然後插入STATDB2
cursor c1 is
    select *
      from tlbb.TEST_USER_CENTER@db84
       where FIRST_LOGIN >= trunc(sysdate, 'dd') - 1
       and FIRST_LOGIN < trunc(sysdate, 'dd');
但是我一路分析過來，到了STATDB1裡面，發現STATDB1裡面的表TABLE竟然沒有增量資料，我把範圍調整為了300天，發現還是沒有任何資料。
SQL> select count(*)
          from tlbb.TEST_USER_CENTER
           where FIRST_LOGIN >= trunc(sysdate, 'dd') - 300
           and FIRST_LOGIN < trunc(sysdate, 'dd');
  COUNT(*)
----------
         0
而STATDB1裡的表確實有不少的資料，隨機取了幾條，發現都是8年以前的了。
SQL> select first_login from tlbb.TEST_USER_CENTER where rownum<30;
FIRST_LOGIN
-------------------
2007-03-15 11:31:02
2007-03-15 11:31:03
而在STATDB2裡面查詢最近的增量資料，資料情況如下：
SQL> select count(1),to_char(first_login,'yyyy-mm-dd') from TEST_USER_CENTER where first_login>=to_date('2016-04-10','yyyy-mm-dd') and first_login<to_date('2016-04-23','yyyy-mm-dd') group by to_char(first_login,'yyyy-mm-dd') order by 2;
  COUNT(1) TO_CHAR(FI
---------- ----------
      5944 2016-04-10
      5300 2016-04-11
      6012 2016-04-12
      5196 2016-04-13
      5297 2016-04-14
      5428 2016-04-15
      6561 2016-04-16
      6260 2016-04-17
      5076 2016-04-18
所以自己就犯難了，這增量資料到底是哪裡來的。
而且反覆核對，發現STATDB2裡的JOB是早上6點觸發，而實際的資料變更是在3點左右，這個也是分析問題的關鍵，我是透過表資料變更從dba_tab_modification裡面得到的論證。
表裡的資料最新的變更是在4月19日的早上3點半。
 INSERTS        UPDATES   DELETES CHG_TIMESTAMP        TRU DROP_SEGMENTS  
-------- -------------- --------- -------------------- --- -------------  
  207346       19540770         0 2016-04-19 03:30:19  NO              0  
所以看來這個job實際上沒有產生任何的作用，當然帶著嚴謹的態度，我把這個使用者下所有的JOB都看了一遍，重點檢視了2點以後的JOB的變更，發現依舊沒有任何線索。
最後還是STATDB1裡面的JOB讓我吃了一劑定心丸。這個JOB雖然存在，但是沒有做任何實質性的操作，是個dummy的job.
BEGIN
dbms_scheduler.create_job('"LOAD_TEST_USER_CENTER"',
job_type=>'PLSQL_BLOCK', job_action=>
'begin
 -- TEST.LOAD_TEST_USER_CENTER_PDAY;
 dbms_output.put_line('''');
end;'
, number_of_arguments=>0,
start_date=>TO_TIMESTAMP_TZ('24-NOV-2009 07.15.59.801866000 PM +08:00','DD-MON-RRRR HH.MI.SSXFF AM T
ZR','NLS_DATE_LANGUAGE=english'), repeat_interval=>
'FREQ=DAILY;BYHOUR=6;BYMINUTE=0;BYSECOND=0'
, end_date=>NULL,
....
所以我再次聯絡了開發的同學，讓他們幫忙梳理一下是否有自定義的JOB，可能會觸發資料的增量變化，我這邊能夠很肯定的證明，資料的增量變更不是在統計庫中完成的。
當然在稍後和同事進行了瞭解，原來這個資料的增量變化是從OLTP主動向STATDB2推送的。
於是我在OLTP的庫中檢視了最近的排程情況，發現最近兩天確實是執行失敗的。
SQL>select log_date,owner,job_name,status,ADDITIONAL_INFO from DBA_SCHEDULER_JOB_LOG where log_date>sysdate-10 and owner='TEST' and job_name like '%USER%' ORDER BY 1
LOG_DATE                                 OWNER                          JOB_NAME             STATUS                         ADDITIONAL
---------------------------------------- ------------------------------ -------------------- ------------------------------ ----------
12-APR-16 03.28.02.318938 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
13-APR-16 03.27.38.337060 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
14-APR-16 03.27.05.682359 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
15-APR-16 03.26.53.582698 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
16-APR-16 03.27.01.285333 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
17-APR-16 03.27.12.866612 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
18-APR-16 03.27.04.888449 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
19-APR-16 03.27.53.720007 AM +08:00      TEST                           SYN_USERCENTER       SUCCEEDED
20-APR-16 02.19.59.855840 AM +08:00      TEST                           SYN_USERCENTER       FAILED
21-APR-16 02.20.00.312195 AM +08:00      TEST                           SYN_USERCENTER       FAILED
而失敗的原因，是否有一些方法查到蛛絲馬跡。可以檢視DBA_SCHEDULER_JOB_RUN_DETAILS找到對應的錯誤資訊。
 ORA-00604: error occurred at recursive SQL level 2
 ORA-12170: TNS:Connect timeout occurred            
有了錯誤資訊，就有了問題分析的方向，很快發現是防火牆的許可權不足導致OLTP庫的db link連線失敗導致增量資料問題。而進一步分析問題，為什麼平時防火牆沒有問題，最近有了，因為OLTP的庫最近做了災難切換，結果防火牆許可權的地方出現了疏漏導致。
明白了這點之後修復就會很自然了。
而透過這個例子可以看出很多問題還是有很多的干擾資訊，而且這類歷史問題在處理的時候還是需要多瞭解一些環境的情況和實現方式，對於問題分析還是大有裨益。