Load trans logs: Specified file 'dump device' is out of sequence.

[thorstenhenrici]

Hello,

im running into trouble while doing a Point-in-Time Recovery of a ASE user database:

Specified file 'dump device' is out of sequence. Current time stamp is May  7
2014 11:11:02:356PM while dump was from May  8 2014 10:14:44:203AM.

Here's what I do:

1. Backup database BBK with HP Dataprotector 8.1:

[Normal] From: OB2BAR@brosapbbk "BBK"  Time: 08.05.2014 09:22:49
Starting OB2BAR Backup: brosapbbk-restore:BBK:BBK<1:0> [DATABASE] "Sybase"

[Normal] From: OB2BAR@brosapbbk "BBK"  Time: 08.05.2014 09:36:46
Backup Profile:

  Run Time ........... 0:13:57
  Backup Speed ....... 93,09 MB/s

[Normal] From: OB2BAR@brosapbbk "BBK"  Time: 08.05.2014 09:36:46
Completed OB2BAR Backup: brosapbbk-restore:BBK:BBK<1:0> [DATABASE] "Sybase"

2. Backup transaction logs with HP Dataprotector 8.1:

[Normal] From: OB2BAR@brosapbbk "BBK"  Time: 08.05.2014 10:16:57
Starting OB2BAR Backup: brosapbbk-restore:BBK:BBK<1:0> [TRAN] "Sybase"

[Normal] From: OB2BAR@brosapbbk "BBK"  Time: 08.05.2014 10:16:59
Backup Profile:

  Run Time ........... 0:00:02
  Backup Speed ....... 0,03 MB/s

[Normal] From: OB2BAR@brosapbbk "BBK"  Time: 08.05.2014 10:16:59
Completed OB2BAR Backup: brosapbbk-restore:BBK:BBK<1:0> [TRAN] "Sybase"

3. Drop database BBK

isql> drop database BBK

4. Create database BBK

isql> create database BBK on BBK_data_001 = "48640M", BBK_data_002 = "17920M", BBK_data_003 = "17920M", BBK_data_004 = "17920M", BBK_data_005 = "17920M" log on BBK_log_001 = "8192M", BBK_log_002 = "8192M" for load

5. Load Database from Backup

load database BBK from "ob2syb::2014/05/08-35::BBK::BBK"
go

Backup Server session id is: 49. Use this value when executing the
'sp_volchanged' system stored procedure after fulfilling any volume change
request from the Backup Server.

Backup Server: 4.125.1.1: Archive API information for
device='ob2syb::2014/05/08-35::BBK::BBK::000': Vendor application name=Data
Protector A.08.10, Library version=221, Message=[Normal] From: OB2BAR@brosapbbk
"BBK"  Time: 05/09/14 09:55:35  Starting OB2BAR Restore:
brosapbbk-restore:BBK:BBK<1:0> [DATABASE] "Sybase"  .
Backup Server: 6.28.1.1: Dumpfile name 'BBK14128083AF    ' section number 1
mounted on byte stream 'ob2syb::2014/05/08-35::BBK::BBK::000'

Backup Server: 4.188.1.1: Database BBK: 226512560 kilobytes (100%) LOADED.

Backup Server: 4.125.1.1: Archive API information for
device='ob2syb::2014/05/08-35::BBK::BBK::000': Vendor application name=Data
Protector A.08.10, Library version=221, Message=[Normal] From: OB2BAR@brosapbbk
"BBK"  Time: 05/09/14 11:26:26  Completed OB2BAR Restore:
brosapbbk-restore:BBK:BBK<1:0> [DATABASE] "Sybase"  .

Backup Server: 3.42.1.1: LOAD is complete (database BBK).

All dumped pages have been loaded. ASE is now clearing pages above page
14155776, which were not present in the database just loaded.

Processed 896 allocation unit(s) out of 896 units (allocation page 14384896).
100% completed.

