Clients still hitting Informix Online 5.05.UC11 tbtape timestamp bug

One of our clients was experiencing an issue with their production Informix Online 5.05.UC11 databases running on SCO Unix 3.24 and we had the opportunity to help them a couple of weeks ago.  It is surprising how many old installations of Informix you find still running out there after all these years, as Informix 5.05 was released in 1995.  The problem was that the Informix tbtape archives finished in about a minute, much more quickly than normal. There were no errors reported by tbtape during the archive or a restore.  A database restored from one of these backups was useless. The tbtape backup utility depends on internal page time stamps in order to know what pages need to be backed up.  When these timestamps grow past the limit of 2,147,483,647, the timestamp wraps and goes negative.  In Online 5.05, tbtape did not know what to do with negative numbers so the backup was invalid even if no errors were returned.  This bug was corrected in Online 5.07.   Unfortunately the client is running Online 5.05 and cannot easily upgrade.I was able to identify this known bug as the cause of the problem and provide the client with a script for use in predicting when the problem will occur again.

The negative timestamps may be seen by running the Informix utility “tbcheck -pr” against the system reserved pages.  These pages contain control and tracking information for the database engine.  A portion of the output follows:

Validating INFORMIX-OnLine reserved pages – PAGE_1CKPT & PAGE_2CKPT

Using check point page PAGE_1CKPT.

Time stamp of checkpoint             -1786155761

Time of checkpoint                                  07/18/11 10:46:27

Physical log begin address                     101f8c

Physical log size                                      7500

Physical log position at Ckpt                9a3

Logical log unique identifier               7635

Logical log position at Ckpt                1238018

DBSpace descriptor page                    100004

Chunk descriptor page                        100007

Mirror chunk descriptor page           100008

. . .

Validating INFORMIX-OnLine reserved pages – PAGE_1ARCH & PAGE_2ARCH

Using archive page PAGE_2ARCH.

Archive Level                                       0

Real Time Archive Began                  04/15/11 05:44:59

Time Stamp Archive Began     2147240892

Logical Log Unique Id                      6650

Logical Log Position                         807018

The output shows a negative time stamp for the checkpoint reserved page as well as an archive page time stamp that is approaching the limit.  (Note also that the last successful archive was completed on April 15, over 3 months ago.)  The only way to reset these time stamps is to reinitialize the instance.  This means unloading the data, wiping out and recreating the instance, and reloading the database.  The client currently has procedures in place for performing this process.  The script that I provided will run “tbcheck -pr” and output a message for any timestamps that are negative or approaching the limit.  The client will now be able to determine when the instance needs to be recreated in order to avoid the bug.

Once initialized, the time stamps for the checkpoint and archive pages were as follows:

Validating INFORMIX-OnLine reserved pages – PAGE_1CKPT & PAGE_2CKPT

Using check point page PAGE_1CKPT.

Time stamp of checkpoint       18910754
Time of checkpoint                            07/18/11 13:10:09
Physical log begin address               101f8c
Physical log size                                  7500
Physical log position at Ckpt           f1c
Logical log unique identifier           1
Logical log position at Ckpt             aa018
DBSpace descriptor page                 100004
Chunk descriptor page                     100007
Mirror chunk descriptor page        100008
. . .
Validating INFORMIX-OnLine reserved pages – PAGE_1ARCH & PAGE_2ARCH

Using archive page PAGE_1ARCH.

Archive Level                                    0
Real Time Archive Began               07/18/11 13:07:27
Time Stamp Archive Began    18910265
Logical Log Unique Id                     1
Logical Log Position                        a9018

The client is currently in the process of upgrading the Informix software on the equipment to Informix 11.50.  The time stamp problem was fixed many versions ago, and the backup process in the newer versions (5.07 and after) no longer has any problem related to old time stamps.