[Info-ingres] Error on database recovery

[Martin Bowes]

Hi All,

Fortunately this was found in a trial...

Ingres 11.0.0.

During a full database recovery rolling all journals we somewhat unexpectedly failed with the following in the errlog...

bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, ulx.c:300             ]: Wed Jan  8 08:57:14 2020 E_DM9049_UNKNOWN_EXCEPTION    An Unexpected Exception occurred in the DMF Facility, exception number 68196.
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, ulx.c:320             ]: Wed Jan  8 08:57:14 2020 E_UL0306_EXCEPTION    Unexpected exception number 68196 occurred, but unable to determine the type.
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:5273         ]: Wed Jan  8 08:57:14 2020 E_DM004A_INTERNAL_ERROR   Internal DMF error detected.
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:3526         ]: Wed Jan  8 08:57:14 2020 E_DM1306_RFP_APPLY_RECORD Error occurred attempting to apply rollforward record.
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO         LSN=(000000005B3CCEAD,00000000ECEB6643), COMP_LSN=(0000000000000000,0000000000000000), DBID=0x0585CD6D, XID=0x00005B3D355D8E
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO 0D
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO         MODIFY       Length:  2520  Flags: JOURNAL,NONREDO
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO             TABLE: (2512,0) NAME(bulk_master,ace)
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO             STRUCTURE: BTREE STATUS: UNIQUE,DUPLICATES
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO             MINPAGES: 0 MAXPAGES: 0 IFILL: 80 DFILL: 80 LFILL: 70
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO             BUCKETS: 32598  RELTUPS: 5036857
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO             Alloc: 4  Extend: 16  Page size: 8192 Type: 70  Name: (2, 371439)
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO                 LOCATION: ii_database
bba.ctsu.ox.ac.uk ::[II_JSP            , 33449     ,  00007f15084fa200, dmfrfp.c:14586        ]: Wed Jan  8 08:57:14 2020 E_DM1371_RFP_INFO Open Transaction 0x00005B3D355D8E0D with BT time 04-Jan-2020 15:29:53.73 for database ace_trexy_live redo 9 undo 0

etc...

With errors E_DM9C5F_DM2T_PURGEBUSY_WARN, E_DM9C53_DM2T_UNFIX_TCB, E_DM9330_DM2T_PURGE_TCB...

Examination of the audit trail shows that the relevant transaction:

Begin   : Transaction Id 00005b3d355d8e0d 04-Jan-2020 15:29:53.73           Username ace

  Alter   : Transaction Id 00005b3d355d8e0d Id (2512,0) Table [bulk_master                     ,ace                             ]

  Modify  : Transaction Id 00005b3d355d8e0d Id (2512,0) Table [bulk_master                     ,ace                             ]

  Drop/Destroy : Transaction Id 00005b3d355d8e0d Id (2512,5057)     Table [bulk_master_fields              ,ace

                     ]

    Location ii_database

  Create  : Transaction Id 00005b3d355d8e0d Id (2512,6099)      Table [bulk_master_fields              ,ace

                ]

    Location ii_database

Begin   : Transaction Id 00005b3d355d90f3 04-Jan-2020 15:30:07.56           Username ace

End     : Transaction Id 00005b3d355d90f3 04-Jan-2020 15:30:07.58

  Index   : Transaction Id 00005b3d355d8e0d  Id (2512,6099) Table [bulk_master                     ,ace

                ]

End     : Transaction Id 00005b3d355d8e0d 04-Jan-2020 15:30:08.26

The table alteration was to change a column from integer4 to integer1.

The audit trail says the transaction was well and truly closed

I've been unable to reproduce this with a small test case...and the thought of pushing a several hundred gig backup and journals to Actian isn't thrilling me...Has anyone seen anything like this? Got any ideas?

Martin Bowes


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.planetingres.org/pipermail/info-ingres/attachments/20200108/26022b60/attachment.html>