Again same error Progress

sagar666 · ‎01-28-2014

Hi ,when i tried to restore i am getting following error

05:51:46 1/29/2014: Restore Started

05:51:47 (202487.xxx) Media id ST9039 is needed for the restore.

05:51:47 (202487.001) Restoring from copy 1 of image created 1/28/2014 1:30:57 AM

05:51:48 INF - If Media id ST9039 is not in a robotic library administrative interaction may be required to satisfy this mount request.

Nate_D1 · ‎01-28-2014

It is looking for a tape or a storage unit named 'ST9039' that has the data needed for the restore. If you do a verify in the catalog on that storage unit do you see your data?

Yasuhisa_Ishika · ‎01-28-2014

This is just a notice. It is always displayed when restore from tapes starts. What is your actual problem?l Restore has no progress?

Nate_D1 · ‎01-28-2014

Yeah, I didnt think about it because I normally just see this notice when I start a backup that I *expect* will need a tape, but it does show this on every restore. There may be no issue at all :)

sagar666 · ‎01-28-2014

After restarting server it is moving but i cant see my console properly like policies,media, etc i am able to see attached console

sagar666 · ‎01-28-2014

Hi i can see java console but i cant see Netbacckup administrator console

sagar666 · ‎01-28-2014

Now i am getting 2820 error while restoring

Nate_D1 · ‎01-28-2014

can you paste the progress log from the job to give more info about the error? Double check disk space on destination?

sagar666 · ‎01-29-2014

Hi Nate,

I have sufficient disk space.Please find log below

08:13:47 1/29/2014: Restore Started

08:13:48 (202494.xxx) Media id ST9039 is needed for the restore.

08:13:48 (202494.001) Restoring from copy 1 of image created 1/28/2014 1:30:57 AM

08:13:50 INF - If Media id ST9039 is not in a robotic library administrative interaction may be required to satisfy this mount request.

08:13:50 INF - Waiting for mount of media id ST9039 on server scc-nbu.cisco.com for reading.

08:13:58 INF - Waiting for positioning of media id ST9039 on server scc-nbu.cisco.com for reading.

08:13:59 INF - Beginning read-blockmap on server scc-nbu.cisco.com of client B16-STG-048.

08:13:59 (202494.xxx) Executing Virtual machine creation on scc-nbu.cisco.com to server B16-SCC-VC-1.

08:15:25 (202494.001) INF - TAR STARTED 1716

08:15:26 (202494.001) INF - If Media id ST9039 is not in a robotic library administrative interaction may be required to satisfy this mount request.

08:15:26 (202494.001) INF - Waiting for positioning of media id ST9039 on server scc-nbu.cisco.com for reading.

08:15:26 (202494.001) INF - Beginning restore from server scc-nbu.cisco.com to client scc-nbu.cisco.com.

08:15:45 (202494.001) TAR - STG-SATA-B-NEW:\B16-STG-048\B16-STG-048.vmdk

08:15:45 (202494.001) FTL - Virtual machine restore: file write failed

08:15:46 (202494.001) INF - TAR EXITING WITH STATUS = 5

08:15:46 (202494.001) INF - TAR RESTORED 0 OF 1 FILES SUCCESSFULLY

08:15:46 (202494.001) INF - TAR KEPT 0 EXISTING FILES

08:15:46 (202494.001) INF - TAR PARTIALLY RESTORED 0 FILES

08:17:04 (202494.001) Status of restore from copy 1 of image created 1/28/2014 1:30:57 AM = the restore failed to recover the requested files

08:17:04 (202494.001) The following files/folders were not restored:

08:17:04 (202494.001) UTF - /STG-SATA-B-NEW/B16-STG-048/B16-STG-048.vmdk

08:17:04 (202494.xxx) INF - Status = VMware policy restore error.

Nate_D1 · ‎01-29-2014

What version of Netbackup is this?

sagar666 · ‎01-29-2014

Netbackup 7.5

Nate_D1 · ‎01-29-2014

Enable bpfis and bpVMutil debug log in [install path]\netbackup\logs that will help us trace it down a bit.

Also when you do the restore you can try checking the 'Remove backing information for devices like DVD/CD-ROM drives, serial or parallel ports". That may help.

sagar666 · ‎01-29-2014

Again same error

Progress logs

0:13:33 1/30/2014: Restore Started

00:13:34 (202706.xxx) Media id ST9060 is needed for the restore.

00:13:34 (202706.001) Restoring from copy 1 of image created 1/29/2014 12:00:07 AM

00:13:36 INF - If Media id ST9060 is not in a robotic library administrative interaction may be required to satisfy this mount request.

00:13:36 INF - Waiting for mount of media id ST9060 on server scc-nbu.cisco.com for reading.

00:13:43 INF - Waiting for positioning of media id ST9060 on server scc-nbu.cisco.com for reading.

00:13:44 INF - Beginning read-blockmap on server scc-nbu.cisco.com of client B16-STG-048.

00:13:44 (202706.xxx) Executing Virtual machine creation on scc-nbu.cisco.com to server B16-SCC-VC-1.

00:15:08 (202706.001) INF - TAR STARTED 5512

00:15:09 (202706.001) INF - If Media id ST9060 is not in a robotic library administrative interaction may be required to satisfy this mount request.

00:15:09 (202706.001) INF - Waiting for positioning of media id ST9060 on server scc-nbu.cisco.com for reading.

00:15:09 (202706.001) INF - Beginning restore from server scc-nbu.cisco.com to client scc-nbu.cisco.com.

00:15:27 (202706.001) TAR - STG-SATA-B-NEW:\B16-STG-048\B16-STG-048.vmdk

00:15:27 (202706.001) FTL - Virtual machine restore: file write failed

00:15:28 (202706.001) INF - TAR EXITING WITH STATUS = 5

00:15:28 (202706.001) INF - TAR RESTORED 0 OF 1 FILES SUCCESSFULLY

00:15:28 (202706.001) INF - TAR KEPT 0 EXISTING FILES

00:15:28 (202706.001) INF - TAR PARTIALLY RESTORED 0 FILES

00:16:46 (202706.001) Status of restore from copy 1 of image created 1/29/2014 12:00:07 AM = the restore failed to recover the requested files

00:16:46 (202706.001) The following files/folders were not restored:

00:16:46 (202706.001) UTF - /STG-SATA-B-NEW/B16-STG-048/B16-STG-048.vmdk

00:16:46 (202706.xxx) INF - Status = VMware policy restore error.

bpVmutil logs

00:10:18.243 [6052.7052] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 2816 b16-stg-esx-06.cisco.com B16-SCC-VC-1

00:10:18.243 [6052.7052] virt_test_log: log function is called

00:10:18.243 [6052.7052] <2> bpVMutil main: cmd = 11 ESXMount = b16-stg-esx-06.cisco.com ESXserver = B16-SCC-VC-1, flags = 0

00:10:18.243 [6052.7052] generateServerFiles: get_id_lock returned 0: -> wait lock timeout value: 15 minutes -> WRITE LOCK B16-SCC-VC-1_lock fd = 236 -> lockname = B16-SCC-VC-1_lock

00:10:18.243 [6052.7052] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_resp_list_b16-stg-esx-06.cisco.com.xml

00:10:18.243 [6052.7052] generateServerFiles: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_resp_list_b16-stg-esx-06.cisco.com.xml does not exist, rebuilding

00:10:18.243 [6052.7052] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:10:18.258 [6052.7052] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65070 TO 10.106.10.81.13720 fd = 424

00:10:18.258 [6052.7052] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:10:18.352 [6052.7052] checkBackupRegEntry: searching configuration for excludeVMservers

00:10:18.352 [6052.7052] RegOpenKey failed with 2

00:10:18.352 [6052.7052] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:10:18.352 [6052.7052] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:18.352 [6052.7052] checkBackupRegEntry: searching configuration for disableFQDN

00:10:18.352 [6052.7052] RegOpenKey failed with 2

00:10:18.352 [6052.7052] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\003\cb965e03+0,1,2,0,1,0+b16-stg-esx-06.cisco.com.txt

00:10:18.352 [6052.7052] get_fqdn_hostname: fqdn host b16-stg-esx-06.cisco.com

00:10:18.352 [6052.7052] listNetworks: Listing networks on B16-SCC-VC-1 for b16-stg-esx-06.cisco.com

00:10:18.352 [6052.7052] checkBackupRegEntry: searching configuration for connecttimeout

00:10:18.352 [6052.7052] RegOpenKey failed with 2

00:10:18.352 [6052.7052] vSphereConnect: ConnectTimeout: 300 secs

00:10:18.352 [6052.7052] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:10:18.352 [6052.7052] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for jobtimeout

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for poweroptimeout

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for snapshottimeout

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for registertimeout

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for browsetimeout

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for refreshtimeout

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:10:18.586 [6052.7052] checkBackupRegEntry: searching configuration for vmcloglevel

00:10:18.586 [6052.7052] RegOpenKey failed with 2

00:10:18.586 [6052.7052] SetTimeoutsAndLogging: vmcloglevel=0

00:10:18.773 [6052.7052] vmwareLogger: Login: key = 5211c710-e51a-3396-f23f-ab773157aa74

00:10:18.773 [6052.7052] dovSphereLogin: sApiType = VirtualCenter

00:10:18.773 [6052.7052] dovSphereLogin: version = 5.1

00:10:18.773 [6052.7052] dovSphereLogin: sBuild = 1064983

00:10:18.773 [6052.7052] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:10:18.773 [6052.7052] dovSphereLogin: sName = VMware vCenter Server

00:10:18.773 [6052.7052] dovSphereLogin: sOsType = win32-x64

00:10:18.773 [6052.7052] dovSphereLogin: sProductLineId = vpx

00:10:18.773 [6052.7052] dovSphereLogin: sVersion = 5.1.0

00:10:18.773 [6052.7052] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:10:18 2014

00:10:18.773 [6052.7052] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:10:18.882 [6052.7052] listResourcePools: Listing Resource Pools on B16-SCC-VC-1 for b16-stg-esx-06.cisco.com

00:10:18.882 [6052.7052] dovSphereLogin: server B16-SCC-VC-1 already logged in

