Restoring Archived Item from NetBackup Failed after EV Server Moving

[jaouher_kasraou]

Hello

After moving an EV Server to new server we are not able to restore archived item from secondary storage using NBUMigrator.

The infrastructure is composed of EV Server 2007 SP6 used only for FSA archiving, NetBackup 6.5.3 and SQL Server 2005.

We moved the EV Server to new Server with new name and new IP Address, after the move action we can Archive Item to primary storage and we can also restore items archived from the primary storage but when we recal items migrated to With NetBackup it fails.

The Windows Event Log records the following Errors and Warnings for item that should be restored :

  

The NetBackup Client log shows this message at the operation end (the real name of the Ev Server is changed with <EVSERVERNAME>) :

20:05:35.864 [4216.376] <2> bsa_bplist: end_date = (null)
20:05:35.864 [4216.376] <2> bsa_bplist: Request = root root <EVSERVERNAME> <EVSERVERNAME> <EVSERVERNAME> NONE 0  3 999 0 4294967295 4 4 1 0 1 0 24 -1 -1 3 0 en en en en en 0 2 0 0 0
20:05:35.864 [4216.376] <4> bsa_bplist: Filepath = /
20:05:36.379 [4216.376] <2> dbc_get_string: Output = EXIT STATUS 20
20:05:36.379 [4216.376] <16> bsa_QueryFile: ERR - bsa_bplist() failed 20
20:05:36.379 [4216.376] <8> : -Wrn- 000-771136.000 XBSA_RetrieveFile:Premature exit of while loop, step 1, status = 3
20:05:36.379 [4216.376] <4> VxBSAEndTxn: INF - entering VxBSAEndTxn.
20:05:36.379 [4216.376] <4> VxBSAEndTxn: INF - Transaction being COMMITED.
20:05:36.379 [4216.376] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_LOG_DIRECTORY
20:05:36.379 [4216.376] <4> VxBSAGetEnv: INF - returning -
20:05:36.379 [4216.376] <4> VxBSAEndTxn: INF - Cleaning directory: <C:\Program Files\Veritas\NetBackup\Logs\exten_client>
20:05:36.379 [4216.376] <4> delete_old_files: entering delete_old_files.
20:05:36.379 [4216.376] <4> VxBSATerminate: INF - entering VxBSATerminate.
20:05:36.379 [4216.376] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_DEBUGFD
20:05:36.379 [4216.376] <4> VxBSAGetEnv: INF - returning -

When i run DTrace on the EV Server with the following configuration :

Enabled Trace options

Id    Name                             Detail     Include Events
41  - EVStgOfflineOpns                 Verbose    Yes        
79  - StorageFileWatch                 Verbose    Yes        

I can see that the log register the following :

