SQL1265N on Rollforward When Restoring Database From One Server to Another

As I mentioned in a recent post, I do a lot of restoring databases to get them from one server to another. On rollforward after a recent restore, I saw this:

$ db2 force applications all; db2 deactivate db WC037P01; db2 "restore db WC037D01 from /app/IBM/db2/db_bkup taken at 20120723030327 into WC037P01 logtarget /app/IBM/db2/db_bkup/logs replace existing without prompting"
DB20000I  The FORCE APPLICATION command completed successfully.
DB21024I  This command is asynchronous and may not be effective immediately.

SQL1493N  The application is already connected to an active database.
SQL2540W  Restore is successful, however a warning "2528" was encountered
during Database Restore while processing in No Interrupt mode.
$ db2 get db cfg for wc037p01 |grep -i log
 Log retain for recovery status                          = RECOVERY
 User exit for logging status                            = YES
 Catalog cache size (4KB)              (CATALOGCACHE_SZ) = 4096
 Log buffer size (4KB)                        (LOGBUFSZ) = 512
 Log file size (4KB)                         (LOGFILSIZ) = 10000
 Number of primary log files                (LOGPRIMARY) = 12
 Number of secondary log files               (LOGSECOND) = 50
 Changed path to log files                  (NEWLOGPATH) =
 Path to log files                                       = /app/IBM/db2/db_logs/NODE0000/
 Overflow log path                     (OVERFLOWLOGPATH) =
 Mirror log path                         (MIRRORLOGPATH) =
 First active log file                                   = S0000078.LOG
 Block log on disk full                (BLK_LOG_DSK_FUL) = NO
 Block non logged operations            (BLOCKNONLOGGED) = NO
 Percent max primary log space by transaction  (MAX_LOG) = 0
 Num. of active log files for 1 active UOW(NUM_LOG_SPAN) = 0
 Percent log file reclaimed before soft chckpt (SOFTMAX) = 520
 Log retain for recovery enabled             (LOGRETAIN) = RECOVERY
 User exit for logging enabled                (USEREXIT) = OFF
 HADR log write synchronization mode     (HADR_SYNCMODE) = NEARSYNC
 First log archive method                 (LOGARCHMETH1) = DISK:/app/IBM/db2/db_arch_logs/WC037P01/
 Options for logarchmeth1                  (LOGARCHOPT1) =
 Second log archive method                (LOGARCHMETH2) = OFF
 Options for logarchmeth2                  (LOGARCHOPT2) =
 Failover log archive path                (FAILARCHPATH) =
 Number of log archive retries on error   (NUMARCHRETRY) = 5
 Log archive retry Delay (secs)         (ARCHRETRYDELAY) = 20
 Log pages during index build            (LOGINDEXBUILD) = OFF