00:10:18.882 [6052.7052] vmwareLogger: BuildDatabases: Building databases

00:10:24.545 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:10:24.654 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:10:24.654 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:10:24.654 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:10:24.654 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:10:24.670 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:10:24.670 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:10:24.670 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:10:24.701 [6052.7052] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:10:24.857 [6052.7052] vmwareLogger: BuildDatabases: Building databases

00:10:24.873 [6052.7052] vmwareLogger: BuildDatabases: Building databases

00:10:24.888 [6052.7052] listDatastores: Listing datastores on B16-SCC-VC-1 for b16-stg-esx-06.cisco.com

00:10:24.888 [6052.7052] getDatastoresList: Creating List of datastores on B16-SCC-VC-1 for b16-stg-esx-06.cisco.com

00:10:24.888 [6052.7052] dovSphereLogin: server B16-SCC-VC-1 already logged in

00:10:24.935 [6052.7052] dovSphereLogin: server B16-SCC-VC-1 already logged in

00:10:24.935 [6052.7052] vmwareLogger: BuildDatabases: Building databases

00:10:24.951 [6052.7052] vmwareLogger: BuildDatabases: Building databases

00:10:24.966 [6052.7052] vmwareLogger: Logout: returned 0

00:10:25.075 [6052.7052] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:25.075 [6052.7052] <2> browseResourcePools: get_id_lock returned 0: -> wait lock timeout value: 30 minutes -> WRITE LOCK b16-stg-esx-06.cisco.com_lock fd = 628 -> lockname = b16-stg-esx-06.cisco.com_lock

00:10:25.075 [6052.7052] <2> browseResourcePools: fileCOPY of C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_resp_list_b16-stg-esx-06.cisco.com.xml to C:\Windows\TEMP\VMutl-06052391020818243052000000000-a07052 returned 0

00:10:25.075 [6052.7052] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:10:27.306 [6360.6380] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 3072 b16-stg-esx-06.cisco.com B16-SCC-VC-1

00:10:27.306 [6360.6380] virt_test_log: log function is called

00:10:27.306 [6360.6380] <2> bpVMutil main: cmd = 12 ESXMount = b16-stg-esx-06.cisco.com ESXserver = B16-SCC-VC-1, flags = 0

00:10:27.306 [6360.6380] generateServerFiles: get_id_lock returned 0: -> wait lock timeout value: 15 minutes -> WRITE LOCK B16-SCC-VC-1_lock fd = 236 -> lockname = B16-SCC-VC-1_lock

00:10:27.306 [6360.6380] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_resp_list_b16-stg-esx-06.cisco.com.xml

00:10:27.306 [6360.6380] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_list_b16-stg-esx-06.cisco.com.xml

00:10:27.306 [6360.6380] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_net_list_b16-stg-esx-06.cisco.com.xml

00:10:27.306 [6360.6380] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_tree_b16-stg-esx-06.cisco.com.xml

00:10:27.306 [6360.6380] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_net_tree_b16-stg-esx-06.cisco.com.xml

00:10:27.306 [6360.6380] <2> browseDatastores: get_id_lock returned 0: -> wait lock timeout value: 30 minutes -> WRITE LOCK b16-stg-esx-06.cisco.com_lock fd = 236 -> lockname = b16-stg-esx-06.cisco.com_lock

00:10:27.306 [6360.6380] <2> browseDatastores: fileCOPY of C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_list_b16-stg-esx-06.cisco.com.xml to C:\Windows\TEMP\VMutl-06360391020827306380000000000-a06380 returned 0

00:10:27.322 [6360.6380] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:10:29.521 [2176.6576] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 5632 b16-stg-esx-06.cisco.com B16-SCC-VC-1

00:10:29.521 [2176.6576] virt_test_log: log function is called

00:10:29.521 [2176.6576] <2> bpVMutil main: cmd = 22 ESXMount = b16-stg-esx-06.cisco.com ESXserver = B16-SCC-VC-1, flags = 0

00:10:29.521 [2176.6576] generateServerFiles: get_id_lock returned 0: -> wait lock timeout value: 15 minutes -> WRITE LOCK B16-SCC-VC-1_lock fd = 236 -> lockname = B16-SCC-VC-1_lock

00:10:29.521 [2176.6576] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_tree.xml

00:10:29.521 [2176.6576] generateServerFiles: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_tree.xml does not exist, rebuilding

00:10:29.521 [2176.6576] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:10:29.537 [2176.6576] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65093 TO 10.106.10.81.13720 fd = 424

00:10:29.537 [2176.6576] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:10:29.631 [2176.6576] checkBackupRegEntry: searching configuration for excludeVMservers

00:10:29.631 [2176.6576] RegOpenKey failed with 2

00:10:29.631 [2176.6576] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:10:29.646 [2176.6576] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:29.646 [2176.6576] checkBackupRegEntry: searching configuration for connecttimeout

00:10:29.646 [2176.6576] RegOpenKey failed with 2

00:10:29.646 [2176.6576] vSphereConnect: ConnectTimeout: 300 secs

00:10:29.646 [2176.6576] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:10:29.646 [2176.6576] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for jobtimeout

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for poweroptimeout

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for snapshottimeout

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for registertimeout

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for browsetimeout

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for refreshtimeout

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:10:29.865 [2176.6576] checkBackupRegEntry: searching configuration for vmcloglevel

00:10:29.865 [2176.6576] RegOpenKey failed with 2

00:10:29.865 [2176.6576] SetTimeoutsAndLogging: vmcloglevel=0

00:10:29.958 [2176.6576] vmwareLogger: Login: key = 5203fb6b-a680-33f1-f506-6d362a89ae56

00:10:29.958 [2176.6576] dovSphereLogin: sApiType = VirtualCenter

00:10:29.958 [2176.6576] dovSphereLogin: version = 5.1

00:10:29.958 [2176.6576] dovSphereLogin: sBuild = 1064983

00:10:29.958 [2176.6576] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:10:29.958 [2176.6576] dovSphereLogin: sName = VMware vCenter Server

00:10:29.958 [2176.6576] dovSphereLogin: sOsType = win32-x64

00:10:29.958 [2176.6576] dovSphereLogin: sProductLineId = vpx

00:10:29.958 [2176.6576] dovSphereLogin: sVersion = 5.1.0

00:10:29.958 [2176.6576] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:10:30 2014

00:10:29.958 [2176.6576] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:10:29.958 [2176.6576] vmwareLogger: BuildDatabases: Building databases

00:10:35.621 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:10:35.699 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:10:35.715 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:10:35.715 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:10:35.715 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:10:35.715 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:10:35.715 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:10:35.715 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:10:35.761 [2176.6576] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:10:35.902 [2176.6576] vmwareLogger: BuildDatabases: Building databases

00:10:35.917 [2176.6576] vmwareLogger: BuildDatabases: Building databases

00:10:35.933 [2176.6576] vmwareLogger: Logout: returned 0

00:10:36.042 [2176.6576] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:36.042 [2176.6576] <2> browseDatastoreTree: get_id_lock returned 0: -> wait lock timeout value: 30 minutes -> WRITE LOCK B16-SCC-VC-1_lock fd = 624 -> lockname = B16-SCC-VC-1_lock

00:10:36.042 [2176.6576] <2> browseDatastoreTree: fileCOPY of C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_tree.xml to C:\Windows\TEMP\VMutl-02176391020829521576000000000-a06576 returned 0

00:10:36.058 [2176.6576] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:10:53.358 [6676.6840] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 3328 <VirtualMachine><Name>B16-STG-048-1111</Name></VirtualMachine>

B16-SCC-VC-1

00:10:53.358 [6676.6840] virt_test_log: log function is called

00:10:53.358 [6676.6840] <2> bpVMutil main: cmd = 13 ESXMount = <VirtualMachine><Name>B16-STG-048-1111</Name></VirtualMachine>

ESXserver = B16-SCC-VC-1, flags = 0

00:10:53.358 [6676.6840] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:10:53.389 [6676.6840] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65133 TO 10.106.10.81.13720 fd = 420

00:10:53.389 [6676.6840] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:10:53.483 [6676.6840] checkBackupRegEntry: searching configuration for excludeVMservers

00:10:53.483 [6676.6840] RegOpenKey failed with 2

00:10:53.483 [6676.6840] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:10:53.483 [6676.6840] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:53.483 [6676.6840] listMatchingVM: Listing matching VMs on B16-SCC-VC-1

00:10:53.483 [6676.6840] find_vm_by_displayname: Looking for B16-STG-048-1111

00:10:53.483 [6676.6840] checkBackupRegEntry: searching configuration for connecttimeout

00:10:53.483 [6676.6840] RegOpenKey failed with 2

00:10:53.483 [6676.6840] vSphereConnect: ConnectTimeout: 300 secs

00:10:53.483 [6676.6840] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:10:53.483 [6676.6840] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for jobtimeout

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for poweroptimeout

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for snapshottimeout

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for registertimeout

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for browsetimeout

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for refreshtimeout

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:10:53.733 [6676.6840] checkBackupRegEntry: searching configuration for vmcloglevel

00:10:53.733 [6676.6840] RegOpenKey failed with 2

00:10:53.733 [6676.6840] SetTimeoutsAndLogging: vmcloglevel=0

00:10:53.842 [6676.6840] vmwareLogger: Login: key = 52222827-8fb2-2143-5e46-694e4aec4225

00:10:53.842 [6676.6840] dovSphereLogin: sApiType = VirtualCenter

00:10:53.842 [6676.6840] dovSphereLogin: version = 5.1

00:10:53.842 [6676.6840] dovSphereLogin: sBuild = 1064983

00:10:53.842 [6676.6840] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:10:53.842 [6676.6840] dovSphereLogin: sName = VMware vCenter Server

00:10:53.842 [6676.6840] dovSphereLogin: sOsType = win32-x64

00:10:53.842 [6676.6840] dovSphereLogin: sProductLineId = vpx

00:10:53.842 [6676.6840] dovSphereLogin: sVersion = 5.1.0

00:10:53.842 [6676.6840] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:10:54 2014

00:10:53.842 [6676.6840] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:10:53.842 [6676.6840] vmwareLogger: BuildDatabases: Building databases