296	19:43:23.525	[5368]	(EVStgOfflineOpns)	<10936>	EV-L	{StorageOfflineOpns} Queueing file request | FileRequest: Identifier = 5D5EFD0FD68B2343B62E50294C84473020050201COLLECTION69747, PartitionEntryId = 15D5EFD0FD68B2343B62E50294C8447301q10000<EvSiteAlias>.<Domain.Lan>, PartitionGUID = 5D5EFD0FD68B2343B62E50294C844730, SecondaryLocation = , RelativeFileName = 2005\02\01\Collection69747.CAB, MigratedFileId = 5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB, Destination = \\<NetAppServer>\Archive09$\EvaultStore009\2005\02\01\Collection69747.ARCHCAB, RequestTime = 17 Dec 2012 19:43:23.525
297	19:43:23.525	[5368]	(EVStgOfflineOpns)	<10936>	EV-H	{StorageOfflineOpns} Waiting for completion of file request for upto 40 seconds | FileRequest: Identifier = 5D5EFD0FD68B2343B62E50294C84473020050201COLLECTION69747, PartitionEntryId = 15D5EFD0FD68B2343B62E50294C8447301q10000<EvSiteAlias>.<Domain.Lan>, PartitionGUID = 5D5EFD0FD68B2343B62E50294C844730, SecondaryLocation = , RelativeFileName = 2005\02\01\Collection69747.CAB, MigratedFileId = 5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB, Destination = \\<NetAppServer>\Archive09$\EvaultStore009\2005\02\01\Collection69747.ARCHCAB, RequestTime = 17 Dec 2012 19:43:23.525
298	19:43:23.525	[5368]	(EVStgOfflineOpns)	<7252>	EV-M	{StorageOfflineOpns} File request being actioned | FileRequest: Identifier = 5D5EFD0FD68B2343B62E50294C84473020050201COLLECTION69747, PartitionEntryId = 15D5EFD0FD68B2343B62E50294C8447301q10000<EvSiteAlias>.<Domain.Lan>, PartitionGUID = 5D5EFD0FD68B2343B62E50294C844730, SecondaryLocation = , RelativeFileName = 2005\02\01\Collection69747.CAB, MigratedFileId = 5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB, Destination = \\<NetAppServer>\Archive09$\EvaultStore009\2005\02\01\Collection69747.ARCHCAB, RequestTime = 17 Dec 2012 19:43:23.525
299	19:43:23.525	[5368]	(EVStgOfflineOpns)	<7252>	EV-M	{StorageOfflineOpns} Creating instance of Migrator object with ProgId = NBUMigrator.Migrator, PartitionEntryId = 15D5EFD0FD68B2343B62E50294C8447301q10000<EvSiteAlias>.<Domain.Lan>
300	19:43:23.557	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf06 000-769803.000 RetrieveFile API:Entered
301	19:43:23.557	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf05 000-769803.001 QueryParms      :Querying NBU_Trace status = C0041AA3
302	19:43:23.557	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf06 000-769803.002 XBSA_MThread    :Preliminary IsStopping() check
303	19:43:23.557	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf04 000-769803.003 XBSA_MThread    :Successfully loaded xbsa.dll, handle = 7E4F0000
304	19:43:23.557	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf04 000-769803.004 XBSA_MThread    :Successfully created function thread
305	19:43:23.557	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf06 000-769803.005 XBSA_RetrieveFile:Entering...
306	19:43:23.557	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf05 000-769803.006 ParmScan        :Scanning 'EV_Policy=EV_Default_Policy'
307	19:43:23.557	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf05 000-769803.007 ParmScan        :Scanning 'EV_FileId=5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB'
308	19:43:23.557	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf05 000-769803.008 ParmScan        :Scanning 'EV_FilePath=\\<NetAppServer>\Archive09$\EvaultStore009\2005\02\01\Collection69747.ARCHCAB'
309	19:43:23.572	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf06 000-769803.009 XBSA_RetrieveFile:Using base date = 01287065347 (unparsed = 01287065347)
310	19:43:24.182	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf05 000-769804.000 XBSA_RetrieveFile:Beginning bracketed search
311	19:43:24.182	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf06 000-769804.001 XBSA_RetrieveFile:Time bracket is +- 15 minutes
312	19:43:24.182	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf06 000-769804.002 XBSA_RetrieveFile:Bracket start time = Thu Oct 14 15:54:07 2010|
313	19:43:24.182	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf06 000-769804.003 XBSA_RetrieveFile:Bracket end time = Thu Oct 14 16:24:07 2010|
314	19:43:25.604	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf06 000-769805.000 XBSA_RetrieveFile:Time bracket is +- 125 minutes
315	19:43:25.604	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf06 000-769805.001 XBSA_RetrieveFile:Bracket start time = Thu Oct 14 14:04:07 2010|
316	19:43:25.604	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf06 000-769805.002 XBSA_RetrieveFile:Bracket end time = Thu Oct 14 18:14:07 2010|
317	19:43:27.041	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf06 000-769807.000 XBSA_RetrieveFile:Time bracket is +- 2940 minutes
318	19:43:27.041	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf06 000-769807.001 XBSA_RetrieveFile:Bracket start time = Tue Oct 12 15:09:07 2010|
319	19:43:27.041	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf06 000-769807.002 XBSA_RetrieveFile:Bracket end time = Sat Oct 16 17:09:07 2010|
320	19:43:28.463	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf06 000-769808.000 XBSA_RetrieveFile:Time bracket is +- 0 minutes
321	19:43:28.463	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf06 000-769808.001 XBSA_RetrieveFile:Bracket start time = Thu Jan 01 01:00:00 1970|
322	19:43:28.463	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf06 000-769808.002 XBSA_RetrieveFile:Bracket end time = Tue Jan 19 04:14:07 2038|
323	19:43:29.229	[5368]	(EVStgOfflineOpns)	<8816>	EV:H	NBU Migrator: -Wrn- 000-769809.000 XBSA_RetrieveFile:Premature exit of while loop, step 1, status = 3
324	19:43:29.229	[5368]	(EVStgOfflineOpns)	<10628>	EV:H	NBU Migrator: -Wrn- 000-769809.001 XBSA_RetrieveFile:Returning 00000003: System detected error, operation aborted. (step 2)
325	19:43:29.229	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf06 000-769809.002 XBSA_RetrieveFile:Exiting, rtn = 00000003
326	19:43:29.229	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf04 000-769809.003 XBSA_MThread    :Thread has exited, rtn =  00000003
327	19:43:29.229	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf05 000-769809.004 PrintStrings    :00BEF0C4 Returned from XBSA_RetrieveFile()
328	19:43:29.229	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf05 000-769809.005 PrintStrings    :  0 = EV_Policy=EV_Default_Policy
329	19:43:29.229	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf05 000-769809.006 PrintStrings    :  1 = EV_FileId=5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB
330	19:43:29.229	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf05 000-769809.007 PrintStrings    :  2 = EV_FilePath=\\<NetAppServer>\Archive09$\EvaultStore009\2005\02\01\Collection69747.ARCHCAB
331	19:43:29.229	[5368]	(EVStgOfflineOpns)	<6724>	EV:L	NBU Migrator: Inf05 000-769809.008 PrintStrings    :  3 = NULL
332	19:43:29.229	[5368]	(EVStgOfflineOpns)	<8816>	EV:L	NBU Migrator: Inf05 000-769809.009 PrintStrings    :  4 = Error=00000003: System detected error, operation aborted.
333	19:43:29.229	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf05 000-769809.010 PrintStrings    :  5 = NULL
334	19:43:29.229	[5368]	(EVStgOfflineOpns)	<6724>	EV:H	NBU Migrator: *Err* 000-769809.011 RetrieveFile API:Failed to retrieve file (error 00000003: System detected error, operation aborted.). Check the NBU Activity Monitor.
335	19:43:29.229	[5368]	(EVStgOfflineOpns)	<8816>	EV~E	Event ID: 6954 The 3rd party Migrator application 'NBU Migrator' has logged the following message: |Failed to retrieve file (error 00000003: System detected error, operation aborted.). Check the NBU Activity Monitor. |
336	19:43:29.229	[5368]	(EVStgOfflineOpns)	<10628>	EV:L	NBU Migrator: Inf06 000-769809.012 RetrieveFile API:Exiting, rtn = 80004005
337	19:43:29.229	[5368]	(EVStgOfflineOpns)	<7252>	EV-H	{StorageOfflineOpns} Exception: Error HRESULT E_FAIL has been returned from a call to a COM component. Info: Diag:HRESULT: 80004005 Type:System.Runtime.InteropServices.COMException ST:   at KVS.EnterpriseVault.Interop.IMigrator.RetrieveFile(String PartitionGUID, String MigratedFileId, String AbsoluteFilename, IMigratorCallback pMigratorCallback)|   at KVS.EnterpriseVault.StorageOfflineOpns.StorageOfflineOpns.ActionFileRequest(Object state)
338	19:43:29.229	[5368]	(EVStgOfflineOpns)	<7252>	EV-H	{StorageOfflineOpns} File request not completed | FileRequest: Identifier = 5D5EFD0FD68B2343B62E50294C84473020050201COLLECTION69747, PartitionEntryId = 15D5EFD0FD68B2343B62E50294C8447301q10000<EvSiteAlias>.<Domain.Lan>, PartitionGUID = 5D5EFD0FD68B2343B62E50294C844730, SecondaryLocation = , RelativeFileName = 2005\02\01\Collection69747.CAB, MigratedFileId = 5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB, Destination = \\<NetAppServer>\Archive09$\EvaultStore009\2005\02\01\Collection69747.ARCHCAB, RequestTime = 17 Dec 2012 19:43:23.525
339	19:43:29.229	[5368]	(EVStgOfflineOpns)	<10936>	EV-H	{StorageOfflineOpns} Exception: Error HRESULT E_FAIL has been returned from a call to a COM component. Info: Diag:HRESULT: 80004005 Type:System.Runtime.InteropServices.COMException ST:   at KVS.EnterpriseVault.StorageOfflineOpns.StorageOfflineOpns.FileRequest.WaitForCompletion(ManualResetEvent StopEvent, Int32 TimeoutInSeconds)|   at KVS.EnterpriseVault.StorageOfflineOpns.StorageOfflineOpns.RequestFile(String PartitionEntryId, String PartitionGUID, String SecondaryLocation, String RelativeFileName, String MigratedFileId, String Destination, Int32 TimeoutInSeconds)
340	19:43:29.229	[8532]	(StorageOnlineOpns)	<9936>	EV~E	Event ID: 6838 Failed to recall a Saveset from its Collection. |Reason: Unspecified error  [0x80004005] |Relative Saveset Filename: 2005\02\01\15\200431000000000~200502011521220000~0.DVS |Relative Collection Filename: 2005\02\01\Collection69747.CAB |PartitionEntryID: 15D5EFD0FD68B2343B62E50294C8447301q10000<EvSiteAlias>.<Domain.Lan> |PartitionGUID: 5D5EFD0FD68B2343B62E50294C844730 |Partition Root Path: \\<NetAppServer>\Archive09$\EvaultStore009 |Secondary Location: (null) |Migrated File Id: 5D5EFD0FD68B2343B62E50294C844730+<NetBackupServer>+01287065347+2005\02\01\Collection69747.CAB |Reference: EVC/RSFC/CA |
341	19:43:29.229	[8532]	(StorageOnlineOpns)	<9936>	EV~W	Event ID: 16389 Unspecified error
342	19:43:29.244	[11168]	(w3wp)	<10432>	EV~W	Event ID: 6287 Unable to fetch item from "<EvServerAlias>.<Domain.Lan>". |Reason: Unspecified error  [0x80004005] |Saveset Id: 200431000000000~200502011521220000~0~0C03A3AE7C1741258691EB8B960DA78 |Archive Name: Store021$|Archive Folder Path: \\<NetAppFiler>.<Domain.Lan>\Store021$\TMR\MONACO PHASE 2\5 - Photos\3 - Visite site Fév. 2005 - Ph. JEGOU |Reference: [GOAFS] |

