转载

增量数据丢失的原因分析（二)

今天处理的一个问题比较绕，花费了我不少的时间来分析，当然最后发现是拜拜忙碌一场空,还是有一些历史原因。
大体的环境情况如下，有一台线上库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的库最近做了灾难切换，结果防火墙权限的地方出现了疏漏导致。
明白了这点之后修复就会很自然了。
而通过这个例子可以看出很多问题还是有很多的干扰信息，而且这类历史问题在处理的时候还是需要多了解一些环境的情况和实现方式，对于问题分析还是大有裨益。

正文到此结束