00:10:59.458 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:10:59.551 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:10:59.567 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:10:59.567 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:10:59.567 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:10:59.567 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:10:59.567 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:10:59.567 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:10:59.614 [6676.6840] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:10:59.754 [6676.6840] vmwareLogger: RetrieveDcMorAndObjMorFromPath: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:10:59.754 [6676.6840] vmwareLogger: GetObjDetails: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:10:59.754 [6676.6840] find_vm_by_displayname: vmcGetObjDetails DataSet2_i failed with status 18

00:10:59.754 [6676.6840] <2> bpVMutil main: EXIT STATUS 227: no entity was found

00:11:27.975 [6184.6240] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 3328 <VirtualMachine><Name>B16-STG-048-1111</Name></VirtualMachine>

B16-SCC-VC-1

00:11:27.975 [6184.6240] virt_test_log: log function is called

00:11:27.975 [6184.6240] <2> bpVMutil main: cmd = 13 ESXMount = <VirtualMachine><Name>B16-STG-048-1111</Name></VirtualMachine>

ESXserver = B16-SCC-VC-1, flags = 0

00:11:27.975 [6184.6240] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:11:27.990 [6184.6240] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65143 TO 10.106.10.81.13720 fd = 420

00:11:27.990 [6184.6240] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:11:28.099 [6184.6240] checkBackupRegEntry: searching configuration for excludeVMservers

00:11:28.099 [6184.6240] RegOpenKey failed with 2

00:11:28.099 [6184.6240] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:11:28.099 [6184.6240] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:11:28.099 [6184.6240] listMatchingVM: Listing matching VMs on B16-SCC-VC-1

00:11:28.099 [6184.6240] find_vm_by_displayname: Looking for B16-STG-048-1111

00:11:28.099 [6184.6240] checkBackupRegEntry: searching configuration for connecttimeout

00:11:28.099 [6184.6240] RegOpenKey failed with 2

00:11:28.099 [6184.6240] vSphereConnect: ConnectTimeout: 300 secs

00:11:28.099 [6184.6240] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:11:28.099 [6184.6240] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for jobtimeout

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for poweroptimeout

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for snapshottimeout

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for registertimeout

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for browsetimeout

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for refreshtimeout

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:11:28.333 [6184.6240] checkBackupRegEntry: searching configuration for vmcloglevel

00:11:28.333 [6184.6240] RegOpenKey failed with 2

00:11:28.333 [6184.6240] SetTimeoutsAndLogging: vmcloglevel=0

00:11:28.458 [6184.6240] vmwareLogger: Login: key = 52fc5516-44c1-1f3a-55d6-fe43491c0a83

00:11:28.458 [6184.6240] dovSphereLogin: sApiType = VirtualCenter

00:11:28.458 [6184.6240] dovSphereLogin: version = 5.1

00:11:28.458 [6184.6240] dovSphereLogin: sBuild = 1064983

00:11:28.458 [6184.6240] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:11:28.458 [6184.6240] dovSphereLogin: sName = VMware vCenter Server

00:11:28.458 [6184.6240] dovSphereLogin: sOsType = win32-x64

00:11:28.458 [6184.6240] dovSphereLogin: sProductLineId = vpx

00:11:28.458 [6184.6240] dovSphereLogin: sVersion = 5.1.0

00:11:28.458 [6184.6240] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:11:28 2014

00:11:28.458 [6184.6240] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:11:28.458 [6184.6240] vmwareLogger: BuildDatabases: Building databases

00:11:34.137 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:11:34.230 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:11:34.246 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:11:34.246 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:11:34.246 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:11:34.246 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:11:34.246 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:11:34.246 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:11:34.293 [6184.6240] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:11:34.449 [6184.6240] vmwareLogger: RetrieveDcMorAndObjMorFromPath: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:11:34.449 [6184.6240] vmwareLogger: GetObjDetails: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:11:34.449 [6184.6240] find_vm_by_displayname: vmcGetObjDetails DataSet2_i failed with status 18

00:11:34.449 [6184.6240] <2> bpVMutil main: EXIT STATUS 227: no entity was found

00:11:40.423 [7008.6628] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 4352 b16-stg-esx-06.cisco.com B16-SCC-VC-1

00:11:40.423 [7008.6628] virt_test_log: log function is called

00:11:40.423 [7008.6628] <2> bpVMutil main: cmd = 17 ESXMount = b16-stg-esx-06.cisco.com ESXserver = B16-SCC-VC-1, flags = 0

00:11:40.423 [7008.6628] generateServerFiles: get_id_lock returned 0: -> wait lock timeout value: 15 minutes -> WRITE LOCK B16-SCC-VC-1_lock fd = 236 -> lockname = B16-SCC-VC-1_lock

00:11:40.423 [7008.6628] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_resp_list_b16-stg-esx-06.cisco.com.xml

00:11:40.423 [7008.6628] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_list_b16-stg-esx-06.cisco.com.xml

00:11:40.423 [7008.6628] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_net_list_b16-stg-esx-06.cisco.com.xml

00:11:40.423 [7008.6628] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_datas_tree_b16-stg-esx-06.cisco.com.xml

00:11:40.423 [7008.6628] generateServerFiles: checking file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_net_tree_b16-stg-esx-06.cisco.com.xml

00:11:40.423 [7008.6628] <2> browseNetworks: get_id_lock returned 0: -> wait lock timeout value: 30 minutes -> WRITE LOCK b16-stg-esx-06.cisco.com_lock fd = 236 -> lockname = b16-stg-esx-06.cisco.com_lock

00:11:40.439 [7008.6628] <2> browseNetworks: fileCOPY of C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\B16-SCC-VC-1_net_list_b16-stg-esx-06.cisco.com.xml to C:\Windows\TEMP\VMutl-07008391020900423628000000000-a06628 returned 0

00:11:40.439 [7008.6628] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:11:49.159 [6052.6560] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 1024 C:\Windows\TEMP\VMval-06212391020909113440000000001-a04440 B16-SCC-VC-1

00:11:49.159 [6052.6560] virt_test_log: log function is called

00:11:49.159 [6052.6560] <2> bpVMutil main: cmd = 4 ESXMount = C:\Windows\TEMP\VMval-06212391020909113440000000001-a04440 ESXserver = B16-SCC-VC-1, flags = 0

00:11:49.175 [6052.6560] <2> dumpXMLFile: <?xml version="1.0" encoding="UTF-8"?>

<VMRestoreConfiguration><VMRestoreConfigurationElement Keyword="VmRestoreType" V

00:11:49.175 [6052.6560] <2> dumpXMLFile: alue="vStorage"/><VMRestoreConfigurationElement Keyword="VmDisplayName" Value="B16-STG-048-1111"/><VMRestoreConfigurati

00:11:49.175 [6052.6560] <2> dumpXMLFile: onElement Keyword="VmUuid" Value="50248e26-0587-0b39-deaf-c34991347fa2"/><VMRestoreConfigurationElement Keyword="VmHost

00:11:49.175 [6052.6560] <2> dumpXMLFile: " Value="b16-stg-esx-06.cisco.com"/><VMRestoreConfigurationElement Keyword="Datacenter" Value="/S+CC"/><VMRestoreConfig

00:11:49.175 [6052.6560] <2> dumpXMLFile: urationElement Keyword="Folder" Value="/S+CC/vm/Staging/"/><VMRestoreConfigurationElement Keyword="Datastore" Value="ST

00:11:49.175 [6052.6560] <2> dumpXMLFile: G-SATA-B-NEW"/><VMRestoreConfigurationElement Keyword="ResourcePool" Value="/S+CC/host/5) STAGING/Resources"/><VMRestor

00:11:49.175 [6052.6560] <2> dumpXMLFile: eConfigurationElement Keyword="VmOverwrite" Value="false"/><VMRestoreConfigurationElement Keyword="VmIdentityRestore" V

00:11:49.175 [6052.6560] <2> dumpXMLFile: alue="false"/><VMRestoreConfigurationElement Keyword="TransferType" Value="san:hotadd:nbd:nbdssl"/><Datastore Name="STG

00:11:49.175 [6052.6560] <2> dumpXMLFile: -SATA-B-NEW" RequiredMbytes="102400"/><VMDK Name="STG-SATA-B-NEW\B16-STG-048\B16-STG-048.vmdk" SizeMbytes="102400"/></V

00:11:49.175 [6052.6560] <2> dumpXMLFile: MRestoreConfiguration>

00:11:49.175 [6052.6560] vm_test_restore: ESXhost = b16-stg-esx-06.cisco.com.

00:11:49.175 [6052.6560] vm_test_restore: transportTypes = san:hotadd:nbd:nbdssl.

00:11:49.175 [6052.6560] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:11:49.191 [6052.6560] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65158 TO 10.106.10.81.13720 fd = 420

00:11:49.191 [6052.6560] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:11:49.284 [6052.6560] checkBackupRegEntry: searching configuration for excludeVMservers

00:11:49.284 [6052.6560] RegOpenKey failed with 2

00:11:49.284 [6052.6560] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:11:49.284 [6052.6560] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:11:49.284 [6052.6560] getDatastoresList: Creating List of datastores on B16-SCC-VC-1 for b16-stg-esx-06.cisco.com

00:11:49.284 [6052.6560] checkBackupRegEntry: searching configuration for connecttimeout

00:11:49.284 [6052.6560] RegOpenKey failed with 2

00:11:49.284 [6052.6560] vSphereConnect: ConnectTimeout: 300 secs

00:11:49.284 [6052.6560] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:11:49.284 [6052.6560] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for jobtimeout

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for poweroptimeout

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for snapshottimeout

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for registertimeout

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for browsetimeout

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for refreshtimeout

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:11:49.549 [6052.6560] checkBackupRegEntry: searching configuration for vmcloglevel

00:11:49.549 [6052.6560] RegOpenKey failed with 2

00:11:49.549 [6052.6560] SetTimeoutsAndLogging: vmcloglevel=0

00:11:49.659 [6052.6560] vmwareLogger: Login: key = 524e4399-130f-4053-0b4d-723440c723f5

00:11:49.659 [6052.6560] dovSphereLogin: sApiType = VirtualCenter

00:11:49.659 [6052.6560] dovSphereLogin: version = 5.1