Can you help me to resolve this issue

Best Reagrds

[Jeff_Shotton]

I remember hearing about this issue before.

I have a horrible feeling that this is a problem with the way the items are being searched for, and that the lookup is looking for the EVServer name, and since it has changed the files now cannot be found from the catalog.

So, while you may want support to confirm it, my gut feeling is you are only going to be able to get the migrator working on restores if you rename the server back to the original name.

With that said, make sure nothing else migrates, because if this IS the issue you may end up with some items stamped with the new server name which will then not recall when you change the server name back.

Regards,

Jeff

[jaouher_kasraou]

Thanks Jeff for your answer

But on the moving server procedure there isn't any warning about this situation.

If the support confirm your suggestion they have to update all TECHNOTES related to EV Servers moving or migration.

I'm waiting for the Support Answer, I will update the post when I receive it.

Regards

Jaouher

[Jeff_Shotton]

Indeed.

I know who I was talking to in support when this came up. I'll ask the question...

Regards,

Jeff

[Jeff_Shotton]

...the question was asked, and there was broad agreement that the issue sounded similar - but nothing has been 'officially' recorded yet.

Your case should hopefully resolve all that.

If I find anything else out I'll let you know

Regards,

Jeff

[jaouher_kasraou · Accepted solution]

Problem resolved.

The problem described on this article was resolved by applying the following technote article : http://www.symantec.com/docs/TECH16957  (the only difference is that the article is regarding Unix Platform but our Platform is Windows).

Thanks to Yoane (https://www-secure.symantec.com/connect/user/yoane-r-my-2#profile-tabs-0)  who helped us to resolve this issue.   

Best Regards