ASE has finished clearing database pages.
Started estimating recovery log boundaries for database 'BBK'.
Database 'BBK', checkpoint=(10495883, 49), first=(10495883, 49), last=(10495895,
45).

Completed estimating recovery log boundaries for database 'BBK'.
Started ANALYSIS pass for database 'BBK'.
Completed ANALYSIS pass for database 'BBK'.
Started REDO pass for database 'BBK'. The total number of log records to process
is 1652.
Redo pass of recovery has processed 171 committed and 0 aborted transactions.
Completed REDO pass for database 'BBK'.
Use the ONLINE DATABASE command to bring this database online; ASE will not
bring it online automatically.

6. Load Trans Logs from Backup

load tran BBK from "ob2syb::2014/05/08-53::BBK::BBK" with until_time="May 08, 2014 09:35:00"
go

Backup Server session id is: 36. Use this value when executing the
'sp_volchanged' system stored procedure after fulfilling any volume change
request from the Backup Server.
Backup Server: 4.132.1.1: Attempting to open byte stream device:
'ob2syb::2014/05/08-53::BBK::BBK::000'
Backup Server: 4.125.1.1: Archive API information for
device='ob2syb::2014/05/08-53::BBK::BBK::000': Vendor application name=Data
Protector A.08.10, Library version=221, Message=[Normal] From: OB2BAR@brosapbbk
"BBK"  Time: 05/09/14 11:43:17  Starting OB2BAR Restore:
brosapbbk-restore:BBK:BBK<1:0> [TRAN] "Sybase"  .
Backup Server: 6.28.1.1: Dumpfile name 'BBK141280907A    ' section number 1
mounted on byte stream 'ob2syb::2014/05/08-53::BBK::BBK::000'
Msg 4305, Level 16, State 1:

Server 'BBK', Line 6:

Specified file 'dump device' is out of sequence. Current time stamp is May  7
2014 11:11:02:356PM while dump was from May  8 2014 10:14:44:203AM.

I understand, that there seem to be missing transaction logs. Thing is that I can't imagine why. The database backup was taken right before the backup of the trans logs. So where does the gap come from.

A lot of thanks for your help in this !

Best Regards,

Thorsten

[thorstenhenrici]

Hello Marc,

yes, this is what I was thinking too, but there is no indication that another database backup ran the night before. I also have no clue why it tells the current time as "May  7 2014 11:11:02:356PM".

A case with an identical description to the one above was send over to HP.

I'll check on Ionut's advise now. Thanks for your Input on this !

[Former Member · Accepted solution]

Dear Mr. Thorsten,

Were the backup configuration and restore activities performed according to the following notes:

1585981  SYB: Ensuring Recoverability for Sybase ASE    

1588316  SYB: Configure automatic database and log backups

1611715  SYB: How to restore a Sybase ASE database server (Windows)

1618817  SYB: How to restore a Sybase ASE database server (UNIX)

1887068  SYB: Using external backup and restore with SAP Sybase ASE

1801984  SYB: Automated management of long running transactions

To generate the load sequence for the database, log in to ASE with isql as user

'sapsa' and execute the command:

1>load database BBK with listonly = 'LOAD_SQL'

2>go

You should be able to find the missing files after that.

Please check if the following dboptions were set:

1> use master
2> go
1> sp_dboption 'BBK', 'trunc log on chkpt', 'false'
2> go

1> sp_dboption 'BBK', 'full logging for all', 'true'
2> go

--after a complete DB dump and before any changes have been made to the database
1> sp_dboption 'BBK', 'enforce dump tran sequence', 'true'
2> go

Kind Regards,

Ionut

[thorstenhenrici]

Hello,

I found the Problem a couple of days ago. A colleague of mine actually had scheduled backup Jobs from DBACOCKPIT. I was not aware of this, so the Problem stemmed from intermittent backups that interfered with my own.

Best Regards,

Thorsten