00:11:49.659 [6052.6560] dovSphereLogin: sBuild = 1064983

00:11:49.659 [6052.6560] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:11:49.659 [6052.6560] dovSphereLogin: sName = VMware vCenter Server

00:11:49.659 [6052.6560] dovSphereLogin: sOsType = win32-x64

00:11:49.659 [6052.6560] dovSphereLogin: sProductLineId = vpx

00:11:49.659 [6052.6560] dovSphereLogin: sVersion = 5.1.0

00:11:49.659 [6052.6560] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:11:49 2014

00:11:49.659 [6052.6560] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:11:49.721 [6052.6560] getStoragePodMap: get_id_lock returned 0: -> wait lock timeout value: 15 minutes -> WRITE LOCK B16-SCC-VC-1hview_lock fd = 632 -> lockname = B16-SCC-VC-1hview_lock

00:11:49.721 [6052.6560] checkBackupRegEntry: searching configuration for xmlCacheLimit

00:11:49.721 [6052.6560] RegOpenKey failed with 2

00:11:49.737 [6052.6560] vmwareLogger: BuildDatabases: Building databases

00:11:55.446 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:11:55.540 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:11:55.540 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:11:55.540 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:11:55.540 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:11:55.555 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:11:55.555 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:11:55.555 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:11:55.587 [6052.6560] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:11:55.743 [6052.6560] vmwareLogger: BuildDatabases: Building databases

00:11:55.743 [6052.6560] validateFolderPath: Folder path is /S+CC/vm/Staging/

00:12:00.703 [6052.6560] vmwareLogger: WaitForTaskCompleteEx: reached Error!

00:12:00.703 [6052.6560] vmwareLogger: WaitForTaskCompleteEx: File [STG-SATA-B-NEW]B16-STG-048-1111 was not found <184>

00:12:00.703 [6052.6560] vmwareLogger: WaitForTaskCompleteEx: SYM_VMC_ERROR: TASK_REACHED_ERROR_STATE

00:12:00.703 [6052.6560] validateOverwrite: Validate datastore path - host = b16-stg-esx-06.cisco.com, dcpath = [STG-SATA-B-NEW]B16-STG-048-1111.

00:12:05.992 [6052.6560] vmwareLogger: WaitForTaskCompleteEx: reached Error!

00:12:05.992 [6052.6560] vmwareLogger: WaitForTaskCompleteEx: File [STG-SATA-B-NEW]B16-STG-048-1111 was not found <184>

00:12:05.992 [6052.6560] vmwareLogger: WaitForTaskCompleteEx: SYM_VMC_ERROR: TASK_REACHED_ERROR_STATE

00:12:05.992 [6052.6560] validateOverwrite: Validate datastore path - host = b16-stg-esx-06.cisco.com, dcpath = [STG-SATA-B-NEW]B16-STG-048-1111.

00:12:05.992 [6052.6560] validateOverwrite: bVmXdirExists = 0.

00:12:05.992 [6052.6560] find_vm_by_displayname: Looking for B16-STG-048-1111

00:12:05.992 [6052.6560] dovSphereLogin: server B16-SCC-VC-1 already logged in

00:12:05.992 [6052.6560] vmwareLogger: RetrieveDcMorAndObjMorFromPath: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:12:05.992 [6052.6560] vmwareLogger: GetObjDetails: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:12:05.992 [6052.6560] find_vm_by_displayname: vmcGetObjDetails DataSet2_i failed with status 18

00:12:05.992 [6052.6560] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\07d\bc18f27d+0,1,2,0,1,0+b16-scc-vc-1.txt

00:12:06.007 [6052.6560] checkBackupRegEntry: searching configuration for connecttimeout

00:12:06.007 [6052.6560] RegOpenKey failed with 2

00:12:06.007 [6052.6560] vSphereConnect: ConnectTimeout: 300 secs

00:12:06.007 [6052.6560] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:12:06.023 [6052.6560] vmwareLogger: Logout: returned 0

00:12:06.273 [6052.6560] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for jobtimeout

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for poweroptimeout

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for snapshottimeout

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for registertimeout

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for browsetimeout

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for refreshtimeout

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:12:06.288 [6052.6560] checkBackupRegEntry: searching configuration for vmcloglevel

00:12:06.288 [6052.6560] RegOpenKey failed with 2

00:12:06.288 [6052.6560] SetTimeoutsAndLogging: vmcloglevel=0

00:12:06.366 [6052.6560] vmwareLogger: Login: key = 52d5098b-b5b8-dbc3-ff13-561499f38d7f

00:12:06.366 [6052.6560] vmwareLogger: Logout: returned 0

00:12:06.366 [6052.6560] <2> cmn_test_VM_cred: Verified credentials with VIX API

00:12:06.366 [6052.6560] vm_test_restore: Done Saved XML to C:\Windows\TEMP\VMutl-06052391020909175560000000000-a06560

00:12:06.366 [6052.6560] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:12:06.366 [6052.6560] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:13:09.998 [6180.5540] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 1024 C:\Windows\TEMP\VMval-03332391020989952932000000001-a06932 B16-SCC-VC-1

00:13:09.998 [6180.5540] virt_test_log: log function is called

00:13:09.998 [6180.5540] <2> bpVMutil main: cmd = 4 ESXMount = C:\Windows\TEMP\VMval-03332391020989952932000000001-a06932 ESXserver = B16-SCC-VC-1, flags = 0

00:13:09.998 [6180.5540] <2> dumpXMLFile: <?xml version="1.0" encoding="UTF-8"?>

<VMRestoreConfiguration><VMRestoreConfigurationElement Keyword="VmRestoreType" V

00:13:09.998 [6180.5540] <2> dumpXMLFile: alue="vStorage"/><VMRestoreConfigurationElement Keyword="VmDisplayName" Value="B16-STG-048-1111"/><VMRestoreConfigurati

00:13:09.998 [6180.5540] <2> dumpXMLFile: onElement Keyword="VmUuid" Value="50248e26-0587-0b39-deaf-c34991347fa2"/><VMRestoreConfigurationElement Keyword="VmHost

00:13:09.998 [6180.5540] <2> dumpXMLFile: " Value="b16-stg-esx-06.cisco.com"/><VMRestoreConfigurationElement Keyword="Datacenter" Value="/S+CC"/><VMRestoreConfig

00:13:09.998 [6180.5540] <2> dumpXMLFile: urationElement Keyword="Folder" Value="/S+CC/vm/Staging/"/><VMRestoreConfigurationElement Keyword="Datastore" Value="ST

00:13:09.998 [6180.5540] <2> dumpXMLFile: G-SATA-B-NEW"/><VMRestoreConfigurationElement Keyword="ResourcePool" Value="/S+CC/host/5) STAGING/Resources"/><VMRestor

00:13:09.998 [6180.5540] <2> dumpXMLFile: eConfigurationElement Keyword="VmOverwrite" Value="false"/><VMRestoreConfigurationElement Keyword="VmIdentityRestore" V

00:13:09.998 [6180.5540] <2> dumpXMLFile: alue="false"/><VMRestoreConfigurationElement Keyword="TransferType" Value="san:hotadd:nbd:nbdssl"/><Datastore Name="STG

00:13:09.998 [6180.5540] <2> dumpXMLFile: -SATA-B-NEW" RequiredMbytes="102400"/><VMDK Name="STG-SATA-B-NEW\B16-STG-048\B16-STG-048.vmdk" SizeMbytes="102400"/></V

00:13:09.998 [6180.5540] <2> dumpXMLFile: MRestoreConfiguration>

00:13:09.998 [6180.5540] vm_test_restore: ESXhost = b16-stg-esx-06.cisco.com.

00:13:09.998 [6180.5540] vm_test_restore: transportTypes = san:hotadd:nbd:nbdssl.

00:13:09.998 [6180.5540] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:13:10.014 [6180.5540] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65181 TO 10.106.10.81.13720 fd = 420

00:13:10.014 [6180.5540] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:13:10.108 [6180.5540] checkBackupRegEntry: searching configuration for excludeVMservers

00:13:10.108 [6180.5540] RegOpenKey failed with 2

00:13:10.108 [6180.5540] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:13:10.108 [6180.5540] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:10.108 [6180.5540] getDatastoresList: Creating List of datastores on B16-SCC-VC-1 for b16-stg-esx-06.cisco.com

00:13:10.108 [6180.5540] checkBackupRegEntry: searching configuration for connecttimeout

00:13:10.108 [6180.5540] RegOpenKey failed with 2

00:13:10.108 [6180.5540] vSphereConnect: ConnectTimeout: 300 secs

00:13:10.108 [6180.5540] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:13:10.108 [6180.5540] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for jobtimeout

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for poweroptimeout

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for snapshottimeout

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for registertimeout

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for browsetimeout

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for refreshtimeout

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:13:10.342 [6180.5540] checkBackupRegEntry: searching configuration for vmcloglevel

00:13:10.342 [6180.5540] RegOpenKey failed with 2

00:13:10.342 [6180.5540] SetTimeoutsAndLogging: vmcloglevel=0

00:13:10.466 [6180.5540] vmwareLogger: Login: key = 52f92822-c4de-7ea0-e73f-43a62ed8ad5d

00:13:10.466 [6180.5540] dovSphereLogin: sApiType = VirtualCenter

00:13:10.466 [6180.5540] dovSphereLogin: version = 5.1

00:13:10.466 [6180.5540] dovSphereLogin: sBuild = 1064983

00:13:10.466 [6180.5540] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:13:10.466 [6180.5540] dovSphereLogin: sName = VMware vCenter Server

00:13:10.466 [6180.5540] dovSphereLogin: sOsType = win32-x64

00:13:10.466 [6180.5540] dovSphereLogin: sProductLineId = vpx

00:13:10.466 [6180.5540] dovSphereLogin: sVersion = 5.1.0

00:13:10.466 [6180.5540] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:13:10 2014

00:13:10.466 [6180.5540] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:13:10.529 [6180.5540] getStoragePodMap: get_id_lock returned 0: -> wait lock timeout value: 15 minutes -> WRITE LOCK B16-SCC-VC-1hview_lock fd = 636 -> lockname = B16-SCC-VC-1hview_lock

