db tape dismounted before finished, request remount

[robinsonjas]

TSM 6.1
We run our restore command and it reads some data and dismounts the tape, then requests we reload the same tape to continue the restore operation. We have made sure our mountretention in our dsmserv.opt is set (mountretention=5), but still the restore kicks the tape out and we have to manually load in next drive, etc...see below:
Any ideas?
$ /opt/tivoli/tsm/server/bin/dsmserv -i /home/tsminst1/tsminst1 restore db todate=02/02/2010 totime=11:15:56 source=dbb -prev=yes
ANR7800I DSMSERV generated at 14:02:08 on Oct 29 2009.

Tivoli Storage Manager for AIX
Version 6, Release 1, Level 2.1

Licensed Materials - Property of IBM

(C) Copyright IBM Corporation 1990, 2009.
All rights reserved.
U.S. Government Users Restricted Rights - Use, duplication or disclosure
restricted by GSA ADP Schedule Contract with IBM Corporation.

ANR7801I Subsystem process ID is 741420.
ANR0900I Processing options file /home/tsminst1/tsminst1/dsmserv.opt.
ANR7811I Using instance directory /home/tsminst1/tsminst1.
ANR4726I The ICC support module has been loaded.
ANR1636W The server machine GUID changed: old value (), new value (22.3c.a0.22-
.67.a7.11.d8.95.9d.08.63.0a.0f.05.65).
ANR8200I TCP/IP Version 4 driver ready for connection with clients on port
1500.
ANR8225I TCP/IP Version 4 administrative driver ready for connection with
clients on port 1580.
rm: Directory /tsmarch is not empty.
mkdir: cannot create /tsmarch.
/tsmarch: File exists
ANR4634I Starting point-in-time database restore to date 02/02/10 11:15:56.
ANR8955I Drive RMT1.1 in library TSMLM01 with serial number is updated with
the newly discovered serial number 1310040424.
ANR8955I Drive RMT2.1 in library TSMLM01 with serial number is updated with
the newly discovered serial number 1310076272.
ANR4620I Database backup series 13 operation 0 device class LTO4.
ANR8326I 001: Mount LTO volume F03487L4 R/O in drive RMT1.1 (/dev/rmt1.1) of
library TSMLM01 within 60 minutes.
ANR8335I 001: Verifying label of LTO volume F03487L4 in drive RMT1.1
(/dev/rmt1.1).
ANR8328I 001: LTO volume F03487L4 mounted in drive RMT1.1 (/dev/rmt1.1).
ANR1363I Input volume F03487L4 opened (sequence number 1).
ANR1364I Input volume F03487L4 closed.
ANR8468I LTO volume F03487L4 dismounted from drive RMT1.1 (/dev/rmt1.1) in
library TSMLM01.
ANR8326I 002: Mount LTO volume F03487L4 R/O in drive RMT2.1 (/dev/rmt2.1) of
library TSMLM01 within 60 minutes.
ANR0498W Session 2 refused for ADMIN_CENTER because restore DB is in progress.
ANR8326I 002: Mount LTO volume F03487L4 R/O in drive RMT2.1 (/dev/rmt2.1) of
library TSMLM01 within 59 minutes.
ANR8326I 002: Mount LTO volume F03487L4 R/O in drive RMT2.1 (/dev/rmt2.1) of
library TSMLM01 within 58 minutes.
ANR8326I 002: Mount LTO volume F03487L4 R/O in drive RMT2.1 (/dev/rmt2.1) of
library TSMLM01 within 57 minutes.

 

[robinsonjas]

Replying to my own thread w/ update from IBM:

I have done my test and confirmed with our development, what you have observed is correct behavior with 6121 db restore. What happens, when you run "dsmserv restore db" in 61x, the command triggers a DB2 restore from the media and DB2 is the one control the behavior of the restore.
During a db2 database restore, the DB2 ask chuck of data at a different time for example Log/DB, which will ask on different time and triggers multiple open/close to the backup volumes.

In my test, I see 1 mount during the starting phase ( use to reply DB2 the volume header information ), 2 mounts during db restore and 1 mounts during log restore. 4 mounts in total.

For example:

R4634I Starting point-in-time database restore to date 02/08/10 23:59:59.
ANR8955I Drive DRIVE1 in library TSM3576 with serial number is updated wit the newly discovered serial number 1210134085.
ANR8955I Drive DRIVE2 in library TSM3576 with serial number is updated witthe newly discovered serial number 1210183013.
ANR4620I Database backup series 24 operation 0 device class LTO.
ANR8337I LTO volume 556ADZ mounted in drive DRIVE1 (/dev/rmt1).
ANR1363I Input volume 556ADZ opened (sequence number 1).
ANR1364I Input volume 556ADZ closed.-----------------------mount 1
ANR8468I LTO volume 556ADZ dismounted from drive DRIVE1 (/dev/rmt1) in librTSM3576.
ANR8337I LTO volume 556ADZ mounted in drive DRIVE2 (/dev/rmt2).
ANR1363I Input volume 556ADZ opened (sequence number 1).------------- mount 2
ANR1364I Input volume 556ADZ closed.
ANR4638I Restore of backup series 24 operation 0 in progress.
ANR0406I Session 3 started for node $$_TSMDBMGR_$$ (DB2/AIX64) (Tcp/Ip127.0.0.1(33206)).
ANR8468I LTO volume 556ADZ dismounted from drive DRIVE2 (/dev/rmt2) in librTSM3576.
ANR8337I LTO volume 556ADZ mounted in drive DRIVE1 (/dev/rmt1).
ANR0510I Session 3 opened input volume 556ADZ.----------------mount 3
ANR1363I Input volume 556ADZ opened (sequence number 1).
ANR4912I Database full restore in progress and DB Data bytes transferred
....
ANR8337I LTO volume 556ADZ mounted in drive DRIVE2 (/dev/rmt2).
ANR0510I Session 4 opened input volume 556ADZ. ----------- Mount 4
ANR1363I Input volume 556ADZ opened (sequence number 1).
ANR4912I Database full restore in progress and DB transaction log bytes
transferred 67,371,008.
ANR1365I Volume 556ADZ closed (end reached).
ANR4912I Database full restore in progress and DB transaction log bytestransferred 113,487,883.
ANR1364I Input volume 556ADZ closed.
....


I just write to confirm what is expected behavior with 61 DB restore ( indeed db2 restore ). I have fount it help to increase the device class "mountretention" to close the length of restore to the outstanding mount request ( like 001/002/003/004 ) since the tape will stay in the drive.