BAB11 - MSL5026 Problems

[mikenb]

Hi

I have instaled the BAB11, after i had uninstalled the BAB9 (with the clean of folders and regestry keys).


Here are the details:


Server: Compaq ML350 G2
Library: Compaq StorageWorks MSL5026 w/ 2 drives
Media: HP/COMPAQ 110/220 SDLT-1
OS: Windows 2000 SP4 all patches applied with the latest Support Pack
Backup Software: Brightstor 11 with all patches and device support updates applied
Library firmware is 423, drive firmware is 75, the latest.

I had disabled the "removable storage" and "HP storage agent" services, and disabled the device drivers from W2k of the Media Changer and the two drives.
I have taken out the "SCSI Information" from the "HP Agents Configuration".

But the backup still don´t work... :'(

The Drives went Offline with no reason, I made a Inventory but in the MSL does nothing...
I run a Job and nothing...

Please help me!!!!!!!

Thanks all your help!!!

MikeNB

Here is a recent tape log, while I as attempting to run a Job:

05/13 18:25:06 [0aa4] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[2] Data[0014F708] --
05/13 18:25:06 [0aa4] GetXCB 9255: Command Supported
05/13 18:25:06 [0aa4] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[0] Data[0014F708] --
05/13 18:25:06 [0aa4] GetXCB 9255: ulTime[13067953]
05/13 18:25:11 [0aa4] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[2] Data[0014F708] --
05/13 18:25:11 [0aa4] GetXCB 9255: Command Supported
05/13 18:25:11 [0158] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[0] Data[0014F708] --
05/13 18:25:11 [0158] GetXCB 9255: ulTime[13073015]
05/13 18:25:16 [0158] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[2] Data[0014F708] --
05/13 18:25:16 [0158] GetXCB 9255: Command Supported
05/13 18:25:16 [0158] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[0] Data[0014F708] --
05/13 18:25:16 [0158] GetXCB 9255: ulTime[13078046]
05/13 18:25:21 [0158] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[2] Data[0014F708] --
05/13 18:25:21 [0158] GetXCB 9255: Command Supported
05/13 18:25:21 [0158] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[0] Data[0014F708] --
05/13 18:25:21 [0158] GetXCB 9255: ulTime[13083093]
05/13 18:25:26 [0aa4] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[2] Data[0014F708] --
05/13 18:25:26 [0aa4] GetXCB 9255: Command Supported
05/13 18:25:26 [0aa4] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[0] Data[0014F708] --
05/13 18:25:26 [0aa4] GetXCB 9255: ulTime[13088140]
05/13 18:25:30 [0158] -Total Jobs now ACTIVE: [5]-
05/13 18:25:30 [0158] CREATEJOBHANDLE[01189620] JobID[12344] Generated for new Job Queue Handle
05/13 18:25:30 [0158] CREATEJOBHANDLE[01189620] JobType:[2][Job Queue]
05/13 18:25:30 [0158] CREATEJOBHANDLE[01189620] Client:[SYSTEM]
05/13 18:25:30 [0158] CREATEJOBHANDLE[01189620] Connection:[Local]
05/13 18:25:30 [0aa4] -- GetXCB called with hJob[01189620] JobID[12344] Type[5000] CBNo[6] Data[0014F708] --
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 5027984
Process_GetXCB_ForMux:: Task/Job Engine sent the JobToken
05/13 18:25:30 [0aa4] GRP: ClientGetGroupStatus() is called.
05/13 18:25:30 [0aa4] GRP: ClientGetGroupStatus:gbPrimaryServer == TRUE
05/13 18:25:30 [0aa4] GetGCBHandleFromGroupName(): GroupName [BSAN]
05/13 18:25:30 [0aa4] GRP: NodeName: [SYSTEM]
05/13 18:25:30 [0aa4] GRP: Making Entry For Node: [SYSTEM], Nodes 1
05/13 18:25:30 [0aa4] GRP: Modified First and Last Time. Node: [SYSTEM], Time: 1084469130
05/13 18:25:30 [0aa4] GRP: JobID[12344] ...in LockGroupEnum for[BSAN]
05/13 18:25:30 [0aa4] GRP: LockGroupEnum:[BSAN]
05/13 18:25:30 [0aa4] GRP: ...in UnLockGroupEnum for JobID[12344] Group[BSAN]
05/13 18:25:30 [0aa4] GRP: 0 High Priority Nodes for Node: [SYSTEM]. Free Drives: 1
05/13 18:25:30 [0aa4] GRP: ClientGetGroupStatus:gbPrimaryServer == TRUE. call _ClientGetGroupStatus()
05/13 18:25:30 [0aa4] GRP: ...in ClientGetGroupStatus for JobID[12344] Group[BSAN]
05/13 18:25:30 [0aa4] GRP: ClientGetGroupStatus: JobType:3 tapeName:[A-BSAN-WED-12-05-04] RID:[e74e] Seq:[1] Group:[BSAN]
05/13 18:25:30 [0aa4] GRP: ClientGetGroupStatus: OwnerName[SYSTEM] JobID[12344]
05/13 18:25:30 [0aa4] GetGCBHandleFromGroupName(): GroupName [BSAN]
05/13 18:25:30 [0aa4] GRP: JobID[12344] ...in LockGroupEnum for[BSAN]
05/13 18:25:30 [0aa4] GRP: LockGroupEnum:[BSAN]
05/13 18:25:30 [0aa4] GRP: Changer group[BSAN] is NOT Reserved
05/13 18:25:30 [0aa4] LDN:7 Look for Free Drive: TapeName:[A-BSAN-WED-12-05-04] RandomID:[e74e] Seq:[1]
05/13 18:25:30 [0aa4] LDN:7 Free Drives:1 Reserved Drive:0
05/13 18:25:30 [0aa4] LDN:7 Free Drive Available!
05/13 18:25:30 [0aa4] GRP: Status = TAPE AND GROUP AVAILABLE
05/13 18:25:30 [0aa4] GRP: ...in UnLockGroupEnum for JobID[12344] Group[BSAN]
05/13 18:25:30 [0aa4] Group Allocated to Node: [SYSTEM]
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 5027984
GROUP = BSAN, tape = A-BSAN-WED-12-05-04, randomId = 59214, sequence = 1 is AVAILABLE.
05/13 18:25:30 [0aa4] GRP: ...in ClientReserveGroup JobID[12344] Group[BSAN]
05/13 18:25:30 [0aa4] GetGCBHandleFromGroupName(): GroupName [BSAN]
05/13 18:25:30 [0aa4] GRP: JobID[12344] ...in LockGroupEnum for[BSAN]
05/13 18:25:30 [0aa4] GRP: LockGroupEnum:[BSAN]
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 5027984
ClientReserveGroup:: Reserving a GROUP = BSAN. Reserved Drives:1 Free Drives:1
05/13 18:25:30 [0aa4] GRP: LDN:7 Group [BSAN] is reserved. ReservedTime:1084469130 Duration:120
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 5027984
ClientReserveGroup:: GROUP RESERVED. nReservedDrives = 1, nFreeDrives = 1
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 5027984
ClientReserveGroup:: nReservedDrives = 1, nFreeDrives = 1
05/13 18:25:30 [0aa4] SAN: ChangerUpdateDistributedServerGUI(): UseSlotUpdateCB is not set
05/13 18:25:30 [0aa4] GRP: LDN:7 Mark Slot:23 as reserved.
05/13 18:25:30 [0aa4] GRP: LDN:7 Reserve:[0] Tape[A-BSAN-WED-12-05-04] RID[e74e] Seq[1] Slot[23] Exp[18:27:30]
05/13 18:25:30 [0aa4] GRP: ...in UnLockGroupEnum for JobID[12344] Group[BSAN]
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 5027984
GROUP = BSAN, tape = A-BSAN-WED-12-05-04, randomId = 59214, sequence = 1 is RESERVED.
05/13 18:25:30 [0aa4] DestroyJobHandle[01189620]
05/13 18:25:30 [0aa4] usJobID = [12344], muxId = 0, jobToken = 0
Destroy JobID[12344]: Active Jobs now: [4]
05/13 18:25:31 [0158] GRP: LDN:7 Tape [0] will expire at[18:27:30]
05/13 18:25:31 [0158] GRP: LDN:7 Tape[A-BSAN-WED-12-05-04] RID[e74e] Seq[1] Slot[23]
05/13 18:25:31 [0254] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[2] Data[0014F708] --
05/13 18:25:31 [0254] GetXCB 9255: Command Supported
05/13 18:25:31 [0158] -- GetXCB called with hJob[01189294] JobID[5000] Type[9255] CBNo[0] Data[0014F708] --
05/13 18:25:31 [0158] GetXCB 9255: ulTime[13093171]
05/13 18:25:31 [0254] SLOTSUPDATE. Slot[23] TimeStamp[13092468] LastQueryTime[13088140] updated?[YES]
05/13 18:25:32 [0254] -Total Jobs now ACTIVE: [5]-
05/13 18:25:32 [0254] CREATEJOBHANDLE[01189620] JobType:[257][Backup Job]
05/13 18:25:32 [0254] CREATEJOBHANDLE[01189620] Client:[caroot_task]
05/13 18:25:32 [0254] CREATEJOBHANDLE[01189620] Connection:[Local]
05/13 18:25:32 [0aa4] -- GetXCB called with hJob[01189620] JobID[65535] Type[9000] CBNo[12] Data[0014F708] --
05/13 18:25:32 [0aa4] CREATEJOBHANDLE[01189620] JobID[12] passed in from Task
05/13 18:25:32 [0254] -- GetXCB called with hJob[01189620] JobID[12] Type[5000] CBNo[6] Data[0014F708] --
05/13 18:25:32 [0254] usJobID = [12], muxId = 0, jobToken = 5027984
Process_GetXCB_ForMux:: Task/Job Engine sent the JobToken
05/13 18:25:32 [0158] CheckIfRAIDGroup: RAIDSupport = FALSE
05/13 18:25:32 [0158] GRP: ...in ConnectToGroup for JobID[12] Group[BSAN]
05/13 18:25:32 [0158] GetGCBHandleFromGroupName(): GroupName [BSAN]
05/13 18:25:32 [0158] GetGCBHandleFromGroupName(): GroupName [BSAN]
05/13 18:25:32 [0158] GRP: Locking Group [BSAN], JobType 257
05/13 18:25:32 [0158] GetGCBHandleFromGroupName(): GroupName [BSAN]
05/13 18:25:32 [0158] ClientEnumTapeOpen(): TapeName [A-BSAN-WED-12-05-04], RID [0000], Seq [0], SelectionFlag [32], JobFlag [0x00000000], DontCheckMediaInUse [0]
05/13 18:25:32 [0158] Detected TSI_ETSF_NAME_PLUS, setting bDontCheckMediaInUse to TRUE for Task....
05/13 18:25:32 [0158] SelectionFlag[0x01] Name[A-BSAN-WED-12-05-04] RandomID[0000] SequenceNo[0].
05/13 18:25:32 [0158] <Enum on TAPE NAME>
05/13 18:25:32 [0158] GRP: JobID[12] ...in LockGroupEnum for[BSAN]
05/13 18:25:32 [0158] GRP: LockGroupEnum:[BSAN]
05/13 18:25:32 [0158] Entering UpdateChangerList()
05/13 18:25:32 [0158] UpdateChangerList: TryEnterCriticalSection [011E3DA8]
05/13 18:25:32 [0158] UpdateChangerList: Inside CriticalSection [011E3DA8] on try [0]
05/13 18:25:32 [0158] LDN:7 ...in ChgPrepChanger
05/13 18:25:32 [0158] ChgTestUnitReady: Entering Critical Section!
05/13 18:25:32 [0158] Test Unit Ready Leaving Critical Section!
05/13 18:25:32 [0158] Test Unit Ready Left Critical Section!
05/13 18:25:32 [0158] Leaving UpdateChangerList: ChangerDetectDoorOpen == FALSE - [011E3DA8]
05/13 18:25:32 [0158] Start SearchForTape for JobID[12] TapeName[A-BSAN-WED-12-05-04] RID[0000] SQ [0] in Group [BSAN]
05/13 18:25:32 [0158] JobID[12] Searching:[0] Name[<BLANK>] RandomID[0000] Seq[0] S/N[0000112] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[1] Name[D-BSAN-THU-06-05-04] RandomID[1d72] Seq[1] S/N[0000101] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[2] Name[M-BSAN-TUE-30-12-03] RandomID[e824] Seq[1] S/N[0000088] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[3] Name[M-BSAN-SAT-31-01-04] RandomID[17c7] Seq[1] S/N[0000011] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[4] Name[F-BSAN-TUE-04-05-04] RandomID[ae7b] Seq[1] S/N[0000055] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[5] Name[M-BSAN-SAT-28-02-04] RandomID[0972] Seq[1] S/N[0000000] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[6] Name[W-BSAN-SAT-24-04-04] RandomID[e7f7] Seq[1] S/N[0000178] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[7] Name[<BLANK>] RandomID[0000] Seq[0] S/N[0000268] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[8] Name[W-CASSIOPE-SAT-28-02-04] RandomID[fe9d] Seq[1] S/N[0000066] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[9] Name[] RandomID[0000] Seq[0] S/N[] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[10] Name[M-BSAN-TUE-27-04-04] RandomID[2f2a] Seq[1] S/N[0000033] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] JobID[12] Searching:[11] Name[<BLANK>] RandomID[0000] Seq[0] S/N[0000257] InUse?[0] Reserved?[0] MyMedia?[0]
05/13 18:25:32 [0158] SearchForTape(): ENUM_TAPE_STATUS_EXHAUSTED
05/13 18:25:32 [0158] Exiting EnumTapeOpen. RC = [238]
05/13 18:25:32 [0aa4] ClientEnumTapeOpen(): TapeName [A-BSAN-WED-12-05-04], RID [0000], Seq [0], SelectionFlag [1], JobFlag [0x00000000], DontCheckMediaInUse [1]
05/13 18:25:32 [0aa4] SelectionFlag[0x01] Name[A-BSAN-WED-12-05-04] RandomID[0000] SequenceNo[0].
05/13 18:25:32 [0aa4] <Enum on TAPE NAME>
05/13 18:25:32 [0aa4] GRP: JobID[12] ...in LockGroupEnum for[BSAN], but Job already has lock!
05/13 18:25:32 [0aa4] GRP: LockGroupEnum:[BSAN]
05/13 18:25:32 [0aa4] Entering UpdateChangerList()
05/13 18:25:32 [0aa4] UpdateChangerList: TryEnterCriticalSection [011E3DA8]
05/13 18:25:32 [0aa4] UpdateChangerList: Inside CriticalSection [011E3DA8] on try [0]
05/13 18:25:32 [0aa4] LDN:7 ...in ChgPrepChanger
05/13 18:25:32 [0aa4] ChgTestUnitReady: Entering Critical Section!
05/13 18:25:32 [0aa4] Test Unit Ready Leaving Critical Section!
05/13 18:25:32 [0aa4] Test Unit Ready Left Critical Section!
05/13 18:25:32 [0aa4] Leaving UpdateChangerList: ChangerDetectDoorOpen == FALSE - [011E3DA8]

 