00:13:10.529 [6180.5540] checkBackupRegEntry: searching configuration for xmlCacheLimit

00:13:10.529 [6180.5540] RegOpenKey failed with 2

00:13:10.544 [6180.5540] vmwareLogger: BuildDatabases: Building databases

00:13:16.160 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:13:16.254 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:13:16.270 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:13:16.270 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:13:16.270 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:13:16.270 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:13:16.270 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:13:16.270 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:13:16.301 [6180.5540] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:13:16.457 [6180.5540] vmwareLogger: BuildDatabases: Building databases

00:13:16.457 [6180.5540] validateFolderPath: Folder path is /S+CC/vm/Staging/

00:13:21.402 [6180.5540] vmwareLogger: WaitForTaskCompleteEx: reached Error!

00:13:21.402 [6180.5540] vmwareLogger: WaitForTaskCompleteEx: File [STG-SATA-B-NEW]B16-STG-048-1111 was not found <184>

00:13:21.402 [6180.5540] vmwareLogger: WaitForTaskCompleteEx: SYM_VMC_ERROR: TASK_REACHED_ERROR_STATE

00:13:21.402 [6180.5540] validateOverwrite: Validate datastore path - host = b16-stg-esx-06.cisco.com, dcpath = [STG-SATA-B-NEW]B16-STG-048-1111.

00:13:26.378 [6180.5540] vmwareLogger: WaitForTaskCompleteEx: reached Error!

00:13:26.378 [6180.5540] vmwareLogger: WaitForTaskCompleteEx: File [STG-SATA-B-NEW]B16-STG-048-1111 was not found <184>

00:13:26.378 [6180.5540] vmwareLogger: WaitForTaskCompleteEx: SYM_VMC_ERROR: TASK_REACHED_ERROR_STATE

00:13:26.378 [6180.5540] validateOverwrite: Validate datastore path - host = b16-stg-esx-06.cisco.com, dcpath = [STG-SATA-B-NEW]B16-STG-048-1111.

00:13:26.378 [6180.5540] validateOverwrite: bVmXdirExists = 0.

00:13:26.378 [6180.5540] find_vm_by_displayname: Looking for B16-STG-048-1111

00:13:26.378 [6180.5540] dovSphereLogin: server B16-SCC-VC-1 already logged in

00:13:26.378 [6180.5540] vmwareLogger: RetrieveDcMorAndObjMorFromPath: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:13:26.378 [6180.5540] vmwareLogger: GetObjDetails: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:13:26.378 [6180.5540] find_vm_by_displayname: vmcGetObjDetails DataSet2_i failed with status 18

00:13:26.378 [6180.5540] checkBackupRegEntry: searching configuration for connecttimeout

00:13:26.378 [6180.5540] RegOpenKey failed with 2

00:13:26.378 [6180.5540] vSphereConnect: ConnectTimeout: 300 secs

00:13:26.378 [6180.5540] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:13:26.394 [6180.5540] vmwareLogger: Logout: returned 0

00:13:26.612 [6180.5540] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for jobtimeout

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for poweroptimeout

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for snapshottimeout

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for registertimeout

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for browsetimeout

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for refreshtimeout

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:13:26.628 [6180.5540] checkBackupRegEntry: searching configuration for vmcloglevel

00:13:26.628 [6180.5540] RegOpenKey failed with 2

00:13:26.628 [6180.5540] SetTimeoutsAndLogging: vmcloglevel=0

00:13:26.690 [6180.5540] vmwareLogger: Login: key = 52d37f95-9191-8a84-568e-862ec43036ef

00:13:26.690 [6180.5540] vmwareLogger: Logout: returned 0

00:13:26.690 [6180.5540] <2> cmn_test_VM_cred: Verified credentials with VIX API

00:13:26.690 [6180.5540] vm_test_restore: Done Saved XML to C:\Windows\TEMP\VMutl-06180391020989998540000000000-a05540

00:13:26.706 [6180.5540] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:26.706 [6180.5540] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:13:44.412 [7084.6516] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 1584 san-hotadd-nbd-nbdssl:b16-stg-esx-06.cisco.com:4224274e-5779-92dd-cd8b-848c900a79c3:B16-STG-048:B16-STG-048_1390933807 B16-SCC-VC-1

00:13:44.412 [7084.6516] virt_test_log: log function is called

00:13:44.412 [7084.6516] <2> bpVMutil main: cmd = 6 ESXMount = san-hotadd-nbd-nbdssl:b16-stg-esx-06.cisco.com:4224274e-5779-92dd-cd8b-848c900a79c3:B16-STG-048:B16-STG-048_1390933807 ESXserver = B16-SCC-VC-1, flags = 48

00:13:44.412 [7084.6516] <2> bpVMutil main: VMuuid 4224274e-5779-92dd-cd8b-848c900a79c3 VMesxhost b16-stg-esx-06.cisco.com VMDisplayName B16-STG-048 VMBackupID B16-STG-048_1390933807 transport mode san-hotadd-nbd-nbdssl

00:13:44.412 [7084.6516] <2> bpVMutil main: XML file is C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\VMXml_B16-STG-048_1390933807.xml

00:13:44.412 [7084.6516] <2> bpVMutil main: Vix file is C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\VMVix_B16-STG-048_1390933807.xml

00:13:44.412 [7084.6516] <2> bpVMutil main: Reading XML...

00:13:44.412 [7084.6516] <2> bpVMutil main: XML read 20128 bytes.

00:13:44.412 [7084.6516] <2> bpVMutil main: renameString read 198 bytes.

00:13:44.412 [7084.6516] <2> bpVMutil main: renameString esxhost=b16-stg-esx-06.cisco.com;datacenter=/S+CC;datastore=STG-SATA-B-NEW;vmname=B16-STG-048-1111;resourcepool=/S+CC/host/5) STAGING/Resources;folder=/S+CC/vm/Staging/;diskdatastores=STG-SATA-B-NEW

00:13:44.412 [7084.6516] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:13:44.427 [7084.6516] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65255 TO 10.106.10.81.13720 fd = 424

00:13:44.427 [7084.6516] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:13:44.521 [7084.6516] checkBackupRegEntry: searching configuration for excludeVMservers

00:13:44.521 [7084.6516] RegOpenKey failed with 2

00:13:44.521 [7084.6516] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:13:44.521 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:44.521 [7084.6516] find_vm_by_displayname: Looking for B16-STG-048-1111

00:13:44.521 [7084.6516] checkBackupRegEntry: searching configuration for connecttimeout

00:13:44.521 [7084.6516] RegOpenKey failed with 2

00:13:44.521 [7084.6516] vSphereConnect: ConnectTimeout: 300 secs

00:13:44.521 [7084.6516] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:13:44.521 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for jobtimeout

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for poweroptimeout

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for snapshottimeout

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for registertimeout

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for browsetimeout

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for refreshtimeout

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:13:44.755 [7084.6516] checkBackupRegEntry: searching configuration for vmcloglevel

00:13:44.755 [7084.6516] RegOpenKey failed with 2

00:13:44.755 [7084.6516] SetTimeoutsAndLogging: vmcloglevel=0

00:13:44.849 [7084.6516] vmwareLogger: Login: key = 52569405-84eb-2a4f-639e-0f2680a10b4b

00:13:44.849 [7084.6516] dovSphereLogin: sApiType = VirtualCenter

00:13:44.849 [7084.6516] dovSphereLogin: version = 5.1

00:13:44.849 [7084.6516] dovSphereLogin: sBuild = 1064983

00:13:44.849 [7084.6516] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:13:44.849 [7084.6516] dovSphereLogin: sName = VMware vCenter Server

00:13:44.849 [7084.6516] dovSphereLogin: sOsType = win32-x64

00:13:44.849 [7084.6516] dovSphereLogin: sProductLineId = vpx

00:13:44.849 [7084.6516] dovSphereLogin: sVersion = 5.1.0

00:13:44.849 [7084.6516] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:13:45 2014

00:13:44.849 [7084.6516] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:13:44.849 [7084.6516] vmwareLogger: BuildDatabases: Building databases

00:13:50.465 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:13:50.558 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:13:50.574 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:13:50.574 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:13:50.574 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:13:50.574 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:13:50.574 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:13:50.574 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:13:50.621 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:13:50.761 [7084.6516] vmwareLogger: RetrieveDcMorAndObjMorFromPath: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:13:50.761 [7084.6516] vmwareLogger: GetObjDetails: SYM_VMC_ERROR: FAILED_TO_GET_MOB

00:13:50.761 [7084.6516] find_vm_by_displayname: vmcGetObjDetails DataSet2_i failed with status 18

00:13:50.761 [7084.6516] <2> find_vm_by_displayname returned 18: bpVMutil

00:13:50.761 [7084.6516] checkBackupRegEntry: searching configuration for addRestoreDisks

00:13:50.761 [7084.6516] RegOpenKey failed with 2

00:13:50.761 [7084.6516] <2> createVMwareVM: createVMwareVM: original format disks requested

00:13:50.761 [7084.6516] <2> createVMwareVM: createVMwareVM: Ignore attached devices that have a file connected

00:13:50.761 [7084.6516] <2> createVMwareVM: createVMwareVM: Using transport mode san-hotadd-nbd-nbdssl

00:13:50.761 [7084.6516] <2> createVMwareVM: createVMwareVM: Evaluating renameString esxhost=b16-stg-esx-06.cisco.com;datacenter=/S+CC;datastore=STG-SATA-B-NEW;vmname=B16-STG-048-1111;resourcepool=/S+CC/host/5) STAGING/Resources;folder=/S+CC/vm/Staging/;diskdatastores=STG-SATA-B-NEW

00:13:50.761 [7084.6516] <2> createVMwareVM: Adding diskDataStores 0 = STG-SATA-B-NEW

00:13:50.761 [7084.6516] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:13:50.777 [7084.6516] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65261 TO 10.106.10.81.13720 fd = 644

00:13:50.777 [7084.6516] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:13:50.870 [7084.6516] checkBackupRegEntry: searching configuration for excludeVMservers

00:13:50.870 [7084.6516] RegOpenKey failed with 2

