Conference orarep::nomahs::dec_data_distributor

266.0. "DDAL-E-PREMATEOT" by CHSR36::LCONS () Thu Feb 06 1997 04:01

Replication Option for Rdb V7.0-0

A customer is migrationg his RDB products to Version 7.

His data transfer is working fine for weeks.
But, after a RMU/CLOSE CLUSTER (I don't know if there is a relation),
RDB$CHANGES was corrupted. He has met no problem with disk space.
Below, you can find the log of the situation and the tables after the problem.
It seems that they have some duplicates in the RDB$CHANGES table.
What can i do to solve this problem ?



22:35:20  %DDAL-I-STADATTRM, starting data transfer/modification
22:36:30  %DDAL-I-PURGING_2, not purging RDB$CHANGES data rows because ...
          %DDAL-I-PURGING_3, ... DDAL$PURGE_KUDA_CASCADE is defined to be "NO"
22:36:30  %DDAL-I-ENDDATTRM, ending data transfer/modification

22:36:30  %DDAL-I-REPUPSTAT,    REPLICATION UPDATE STATISTICS

          %DDAL-I-NUMROWINS, number of rows inserted         =          0
          %DDAL-I-NUMROWUPD, number of rows updated          =          5
          %DDAL-I-NUMROWDEL, number of rows deleted          =          0
          %DDAL-I-TOTALIUDS, total inserts, updates, deletes =          5

          %DDAL-I-TOTALSRCT, source transactions applied =          5

22:36:30  %DDAL-I-COPY_EXIT, normal copy process termination

RMU/CLOSE CLUSTER
-----------------

22:52:01  %DDAL-I-ATTACHSDB, attaching to source database
KUDA_DB20:[KUDA_DB]KUDA_DATABASE.RDB
----- 30-JAN-1997 22:52:01.29 ----- Error           -------------------------
%RDB-F-SYS_REQUEST, error from system services request
-RDMS-F-DBNOTOPEN, database is not open for access


RMU/OPEN
--------

09:51:10  %DDAL-I-READTRDEF, reading the transfer definition from the transfer
database
09:51:13  %DDAL-I-ATTACHSDB, attaching to source database
KUDA_DB20:[KUDA_DB]KUDA_DATABASE.RDB
09:51:13  %DDAL-I-ATTACHTDB, attaching to target database
KUDA_CASCADE22:[KUDA_DB]KUDA_CASCADE
09:51:13  %DDAL-I-STADATTRM, starting data transfer/modification
----- 31-JAN-1997 09:53:03.41 ----- Error           -------------------------
%DDAL-E-PREMATEOT, END_OF_TRANSACTION encountered prematurely
-DDAL-I-TSER, in transaction with commit-time serial number: 5404027

 

10:50:28  %DDAL-I-READTRDEF, reading the transfer definition from the transfer
database
10:50:30  %DDAL-I-ATTACHSDB, attaching to source database
KUDA_DB20:[KUDA_DB]KUDA_DATABASE.RDB
10:50:33  %DDAL-I-ATTACHTDB, attaching to target database
KUDA_CASCADE22:[KUDA_DB]KUDA_CASCADE
10:50:34  %DDAL-I-STADATTRM, starting data transfer/modification

10:55:48  %DDAL-I-SRCROWSTA,            SOURCE DATA ROW ID'S

          %DDAL-I-HILOOPTB1,   Source Db_key   Target
          %DDAL-I-HILOOPTB2,   High     Low     Opr          Table name
          %DDAL-I-HILOOPTB3, -------- --------  ---  -------------------------
          %DDAL-I-TARGETOPR, 00740000 19B7001E  Upd  DIENSTLEISTUNGTEILNAHME
          %DDAL-I-TARGETOPR, 00740000 6EFE001C  Upd  DIENSTLEISTUNGTEILNAHME
----- 31-JAN-1997 10:55:49.60 ----- Error           -------------------------
%DDAL-E-PREMATEOT, END_OF_TRANSACTION encountered prematurely
-DDAL-I-TSER, in transaction with commit-time serial number: 5404027
 


SQL> select * from rdb$changes where RDB$TRANSACTION_TSER = 5404027;

 RDB$TRANSACTION_TID   RDB$TRANSACTION_SEQUENCE   RDB$TRANSACTION_TSER
   RDB$TRANSACTION_CHANGES
            78052836                          1                5404027
   ..I....DIENSTLEISTUNGTEILNAHME...7b..t.R........................*.)Qm....@.{
   >>...................*.)Qm....@.{l..........-Qm..K...)Qm....LQm.....@.{l....
   >>
   >>
   >>
   >>
   >>
   >>
   >>
--------------------
--------------------
            78052268                          1                5404027
   ..k....SYSTEMPARAMETER...>...V.'...Datenbank 6.0 Test  .S.b.r..........x'...
   >>
   >>
   >>
   >>
   >>
   >>
   >>
   >>
   >>
   >>
---------------------------------------
----------------------------------------
SQL> select * from rdb$vintage
cont> ;
 RDB$VINTAGE_TSER   RDB$VINTAGE_TIMESTAMP     RDBVMS$VINTAGE_TRANSFER_BUSY
RDBVMS$VINTAGE_TRANSFER_NAME
   RDBVMS$VINTAGE_TRANSFER_ID
      RDBVMS$VINTAGE_TRANSFER_NODE
         RDBVMS$VINTAGE_TRANSFER_ADDR
          5404025   30-JAN-1997 22:32:19.81   F
KUDA_CASCADE
                            1
      GDC141
      >>
      >>

            NULL
            >>
            >>
            >>
1 row selected

SQL> select RDB$TRANSACTION_TID,RDB$TRANSACTION_SEQUENCE,RDB$TRANSACTION_TSER
from rdb$changes where RDB$TRANSACTION_TSER >
cont> 5404025 order by RDB$TRANSACTION_TSER limit to 10 rows;
 RDB$TRANSACTION_TID   RDB$TRANSACTION_SEQUENCE   RDB$TRANSACTION_TSER
            78052840                          1                5404026    <---
            78052257                          1                5404026    <---
            78052836                          1                5404027    <---
            78052268                          1                5404027    <---
            78052841                          1                5404028
            78053468                          1                5404029
            78053469                          1                5404030
            78053471                          1                5404031
            78053476                          1                5404032
            78053477                          1                5404033
10 rows selected

   SQL> select * from rdb$changes_max_tser;
 RDB$TRANSACTION_TSER
              5409281
1 row selected

    
    Thank you for the fine detailed information.  As it happens we have
    been researching RDB$CHANGES corruption problems of a different kind
    but which might have a common root to the one you reported.  Would you
    please turn this into an official bug report.  I think if you were to
    try to log it as a Replication Option problem, the bug system would
    reject that today.  My manager is trying to get this situation
    corrected.  Instead, post it as an Rdb problem.  It actually is anyway. 
    Problems that have to do with corruption of the RDB$CHANGES table are
    problems within the Rdb executive.
    
    Meanwhile, the only solution your customer has is to REINITIALIZE the
    failed transfers and restart them.  I had considered the idea of
    deleting from RDB$CHANGES the duplicate entries, but they are not
    really duplicates.  The TSER numbers are being assigned to two
    different transactions (different transaction ids).

Thank you for you quick answer.
I'll open a bug.
Do you thing that this problem could be linked to RMU/CLOSE CLUSTER ?
The transfer was working fine for weeks and after the first CLOSE CLUSTER they
met the problem.
I cannot make a relation between RDB$CHANGES corrupted and CLOSE CLUSTER.

Louis

    
    It's possible that CLOSE CLUSTER triggered the problem.  I've forwarded
    your information to Ian Smith, who has been looking recently at the
    logic in the Rdb executive and how it handles writing to the
    RDB$CHANGES table.  Why the TSER values get duplicately assigned is the
    question that needs to be investigated.