$ cp ./logs/*.LOG /app/IBM/db2/db_logs/NODE0000/
$ db2 rollforward db wc037p01 to end of backup and stop
SQL1265N  The archive log file "S0000078.LOG" is not associated with the
current log sequence for database "WC037P01" on node "0".

On getting this, I did some further investigation to see where it was getting this log file:

$ ls /app/IBM/db2/db_logs/NODE0000/
S0000078.LOG  SQLLPATH.TAG
$ ls -latr logs
total 4972
drwxr-xr-x 5 db2inst1 db2inst1    4096 Jul 23 03:09 ..
-rw------- 1 db2inst1 db2iadm1 5070848 Jul 23 03:12 S0000078.LOG
drwxr-xr-x 2 db2inst1 db2iadm1    4096 Jul 23 03:12 .
$ cd /app/IBM/db2/db_arch_logs/WC037P01/
$ ls
db2inst1
$ cd d*
$ ls
WC037P01
$ cd W*
$ ls
NODE0000
$ cd N*
$ ls
C0000000  C0000001
$ cd C0000001
$ pwd
/app/IBM/db2/db_arch_logs/WC037P01/db2inst1/WC037P01/NODE0000/C0000001
$ ls -latr
total 379872
drwxr-x--- 4 db2inst1 db2iadm1     4096 Jul 20 23:20 ..
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:01 S0000067.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:02 S0000068.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:03 S0000069.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:04 S0000070.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:05 S0000071.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:06 S0000072.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:07 S0000073.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:20 S0000074.LOG
-rw-r----- 1 db2inst1 db2iadm1 40968192 Jul 21 00:21 S0000075.LOG
-rw-r----- 1 db2inst1 db2iadm1 10706944 Jul 21 03:01 S0000076.LOG
-rw-r----- 1 db2inst1 db2iadm1  4710400 Jul 22 03:01 S0000077.LOG
-rw-r----- 1 db2inst1 db2iadm1  4386816 Jul 23 03:00 S0000078.LOG
-rw-r----- 1 db2inst1 db2iadm1    16384 Jul 23 03:04 S0000079.LOG
drwxr-x--- 2 db2inst1 db2iadm1     4096 Jul 23 03:04 .

What I discovered here is that the log file it is complaining about is the one that I restored from the backup image (into db_bkup/logs). But it looks like the database I’m restoring into also had a S0000078.LOG, and it’s in the archive path. So, for some reason, even thought the log file exists in the active path (because I manually copied it there after the restore), the rollforward is also attempting to retrieve it from the archive log path. When I delete or rename the log file in the archive path, the problem is resolved – In the example below, I’m doing this by simply compressing it, which makes it so that DB2 cannot retrieve it.

$ pwd
/app/IBM/db2/db_arch_logs/WC037P01/db2inst1/WC037P01/NODE0000/C0000001
$ gzip *.LOG
$ db2 rollforward db wc037p01 to end of backup and stop

                                 Rollforward Status

 Input database alias                   = wc037p01
 Number of nodes have returned status   = 1

 Node number                            = 0
 Rollforward status                     = not pending
 Next log file to be read               =
 Log files processed                    = S0000078.LOG - S0000078.LOG
 Last committed transaction             = 2012-07-23-01.04.12.000000 UTC

DB20000I  The ROLLFORWARD command completed successfully.

I still have a question in mind as to why I’m seeing this behavior. It seems to me that if the log file is already in the active log path, db2 should not be retrieving it from the archive log path. But I’ve seen this error at least three times on two different servers in the last two weeks on a set of 9.7 FixPack 4 servers.

You may also like...

14 Responses

  1. Ben says:

    I believe if you specifed the overflow log path, you wouldn’t get this error.

    • Ember Crooks says:

      I thought I tried that, but I’ll try again the next time it happens and document the results

      • Ember Crooks says:

        I tried it today, and it didn’t help – I still got the error until I renamed (through compressing) the archived log files.

        $ db2 force applications all; db2 deactivate db SAMPLE; db2 "restore db PROD from /db_bkup taken at 2012073016190 into SAMPLE logtarget /db_bkup/logs replace existing without prompting"
        DB20000I  The FORCE APPLICATION command completed successfully.
        DB21024I  This command is asynchronous and may not be effective immediately.
        
        SQL1496W  Deactivate database is successful, but the database was not
        activated.
        SQL2540W  Restore is successful, however a warning "2528" was encountered
        during Database Restore while processing in No Interrupt mode.
        
        $ db2 "rollforward db SAMPLE to end of backup overflow log path ('/db_bkup/logs')"
        SQL1265N  The archive log file "S0000097.LOG" is not associated with the
        current log sequence for database "WC037Q01" on node "0".
        $ cp /db_bkup/logs/*.LOG /db_logs/NODE0000/
        $ db2 "rollforward db SAMPLE to end of backup overflow log path ('/db_bkup/logs')"
        SQL1265N  The archive log file "S0000097.LOG" is not associated with the
        current log sequence for database "WC037Q01" on node "0".
        $ cd /db_arch_logs/SAMPLE/db2inst1/SAMPLE/NODE0000/C0000003
        $ ls
        S0000079.LOG.gz  S0000083.LOG  S0000087.LOG  S0000091.LOG  S0000095.LOG  S0000099.LOG  S0000103.LOG  S0000107.LOG  S0000111.LOG  S0000115.LOG  S0000119.LOG  S
        S0000080.LOG     S0000084.LOG  S0000088.LOG  S0000092.LOG  S0000096.LOG  S0000100.LOG  S0000104.LOG  S0000108.LOG  S0000112.LOG  S0000116.LOG  S0000120.LOG  S
        S0000081.LOG     S0000085.LOG  S0000089.LOG  S0000093.LOG  S0000097.LOG  S0000101.LOG  S0000105.LOG  S0000109.LOG  S0000113.LOG  S0000117.LOG  S0000121.LOG
        S0000082.LOG     S0000086.LOG  S0000090.LOG  S0000094.LOG  S0000098.LOG  S0000102.LOG  S0000106.LOG  S0000110.LOG  S0000114.LOG  S0000118.LOG  S0000122.LOG
        $ gzip *.LOG
        $ db2 "rollforward db SAMPLE to end of backup overflow log path ('/db_bkup/logs')"
        
                                         Rollforward Status
        
         Input database alias                   = SAMPLE
         Number of nodes have returned status   = 1
        
         Node number                            = 0
         Rollforward status                     = DB  working
         Next log file to be read               = S0000097.LOG
         Log files processed                    = S0000097.LOG - S0000097.LOG
         Last committed transaction             = 2012-07-30-14.20.02.000000 UTC
        
        DB20000I  The ROLLFORWARD command completed successfully.
        
  2. Siva says:

    Hi, I too have encountered this error couple of times, I believe the only option is to remove or rename the log file in the archive path before the rollforward. I had the new log files which are not associated with the database that is restored present both in active and archive log paths, due to which rollforward failed even with over flow log path specified.
    I think rollforward first looks at archive /retrieve path and then active log path, before even checking the overflow log path for the required log file and then moves it into the active log path directory after it applies all transactions in it. I am guessing immediately after the restore, database would have got activated, due to which the logs gets generated in the log paths (active and archive) with the same log sequence number of the database that is backed up.

  3. Justin Spies says:

    So I ran into this today and it made me go nuts. But I found the issue. This thread is about 6 months old so maybe you found the issue too.

    This happens when you do a restore as ‘REPLACE EXISTING’. What happens is that DB2 does not remove the existing files from the active log directory. Since the DB was previously active and had files in that directory, it must have looked in that directory first. Then it looks in the archive directory, then the new log path.

    I confirmed this behavior by using the following pattern:
    – db2 restore db … replace existing
    – db2 rollforward …

    that generated the error. When I looked in the active log directories, I noticed that the active log directory included the file that the rollforward was trying to process AND the archive log directory included the same.

    I then used the following pattern:
    – db2 drop db …
    – db2 restore db …
    – db2 rollforward db …

    The above worked properly and, before doing the rollforward, I confirmed that in all cases, the active log directory was empty.

    I would imagine that deleting the active log files would work if they are not needed. Typically I think that the sequence numbers should only overlap if you’re doing a ‘REPLACE EXISTING’ when doing testing, or when restoring multiple times because the first attempts failed for some reason.

  4. Raul Baron says:

    Thanks a lot for sharing this. I had this problem this very morning and I solved it thanks to your help.
    I’m in debt with you.
    Once again, thank you very much.
    Best regards,
    Raul

  5. Noel says:

    I have seen a few people (myself included) having problems with incorrect log files. I’ve added a step to my restore scripts/instructions to copy/delete any files in the archive log path before starting a restore operation. It makes things much easier.

  6. Raul Baron says:

    I confirm Noel’s procedure. I have never again had such problems by erasing the contents of the Path to log files as well as the contents of the logtarget directory.

  7. Michael Krafick says:

    Just to add on the the party …

    In our specific case, the restore was continuing to reach out to TSM over and over for archive logs. We ended up changing our rollforward statement to “to end of backup” and used “NORETRIEVE” at the end of the statement. Soon as we did that, it worked!

  8. venkat says:

    thanks a lot Ember ,

    this helped me a lot, i faced the sam problem and i am able to resolve after following your blog

  9. Fresher says:

    Hi,
    I had the below error like discussed above

    db2 “rollforward db db to end of logs overflow log path (‘path’)”
    I made sure I deleted all files in the active log directory before starting the roll forward. stil had no luck . I didnt use any REPLACE EXISTING in my backup. I also had manually copied the log file listed in the error file to active directory and renamed the file in the archive log directory still no luck. I am using db2 9.7. Anyone please advice

  10. Raul Baron says:

    We are using this and it works fine. I hope it helps

    rm -rf /logs/newdb/*
    rm -rf /logs/logtarget/*
    rm -rf /backups/archived_logs/instance/newdb/NODE0000/*

    db2 restore db db from ‘/backups’ taken at $date on ‘/tablespacepath’ into newdb LOGTARGET ‘/logs/logtarget’ newlogpath ‘/logs/newdb’ without prompting

    db2 rollforward db newdb to end of logs and stop overflow log path ‘(/logs/logtarget)’

  1. February 2, 2016

    […] SQL1265N on Rollforward When Restoring Database From One Server to Another […]

Leave a Reply

Your email address will not be published. Required fields are marked *