00:13:50.870 [7084.6516] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:13:50.870 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:50.870 [7084.6516] find_virtual_server_cred: Looking for: b16-stg-esx-06.cisco.com

00:13:50.870 [7084.6516] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65265 TO 10.106.10.81.13720 fd = 640

00:13:50.870 [7084.6516] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:13:50.964 [7084.6516] checkBackupRegEntry: searching configuration for excludeVMservers

00:13:50.964 [7084.6516] RegOpenKey failed with 2

00:13:50.964 [7084.6516] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:13:50.964 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:50.964 [7084.6516] find_virtual_server_cred: Couldn't find b16-stg-esx-06.cisco.com

00:13:50.964 [7084.6516] <2> createVMwareVM: find credential failed for ESX host b16-stg-esx-06.cisco.com using B16-SCC-VC-1

00:13:50.964 [7084.6516] checkBackupRegEntry: searching configuration for UseDiskControllerPrefix

00:13:50.964 [7084.6516] RegOpenKey failed with 2

00:13:50.964 [7084.6516] checkBackupRegEntry: searching configuration for IgnoreAttachedDevices

00:13:50.964 [7084.6516] RegOpenKey failed with 2

00:13:50.964 [7084.6516] checkBackupRegEntry: searching configuration for connecttimeout

00:13:50.964 [7084.6516] RegOpenKey failed with 2

00:13:50.964 [7084.6516] vSphereConnect: ConnectTimeout: 300 secs

00:13:50.964 [7084.6516] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:13:50.964 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for jobtimeout

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for poweroptimeout

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for snapshottimeout

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for registertimeout

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for browsetimeout

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for refreshtimeout

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:13:50.979 [7084.6516] checkBackupRegEntry: searching configuration for vmcloglevel

00:13:50.979 [7084.6516] RegOpenKey failed with 2

00:13:50.979 [7084.6516] SetTimeoutsAndLogging: vmcloglevel=0

00:13:51.042 [7084.6516] vmwareLogger: Login: key = 52140635-5a74-76a3-816f-1627e36d5672

00:13:51.057 [7084.6516] dovSphereLogin: sApiType = VirtualCenter

00:13:51.057 [7084.6516] dovSphereLogin: version = 5.1

00:13:51.057 [7084.6516] dovSphereLogin: sBuild = 1064983

00:13:51.057 [7084.6516] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:13:51.057 [7084.6516] dovSphereLogin: sName = VMware vCenter Server

00:13:51.057 [7084.6516] dovSphereLogin: sOsType = win32-x64

00:13:51.057 [7084.6516] dovSphereLogin: sProductLineId = vpx

00:13:51.057 [7084.6516] dovSphereLogin: sVersion = 5.1.0

00:13:51.057 [7084.6516] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:13:51 2014

00:13:51.057 [7084.6516] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:13:51.057 [7084.6516] <2> createVMwareVM: working datacenter set to /S+CC

00:13:51.057 [7084.6516] <2> createVMwareVM: vmcCreateVirtualMachineEx arguments:

00:13:51.057 [7084.6516] <2> createVMwareVM: Client = B16-SCC-VC-1

00:13:51.057 [7084.6516] <2> createVMwareVM: vmName = B16-STG-048-1111

00:13:51.057 [7084.6516] <2> createVMwareVM: hostName = b16-stg-esx-06.cisco.com

00:13:51.057 [7084.6516] <2> createVMwareVM: folder = /S+CC/vm/Staging/

00:13:51.057 [7084.6516] <2> createVMwareVM: resourcePoolPath = /S+CC/host/5) STAGING/Resources

00:13:51.057 [7084.6516] <2> createVMwareVM: VM version = NULL

00:13:51.057 [7084.6516] <2> createVMwareVM: vmDatastoreName = STG-SATA-B-NEW

00:13:51.057 [7084.6516] <2> createVMwareVM: diskDatastores[0] = STG-SATA-B-NEW

00:13:51.057 [7084.6516] <2> createVMwareVM: bThinProvision = 0

00:13:51.057 [7084.6516] <2> createVMwareVM: bEagerlyScrub = 0

00:13:51.057 [7084.6516] <2> createVMwareVM: bWriteThrough = 0

00:13:51.057 [7084.6516] <2> createVMwareVM: bKeepExistingUuid = 0

00:13:51.057 [7084.6516] <2> createVMwareVM: bPreserveNics = 1

00:13:51.057 [7084.6516] <2> createVMwareVM: bStripNetworks = 1

00:13:51.057 [7084.6516] <2> createVMwareVM: bUseVmDatastoreForDisks = 0

00:13:51.057 [7084.6516] vmwareLogger: BuildDatabases: Building databases

00:13:55.332 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:13:55.347 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:13:55.347 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:13:55.347 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:13:55.347 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:13:55.347 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:13:55.347 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:13:55.379 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:13:55.425 [7084.6516] vmwareLogger: BuildDatabases: Building databases

00:13:55.457 [7084.6516] vmwareLogger: CreateVirtualMachine: Setting VM version to 'vmx-08' since host is version 51

00:13:55.550 [7084.6516] vmwareLogger: PopulateConfigSpec: Skipping CdRom device with ISO file

00:13:55.550 [7084.6516] vmwareLogger: GetResourcePoolPath: /S+CC/host/5) STAGING/Resources

00:13:55.550 [7084.6516] vmwareLogger: CreateVirtualMachine: DRSenabled=false, pod=Null, IsVC=true, version=51

00:13:55.550 [7084.6516] vmwareLogger: IsResourcePoolInAVapp: No

00:13:55.550 [7084.6516] vmwareLogger: CreateVm: entered

00:13:59.497 [7084.6516] vmwareLogger: BuildDatabases: Building databases

00:14:03.771 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:14:03.787 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:14:03.787 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:14:03.787 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:14:03.787 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:14:03.787 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:14:03.787 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:14:03.818 [7084.6516] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:14:03.865 [7084.6516] <2> createVMwareVM: Created VM; sVMMorName: vm-9177, xmlFile: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\VMXml_B16-STG-048_1390933807.xml

00:14:03.881 [7084.6516] <2> createVMwareVM: createVMwareVM: VMpath = /vminstuuid/5024757b-583c-a456-cf04-796c3356e1cb

00:14:03.881 [7084.6516] <2> createVMwareVM: createVMwareVM: moref = moref=vm-9177

00:14:03.881 [7084.6516] restore_freeze: gethostname returned 0 scc-nbu

00:14:03.881 [7084.6516] restore_freeze: freezing /vminstuuid/5024757b-583c-a456-cf04-796c3356e1cb

00:14:03.881 [7084.6516] restore_freeze: logged in to B16-SCC-VC-1

00:14:03.881 [7084.6516] restore_freeze: VMpath = /vminstuuid/5024757b-583c-a456-cf04-796c3356e1cb

00:14:03.896 [7084.6516] restore_freeze: returned from vmcGetObjectInfo status 0

00:14:03.896 [7084.6516] restore_freeze: calling getVMdetails

00:14:03.896 [7084.6516] getVMdetails: powerState = poweredOff

00:14:03.896 [7084.6516] getVMdetails: Found 0 snapshots

00:14:03.896 [7084.6516] restore_freeze: getVMdetails returned 0

00:14:03.896 [7084.6516] restore_freeze: templatePath = (null)

00:14:03.896 [7084.6516] restore_freeze: creating snapshot for /vminstuuid/5024757b-583c-a456-cf04-796c3356e1cb

00:15:01.039 [7084.6516] restore_freeze: freeze returned 0

00:15:01.039 [7084.6516] restore_freeze: path = C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\VMVix_B16-STG-048_1390933807.xml

00:15:01.039 [7084.6516] restore_freeze: Using transport mode string san:hotadd:nbd:nbdssl

00:15:01.070 [7084.6516] restore_freeze: vmcGetObjDetails of /vminstuuid/5024757b-583c-a456-cf04-796c3356e1cb returned 0

00:15:01.101 [7084.6516] restore_freeze: vmcGetAllSnapshotDiskDetails returned 0

00:15:01.101 [7084.6516] restore_freeze: found 1 files

00:15:01.101 [7084.6516] restore_freeze: snapmor snapshot-9178

00:15:01.101 [7084.6516] restore_freeze: Adding disks in ascending order

00:15:01.101 [7084.6516] restore_freeze: 0 found STG-SATA-B-NEW datastore

00:15:01.101 [7084.6516] restore_freeze: 0 found [STG-SATA-B-NEW] B16-STG-048-1111/B16-STG-048-1111.vmdk file name

00:15:01.101 [7084.6516] restore_freeze: 0 found Hard disk 1 disk label

00:15:01.101 [7084.6516] restore_freeze: 0 found scsi0-0 disk ctlr

00:15:01.101 [7084.6516] restore_freeze: 0 found Mode persistent

00:15:01.101 [7084.6516] restore_freeze: 0 found capacity 104857600

00:15:01.101 [7084.6516] restore_freeze: 0 found unit number 0

00:15:01.101 [7084.6516] restore_freeze: 0 found key 2000

00:15:01.101 [7084.6516] restore_freeze: 0 found controllerkey 1000

00:15:01.101 [7084.6516] restore_freeze: 0 found diskUUID 6000C29e-482c-ebe9-140e-17e58480933c

00:15:01.101 [7084.6516] restore_freeze: 0 found compatibility mode: dependent

00:15:01.117 [7084.6516] vmwareLogger: Logout: returned 0

00:15:01.257 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:15:01.257 [7084.6516] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:15:01.257 [7084.6516] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65273 TO 10.106.10.81.13720 fd = 624

00:15:01.257 [7084.6516] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:15:01.351 [7084.6516] checkBackupRegEntry: searching configuration for excludeVMservers

00:15:01.351 [7084.6516] RegOpenKey failed with 2

00:15:01.351 [7084.6516] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:15:01.351 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:15:01.351 [7084.6516] checkBackupRegEntry: searching configuration for connecttimeout

00:15:01.351 [7084.6516] RegOpenKey failed with 2

00:15:01.351 [7084.6516] vSphereConnect: ConnectTimeout: 300 secs