[davidmichel]

Well I did not see any errors.
The tape it was looking for was not in the library. There were a few blank tapes.
Was there any tape in the Media Pool Scratch set?
Perhaps all you need to do is add those blank tapes to the media pool (right click).

 

[mikenb]

The problem is that when i made an inventory the brightsor tells me that is doing it, but the MSL don´t do anything or starts but in the middle of the process stops. So the Brighstor never knows what tapes the Library have. It seems that the aplication is not comunicating right with the hardware.

 

[davidmichel]

Does the library support barcodes?

If so see How Are Barcodes Used? faq478-3963

 

[mikenb]

Yes i have barcodes in the Library and it works.
But i give up... and have uninstalled the BAB11 and reinstalled the BAB9 and is working just fine, for now...

Thanks for your help

MikeNB

 

[Fredje]

We are two with the same problem. ;o)

I installed BABv11 3 weeks ago and this problem has come +/- 10 times.

The problem is: VLDB index is corrupted.
So when the tape engine ask the database it never answer...

Solution:
Re-create the index of the database.
1. Stop your arcserve database service
2. Open the "database" folder
3. Delete all files that has the extention .ch*
4. Start the database service
(Procedure from Davidmichel that works perfect. Thx to him once again ;o) )

After this your inventory will run perfectly.

If it helps...

Fredje