00:15:01.351 [7084.6516] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:15:01.351 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for jobtimeout

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for poweroptimeout

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for snapshottimeout

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for registertimeout

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for browsetimeout

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for refreshtimeout

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:15:01.366 [7084.6516] checkBackupRegEntry: searching configuration for vmcloglevel

00:15:01.366 [7084.6516] RegOpenKey failed with 2

00:15:01.366 [7084.6516] SetTimeoutsAndLogging: vmcloglevel=0

00:15:01.507 [7084.6516] vmwareLogger: Login: key = 52cdfe66-40f6-6925-88f3-90456affa2db

00:15:01.507 [7084.6516] dovSphereLogin: sApiType = VirtualCenter

00:15:01.507 [7084.6516] dovSphereLogin: version = 5.1

00:15:01.507 [7084.6516] dovSphereLogin: sBuild = 1064983

00:15:01.507 [7084.6516] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:15:01.507 [7084.6516] dovSphereLogin: sName = VMware vCenter Server

00:15:01.507 [7084.6516] dovSphereLogin: sOsType = win32-x64

00:15:01.507 [7084.6516] dovSphereLogin: sProductLineId = vpx

00:15:01.507 [7084.6516] dovSphereLogin: sVersion = 5.1.0

00:15:01.507 [7084.6516] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:15:01 2014

00:15:01.507 [7084.6516] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:15:01.522 [7084.6516] vddkLog: VixDiskLib: config options: libdir 'C:\Program Files\Common Files\VERITAS\VxMS\Shared\VDDK', tmpDir 'C:\Windows\TEMP\vmware-SYSTEM'.

00:15:01.522 [7084.6516] vddkLog: VixDiskLib: Attempting to locate advanced transport module in "C:\Program Files\Common Files\VERITAS\VxMS\Shared\VDDK\plugins".

00:15:01.600 [7084.6516] vddkLog: VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib.

00:15:01.600 [7084.6516] vddkLog: VixDiskLib: Enabling advanced transport modes.

00:15:01.600 [7084.6516] vddkLog: VixDiskLib: Transport modes available: file:nbdssl:nbd:san.

00:15:01.600 [7084.6516] vddkLog: VMware VixDiskLib (5.0) Release build-427917

00:15:01.756 [7084.6516] vddkLog: POLL Using the WSAPoll API Implementation for PollDefault

00:15:01.756 [7084.6516] lockVM: Calling VixDiskLib_PrepareForAccess

00:15:01.756 [7084.6516] vddkLog: VixDiskLibVimResolveHostName: Resolving IP address for hostname B16-SCC-VC-1.

00:15:01.756 [7084.6516] vddkLog: VixDiskLibVimResolveHostName: Resolved to 10.106.10.85.

00:15:01.756 [7084.6516] vddkLog: HOSTINFO 870921587687 @ 14318180Hz -> 0 @ 1000000000Hz

00:15:01.756 [7084.6516] vddkLog: HOSTINFO ((x * 2343484437) >> 25) + -60826277333254

00:15:01.756 [7084.6516] vddkLog: VixDiskLibVim: VixDiskLibVimLogin

00:15:01.772 [7084.6360] vddkLog: VThreadBase detected multiple threads.

00:15:02.786 [7084.6516] vddkLog: VixDiskLibVim: TicketFindVMByMoRef: vmxPath = -vm-9177-

00:15:02.786 [7084.6516] vddkLog: VixDiskLibVim: VixDiskLibVimLoadVM

00:15:03.035 [7084.6516] vddkLog: VixDiskLibVim: VixDiskLibVimLoadAuthMgr

00:15:03.035 [7084.6516] vddkLog: VixDiskLibVim: VixDiskLibVimLoadVMCb

00:15:03.301 [7084.6516] vddkLog: VixDiskLibVim: VixDiskLibVimLogout

00:15:03.519 [7084.6516] lockVM: VixDiskLib_PrepareForAccess returned:0 [The operation was successful]

00:15:03.519 [7084.6516] vddkLog: VixDiskLib: VixDiskLib_Exit called. Unmatched Init calls so far: 1.

00:15:03.519 [7084.6516] vddkLog: diskLibPlugin: 2014-01-30T00:15:03.519+05:30 [06516 trivia 'Default'] Starting to shut down worker thread pool.

00:15:04.533 [7084.6516] vddkLog: diskLibPlugin: 2014-01-30T00:15:04.533+05:30 [06516 trivia 'Default'] Worker thread pool is shut down.

00:15:04.533 [7084.6516] vmwareLogger: Logout: returned 0

00:15:04.533 [7084.6516] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:15:04.533 [7084.6516] checkBackupRegEntry: searching configuration for KeepVMXmlFiles

00:15:04.533 [7084.6516] RegOpenKey failed with 2

00:15:04.533 [7084.6516] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

00:15:28.557 [7108.7028] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpVMutil.exe 2050 B16-STG-048_1390933807 B16-SCC-VC-1

00:15:28.572 [7108.7028] virt_test_log: log function is called

00:15:28.572 [7108.7028] <2> bpVMutil main: cmd = 8 ESXMount = B16-STG-048_1390933807 ESXserver = B16-SCC-VC-1, flags = 2

00:15:28.572 [7108.7028] <2> bpVMutil main: Vix file is C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\VMVix_B16-STG-048_1390933807.xml

00:15:28.572 [7108.7028] <2> deleteVMwareSnapshot: deleteVMwareSnapshot: Virtual machine UUID path: /vminstuuid/5024757b-583c-a456-cf04-796c3356e1cb

00:15:28.572 [7108.7028] find_virtual_server_cred: Looking for: B16-SCC-VC-1

00:15:28.588 [7108.7028] <2> logconnections: BPRD CONNECT FROM 10.106.10.81.65330 TO 10.106.10.81.13720 fd = 424

00:15:28.588 [7108.7028] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2

00:15:28.713 [7108.7028] checkBackupRegEntry: searching configuration for excludeVMservers

00:15:28.713 [7108.7028] RegOpenKey failed with 2

00:15:28.713 [7108.7028] format_virtualserver_cred: read 1 B16-SCC-VC-1 scc-netbackup af1775bc1d4e917f2c49c7732268a553d2030dbe9e8b7ddbb1915e9e107730808af2f286f7d3bc0da233f80dbe1fdd26c206918abcec6cea95ff870c4b0a49c0 18175 0

00:15:28.713 [7108.7028] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:15:28.713 [7108.7028] checkBackupRegEntry: searching configuration for connecttimeout

00:15:28.713 [7108.7028] RegOpenKey failed with 2

00:15:28.713 [7108.7028] vSphereConnect: ConnectTimeout: 300 secs

00:15:28.713 [7108.7028] vSphereConnect: connecting to https://B16-SCC-VC-1/sdk

00:15:28.713 [7108.7028] dovSphereDisconnect: disconnect for B16-SCC-VC-1 completed with flags 0 and status 0

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for jobtimeout

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for poweroptimeout

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for snapshottimeout

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for registertimeout

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for browsetimeout

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for refreshtimeout

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: JobTimeout: 900 secs

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: PowerOpTimeout: 900 secs

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: SnapshotTimeout: 900 secs

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: RegisterTimeout: 180 secs

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: BrowseTimeout: 3 secs

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: RefreshTimeout: 3 secs

00:15:28.962 [7108.7028] checkBackupRegEntry: searching configuration for vmcloglevel

00:15:28.962 [7108.7028] RegOpenKey failed with 2

00:15:28.962 [7108.7028] SetTimeoutsAndLogging: vmcloglevel=0

00:15:29.025 [7108.7028] vmwareLogger: Login: key = 52feb2bb-0a64-64f9-c30e-d9f4980457fd

00:15:29.025 [7108.7028] dovSphereLogin: sApiType = VirtualCenter

00:15:29.025 [7108.7028] dovSphereLogin: version = 5.1

00:15:29.025 [7108.7028] dovSphereLogin: sBuild = 1064983

00:15:29.025 [7108.7028] dovSphereLogin: full name = VMware vCenter Server 5.1.0 build-1064983

00:15:29.025 [7108.7028] dovSphereLogin: sName = VMware vCenter Server

00:15:29.025 [7108.7028] dovSphereLogin: sOsType = win32-x64

00:15:29.025 [7108.7028] dovSphereLogin: sProductLineId = vpx

00:15:29.025 [7108.7028] dovSphereLogin: sVersion = 5.1.0

00:15:29.025 [7108.7028] dovSphereLogin: sServerCurrentTime = Thu Jan 30 00:15:29 2014

00:15:29.025 [7108.7028] dovSphereLogin: login for B16-SCC-VC-1 completed with flags 70 and status 0

00:15:29.025 [7108.7028] vmwareLogger: BuildDatabases: Building databases

00:15:34.688 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:15:34.781 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:15:34.781 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:15:34.781 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:15:34.781 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:15:34.781 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:15:34.781 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:15:34.797 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:15:34.828 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:15:34.984 [7108.7028] <2> deleteVMwareSnapshot: deleteVMwareSnapshot: moref = moref=vm-9177

00:15:34.984 [7108.7028] checkBackupRegEntry: searching configuration for keepvmonerror

00:15:34.984 [7108.7028] RegOpenKey failed with 2

00:16:40.316 [7108.7028] vmwareLogger: SetVmPowerState: destroy: Completed OK

00:16:40.519 [7108.7028] vmwareLogger: BuildDatabases: Building databases

00:16:46.213 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-17.cisco.com> because state is notResponding

00:16:46.307 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-12.cisco.com> because state is notResponding

00:16:46.322 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-02.cisco.com> because state is notResponding

00:16:46.322 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-03.cisco.com> because state is notResponding

00:16:46.322 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-04.cisco.com> because state is notResponding

00:16:46.322 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-07.cisco.com> because state is notResponding

00:16:46.322 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-08.cisco.com> because state is notResponding

00:16:46.338 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-dv-esx-10.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-05.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-06.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-07.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-08.cisco.com> because state is notResponding

00:16:46.525 [7108.7028] <2> delete_vm returned 0, try 0: bpVMutil

00:16:46.525 [7108.7028] checkBackupRegEntry: searching configuration for KeepVMXmlFiles

00:16:46.525 [7108.7028] RegOpenKey failed with 2

00:16:46.525 [7108.7028] <2> bpVMutil main: EXIT STATUS 0: the requested operation was successfully completed

They is no files in bpfis

Nate_D1 · ‎01-29-2014

Could possibly be a DNS related issue or something to do with the guest lookup because of:

00:13:50.761 [7084.6516] find_vm_by_displayname: vmcGetObjDetails DataSet2_i failed with status 18

00:13:50.761 [7084.6516] <2> find_vm_by_displayname returned 18: bpVMutil

I have ran into this before but for backups. Here are a couple things I have done when I run into that:

From Marianne's comment here:

Have you updated hosts files or DNS recently?

If so, have you refreshed NBU host cache on media server?

bpclntcmd -clear_host_cache

Is there a firewall between media server and client?
If so, have backup-IPs been added to firewall rules?

Please show us output of all the following:

On Media server:
bpclntcmd -hn <client_bk-name>
bpclntcmd -ip <client_bk-IP>

On Client:
bpclntcmd -hn <media_bk-name>
bpclntcmd -ip <media_bk-IP>

On Media server:
bptestbpcd -client <client_bk-name> -debug -verbose

Searching symantecs site is going to run you into a lot of stuff like this here and this here and you could try those, I just have not found that type of thing to fix the issue in the past.

sagar666 · ‎01-29-2014

Have you updated hosts files or DNS recently?

No

bpclntcmd -clear_host_cache

C:\Program Files\Veritas\Volmgr\bin>bpclntcmd -clear_host_cache

'bpclntcmd' is not recognized as an internal or external command,

operable program or batch file.

Is there a firewall between media server and client?

How to check firewall b/w media server and client

If so, have backup-IPs been added to firewall rules?

Please show us output of all the following:

On Media server:
bpclntcmd -hn <client_bk-name>

C:\Program Files\Veritas\Volmgr\bin>bpclntcmd -hn B16-STG-047

'bpclntcmd' is not recognized as an internal or external command,

operable program or batch file.

bpclntcmd -ip <client_bk-IP>

C:\Program Files\Veritas\Volmgr\bin>bpclntcmd -hn 10106.10.107

'bpclntcmd' is not recognized as an internal or external command,

operable program or batch file.

On Client:
bpclntcmd -hn <media_bk-name>
bpclntcmd -ip <media_bk-IP>

On Media server:
bptestbpcd -client <client_bk-name> -debug -verbose

not recognized internal or external command

Nate_D1 · ‎01-29-2014

hmm, possibly the wrong path? As ran from my 7.5 box just now:

C:\Program Files\Veritas\NetBackup\bin>bpclntcmd -hn jade
host jade: jade.domain at 10.1.255.xxx
aliases: jade.domain jade 10.1.255.xxx

C:\Program Files\Veritas\NetBackup\bin>

Mark_Solutions · ‎01-29-2014

What are B16-SCC-VC-1 and b16-stg-esx-06.cisco.com?

I am guessing that the -VC- one is your vCenter and the -esx- one is an esx server?

If so does your environment have an issue because i see a lot of these:

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-02.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-03.cisco.com> because state is notResponding

00:16:46.369 [7108.7028] vmwareLogger: RetrieveHostContents: Skipping host <b16-pf-qa-esx-04.cisco.com> because state is notResponding

It may however be a restore rights issue so double check the account you use for th vCenter to ensure that it has sufficient rights to actually do the restore

Check through this tech note: http://www.symantec.com/docs/TECH130493

It looks like it is struggling to get everything it needs and is being slowed down by a poor vCenter setup - these delays could just be causing the restore to timeout which could cause the failure

#edit#

just noticed your other thread where you are having issues backing clients up via vCenter too

You need to get all of your vCenter and NetBackup setup perfect before you can get a restore to work correctly

sagar666 · ‎01-29-2014

Hi There is Problem with credentials given in NBU. I given vcenter administrator password.

But still restore is not happening it is going struck

Progress logs

07:50:20 1/30/2014: Restore Started

07:50:21 (202715.xxx) Media id ST9060 is needed for the restore.

07:50:21 (202715.001) Restoring from copy 1 of image created 1/29/2014 12:00:07 AM

07:50:22 INF - If Media id ST9060 is not in a robotic library administrative interaction may be required to satisfy this mount request.

State Details

A pending action is associated with the resource request.User intervention may require

Detailed Status

1/30/2014 7:50:20 AM - begin Restore

1/30/2014 7:50:21 AM - media ST9060 required

1/30/2014 7:50:21 AM - restoring image B16-STG-048_1390933807

1/30/2014 7:50:21 AM - Info bprd(pid=5944) Restoring from copy 1 of image created 01/29/14 00:00:07

1/30/2014 7:50:22 AM - Info bptm(pid=5592) start

1/30/2014 7:50:22 AM - started process bptm (5592)

1/30/2014 7:50:22 AM - Info bpdm(pid=5592) reading backup image

1/30/2014 7:50:22 AM - Info bptm(pid=5592) using 30 data buffers

1/30/2014 7:50:22 AM - Info bptm(pid=5592) spawning a child process

1/30/2014 7:50:22 AM - Info bptm(pid=5592) child pid: 1668

1/30/2014 7:50:22 AM - Info bptm(pid=1668) start

1/30/2014 7:50:22 AM - started process bptm (1668)

1/30/2014 7:50:22 AM - requesting resource ST9060

1/30/2014 7:50:23 AM - awaiting resource ST9060 A pending request has been generated for this resource request.

Operator action may be required. Pending Action: No action.,

Media ID: ST9060, Barcode: ST9060, Density: hcart3, Access Mode: Read,

Action Drive Name: N/A, Action Media Server: N/A, Robot Number: N/A, Robot Type: NONE,

Volume Group: 000_00002_TLD, Action Acs: N/A, Action Lsm: N/A

1/30/2014 7:51:01 AM - awaiting resource ST9060 A pending request has been generated for this resource request.

Operator action may be required. Pending Action: No action.,

Media ID: ST9060, Barcode: ST9060, Density: hcart3, Access Mode: Read,

Action Drive Name: N/A, Action Media Server: N/A, Robot Number: N/A, Robot Type: NONE,

Volume Group: 000_00002_TLD, Action Acs: N/A, Action Lsm: N/A

sagar666 · ‎01-29-2014

Hi Nate,

I dont know about firewall exactly i think there is No firewall between client and NBU because all Devices and clients reside in same LAN

I think i cant execute below cmds in client because my clients are VMware .If it is possible please let me know where to execute

On Client:
bpclntcmd -hn <media_bk-name>

bpclntcmd -ip <media_bk-IP>

C:\Program Files\Veritas\NetBackup\bin>bpclntcmd -hn B16-STG-048

host B16-STG-048: B16-STG-048.cisco.com at 10.106.6.238

aliases: B16-STG-048.cisco.com B16-STG-048 10.106.6.238

C:\Program Files\Veritas\NetBackup\bin>bpclntcmd -ip 10.106.6.238

host 10.106.6.238: b16-stg-048.cisco.com at 10.106.6.238

aliases: b16-stg-048.cisco.com 10.106.6.238

08:09:09.032 [6060.5176] <2> bptestbpcd: VERBOSE = 0

08:09:09.064 [6060.5176] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen()

failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\1b2\478f1b

b2+veritas_pbx,1,400,2,1,0+b16-stg-048.txt

08:09:09.298 [6060.5176] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen()

failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\08f\531cb0

8f+0,1,a,0,1,0+10.106.6.238.txt

08:09:09.298 [6060.5176] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen()

failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\1b2\478f1b

b2+vnetd,1,400,2,1,0+b16-stg-048.txt

08:09:09.313 [6060.5176] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen()

failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\1b2\478f1b

b2+bpcd,1,400,2,1,0+b16-stg-048.txt

08:09:09.313 [6060.5176] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen()

failed ERRNO=2 FILE=C:\Program Files\Veritas\NetBackup\var\host_cache\1b2\478f1b

b2+bpcd,1,400,2,1,0+b16-stg-048.txt

08:09:11.326 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:12.339 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:13.353 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:15.397 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:16.411 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:17.425 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:19.453 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:20.467 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:21.481 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:24.492 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:25.506 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:26.504 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:33.524 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:34.538 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:35.536 [6060.5176] <8> async_connect: [vnet_connect.c:1653] getsockopt SO_

ERROR returned 10061 0x274d

08:09:35.536 [6060.5176] <16> connect_to_service: connect failed STATUS (18) CON

NECT_FAILED

status: FAILED, (42) CONNECT_REFUSED; system: (10061) No connection coul

d be made because the target machine actively refused it. ; FROM 0.0.0.0 TO B16-

STG-048 10.106.6.238 bpcd VIA pbx

status: FAILED, (42) CONNECT_REFUSED; system: (10061) No connection coul

d be made because the target machine actively refused it. ; FROM 0.0.0.0 TO B16-

STG-048 10.106.6.238 bpcd VIA vnetd

status: FAILED, (42) CONNECT_REFUSED; system: (10061) No connection coul

d be made because the target machine actively refused it. ; FROM 0.0.0.0 TO B16-

STG-048 10.106.6.238 bpcd

08:09:35.536 [6060.5176] <8> vnet_connect_to_bpcd: [vnet_connect.c:279] connect_

to_service() failed 18 0x12

08:09:35.536 [6060.5176] <2> local_bpcr_connect: Can't connect to client B16-STG

-048

08:09:35.536 [6060.5176] <2> ConnectToBPCD: bpcd_connect_and_verify(B16-STG-048,

B16-STG-048) failed: 25

<16>bptestbpcd main: Function ConnectToBPCD(B16-STG-048) failed: 25

08:09:35.536 [6060.5176] <16> bptestbpcd main: Function ConnectToBPCD(B16-STG-04

8) failed: 25

<2>bptestbpcd: cannot connect on socket

08:09:35.536 [6060.5176] <2> bptestbpcd: cannot connect on socket

<2>bptestbpcd: EXIT status = 25

08:09:35.536 [6060.5176] <2> bptestbpcd: EXIT status = 25

cannot connect on socket

C:\Program Files\Veritas\NetBackup\bin\admincmd>

sagar666 · ‎01-30-2014

Any update??

VOX

I cant restore VMware client