Video Screencast Help

Question VMware backup (failing Error 23)

Created: 15 Aug 2011 • Updated: 18 Aug 2011 | 18 comments
mmeeggaann's picture
This issue has been solved. See solution.

In order to backup VMware virtual machines, is it  necessary to set up  the FQDN of the ESX server?

I have a ESX 4 standalone server (no administered by a vCenter), but is not added to the DNS. So Im able to added to NBU by Ip address only even when I  added the entry to the hosts file.

As a result the VM backup failed with Error 23, Error to opening the snapshot disks using given transport mode.

In the VxMS I found the lines:

 SSLVerifyCertAgainstSystemStore: Subject mismatch: hostname. vs IP address

        08/15/2011 20:28:12.0140 [TID 0x0001bc54]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : SSLVerifyCertAgainstSystemStore: The remote host certificate has these problems:

* The host name used for the connection does not match the subject name on the host certificate

* The host certificate chain is not complete.

 

Any ideas?

Comments 18 CommentsJump to latest comment

pikachu's picture

I am assuming the child job is failing. If so... that means you actually got a status code 6.

Are you backing up over the SAN? NBD? HotADD?

What version of NBU/VC/ESX are you running?

Nothing has changed...

mmeeggaann's picture

Yes the child job is failing, in a second post I'll confirm you the status code  because I have to verify it.

NBU 7.0.1

vSphere 4 Enterprise

nbd transport mode

 

 

Thanks :)

 

 

pikachu's picture

Do you have any vmware rollup patches installed?

The eeb is: 2105102

Also let me know IF you have it installed... at patch version it is.

 

You can ignore:

 

 SSLVerifyCertAgainstSystemStore: Subject mismatch: hostname. vs IP address

        08/15/2011 20:28:12.0140 [TID 0x0001bc54]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : SSLVerifyCertAgainstSystemStore: The remote host certificate has these problems:

 

 

Increase vxms logging to hex 7580. Clean out the vxms log folder. Re-run the job and re-post it.

 

Also does the backup work if you backup through the ESX directly?

Nothing has changed...

mmeeggaann's picture

You're right. The backup job is failing with the status code 6.

I re-check...  the version of VMware ESX is 4.1.0 , 260247

About the transport mode is ndb, but I already test with the "try all types" option.

The snapshots creation is working welll, the error is with the child job at the time to read 

 

 

What do you mean about "backup through the ESX directly"'?

 

 

 

I increased VxMS logging to hex 7580 and re-run the job:

 

 

 

08/17/2011 17:32:04.0519 [TID 0x0001c378]: VixInterface::vdOpen:.\VixInterface.cpp:198 <VFM_ESERROR> [Sys Error: No error] : VixDiskLib_Open() error. Exited
        08/17/2011 17:32:04.0519 [TID 0x0001c378]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:436 <VFM_ESERROR> [Sys Error: No error] : vdOpen() error = 13. Calling closeLeafSnapshotDisks()
        08/17/2011 17:32:04.0519 [TID 0x0001c378]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:539 <VFM_ESERROR> [Sys Error: No error] : Exited with failure
        08/17/2011 17:32:04.0519 [TID 0x0001c378]: VixCoordinator::vixMapObjCtl:.\VixCoordinator.cpp:904 <VFM_ESERROR> [Sys Error: No error] : Exited with 23
        08/17/2011 17:32:04.0519 [TID 0x0001c378]: vix_map_objctl:.\libvix.cpp:1145 <VFM_ESERROR> [Sys Error: No error] : Error 23
 
End vfm_objctl: result(23)
 
 
 
        08/17/2011 17:32:04.0519 [TID 0x0001c378]: VixManager::closeGuest:.\VixManager.cpp:90 <VFM_ESINFO> : Guest has no open file systems hence deleting it
        08/17/2011 17:32:04.0519 [TID 0x0001c378]: VixGuest::~VixGuest:.\VixGuest.cpp:105 <VFM_ESINFO> : Entered
        08/17/2011 17:32:04.0566 [TID 0x0001c378]: VixGuest::~VixGuest:.\VixGuest.cpp:214 <VFM_ESINFO> : Cleaned up VM State files
        08/17/2011 17:32:04.0566 [TID 0x0001c378]: VixGuest::~VixGuest:.\VixGuest.cpp:235 <VFM_ESINFO> : Exited
 
 

 

Thanks.

 

 

pikachu's picture

What do you mean about "backup through the ESX directly"'?

=> My bad... you are using a stand alone ESX server.

 

Anyway you could post the entire VxMS log?

If you didn't introduce the datastore luns over san/iscsi to the backup host, try all types doesn't help. Just keep it on NBD.

 

In the policy try to disable EXCLUDE WHITE SPACES and disable QUIESCING.

Nothing has changed...

SOLUTION
Rick Brown's picture

I have 3 machines randomly doing this same sort of thing. They don't fail everytime but when they do, we can usually just re-run the backup & it works successfully. Very odd becasue we do over 1k SQL backups per day. Yet these 3 VM's have something different about them, all are running NBU 7.0.1.

These are running a 32bit version SQL2005 as a VM. At first we thoguht it was a memory issue, so we added more but the issue persists. I have a case open with Symantec for this, but I'm waiting to capture a failure with the logging jacked up to 5 - it's like fishing & waiting for the big one to strike.

pikachu's picture

Best practice is to backup the SQL VMs with the NBU client. Microsoft has a white paper about it for Hyper-V, which is the same thing. Think about it... we do not truncate the logs besides, which means we do not check in what state the DB is in. Also in that case the snapback of the delta data might not always get deleted depending on how busy the system is.

Nothing has changed...

mmeeggaann's picture

 

I set the Policy as follow and re-run the backup:

Perform block level incremental backups: not selected

 

*Client name selection:  VM hostname

*Virtual machine backup: Mapped full VM backup

*Transfer type: nbd 

*Virtual machine quiesce: disabled (before enabled)

*Exclude unused and deleted blocks: disabled (before enabled)

*Existing snpashot handing: Remove NBU

 

 

Great! the backup is running now, it began to write :)

 

Now, I'll test to know which of the 2 paramters is helping the backup works.

I would like to enable the VM quiesce paramter to guaratee the integrity of the data.

 

Let me test, I would let you know the results

 

 

 

 

 

mmeeggaann's picture

Here the results:

 

  • The job failed

*Client name selection:  VM hostname

 

*Virtual machine backup: Mapped full VM backup

*Transfer type: nbd 

*Virtual machine quiesce: Enabled

*Exclude unused and deleted blocks: disabled 

*Existing snpashot handing: Remove NBU

  
  • The backup ran successfully  
 

*Client name selection:  VM hostname

*Virtual machine backup: Mapped full VM backup

*Transfer type: nbd 

*Virtual machine quiesce: Disabled

*Exclude unused and deleted blocks: Enabled 

*Existing snpashot handing: Remove NBU

 

I would like to find the cause, because I think is important to quiesce the VM to back them up.

 

I attach the VxMS log of the 1st try (Quiesce enabled) when the job failed.

 

 

 

 

Begin VxMS Session...
Logmask set to 0x0
Current Environment Variables
VFM_ROOT = NULL
VFM_PRIVATE_ROOT = NULL
VFM_MAP_API_LIB = NULL
VFM_MAP_DIR = NULL
VFM_UTIL_LIB = NULL
 
Begin: vfm_open_id [08/17/11 14:57:07]
 
  Input Parameters:
  flags=524291
  context=NULL
  origobjid=NULL
 
   [ Objid ]
     vfm_objid_t { 
       vid_length = 206
objid->vid_name[E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml] is of length objid->vid_len = 206!!
       vid_type = 0
     }
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: vhd_map_init:.\libvhd.cpp:798 <VFM_ESINFO> : Entered
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: vhd_map_init:.\libvhd.cpp:817 <VFM_ESINFO> : Exited
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdCoordinator::vhdMapInit:.\VhdCoordinator.cpp:640 <VFM_ESINFO> : Entered
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdCoordinator::vhdMapInit:.\VhdCoordinator.cpp:679 <VFM_ESINFO> : Exited
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: vhd_map_claim_id:.\libvhd.cpp:224 <VFM_ESINFO> : Entered
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: vhd_map_claim_id:.\libvhd.cpp:227 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: vhd_map_claim_id:.\libvhd.cpp:246 <VFM_ESINFO> : Exited
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdCoordinator::vhdMapClaimId:.\VhdCoordinator.cpp:157 <VFM_ESINFO> : Entered
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdCoordinator::vhdMapClaimId:.\VhdCoordinator.cpp:159 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimId:.\VhdManager.cpp:178 <VFM_ESINFO> : Entered
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimId:.\VhdManager.cpp:180 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimId:.\VhdManager.cpp:224 <VFM_ESINFO> : Exited
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimHyperVGuestId:.\VhdManager.cpp:265 <VFM_ESINFO> : Entered
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimHyperVGuestId:.\VhdManager.cpp:268 <VFM_ESINFO> : Trying to open E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimHyperVGuestId:.\VhdManager.cpp:286 <VFM_ESINFO> : Allocating buffer of filesize 3022 and reading the file
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimHyperVGuestId:.\VhdManager.cpp:298 <VFM_ESINFO> : filesize = 3022 and bytesRead = 3022
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdManager::claimHyperVGuestId:.\VhdManager.cpp:347 <VFM_ESINFO> : Exited with no claim
        08/17/2011 19:57:07.0282 [TID 0x00019f1c]: VhdCoordinator::vhdMapClaimId:.\VhdCoordinator.cpp:183 <VFM_ESINFO> : Exited
        08/17/2011 19:57:07.0298 [TID 0x00019f1c]: VixInterface::vdInit:.\VixInterface.cpp:157 <VFM_ESINFO> : vixDiskLib config file = [C:\Windows\TEMP\vixFDE2.tmp] 
        08/17/2011 19:57:07.0298 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : VixDiskLib: config options: libdir 'C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\', tmpDir 'C:\Windows\TEMP\vmware-SYSTEM'.
 
        08/17/2011 19:57:07.0454 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib. Accelerated transport modes available.
 
        08/17/2011 19:57:07.0454 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : VixDiskLib: Enabling advanced transport modes.
 
        08/17/2011 19:57:07.0500 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : VMware VixDiskLib (1.1) Release build-207031
 
        08/17/2011 19:57:07.0500 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : Using system libcrypto, version 90805F
 
        08/17/2011 19:57:08.0982 [TID 0x00019f1c]: vix_map_claim_id:.\libvix.cpp:233 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0982 [TID 0x00019f1c]: vix_map_claim_id:.\libvix.cpp:252 <VFM_ESINFO> : Exited
        08/17/2011 19:57:08.0982 [TID 0x00019f1c]: VixCoordinator::vixMapClaimId:.\VixCoordinator.cpp:174 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0982 [TID 0x00019f1c]: VixManager::claimId:.\VixManager.cpp:179 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: vix_map_open_id:.\libvix.cpp:1163 <VFM_ESINFO> : Entered. Flags: 0x80003
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapOpenId:.\VixCoordinator.cpp:919 <VFM_ESINFO> : Entered. Flags: 0x80003
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixManager::claimId:.\VixManager.cpp:179 <VFM_ESINFO> : Objid: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixManager::openId:.\VixManager.cpp:290 <VFM_ESINFO> : Opening guest
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixManager::openGuest:.\VixManager.cpp:370 <VFM_ESINFO> : Entered. Flags: 0x80003
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixMetaSave::open:.\VixMetaSave.cpp:43 <VFM_ESINFO> : Entered
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixMetaSave::open:.\VixMetaSave.cpp:94 <VFM_ESINFO> : Exited
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapOpenId:.\VixCoordinator.cpp:935 <VFM_ESINFO> : rflags returned: 0x402307dc
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: vix_map_get_obj_prop:.\libvix.cpp:648 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapGetObjProp:.\VixCoordinator.cpp:598 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapGetObjProp:.\VixCoordinator.cpp:618 <VFM_ESWARN> : VFM_ENOTSUP on RVP_OBJECT_TYPE_GUEST
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapGetObjProp:.\VixCoordinator.cpp:636 <VFM_ESERROR> [Sys Error: No error] : Exited with 4
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: vix_map_get_obj_prop:.\libvix.cpp:676 <VFM_ESERROR> [Sys Error: No error] : Error 4
 
  Output Parameters:
  rflags=0
 
   [ New Obj ] (0x000000000701AD60)
     vfm_obj_t { 
       obj_name = 0x0000000000000000
       obj_altname = 0x0000000000000000
       obj_orig_name = E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml[f9dd0486]
       obj_print_name = E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
       obj_configid = 0x000000000701ADC0
       obj_plugin = 0x0000000003EA04C0
       obj_libpriv = 0x0000000006CC31A0
       obj_pgnpriv = 0x000000000701AD40
     }
 
End vfm_open_id: result(0)
 
Begin: vfm_objctl [08/17/11 14:57:08]
 
  Input Parameters:
  cmd=-103
  arg=0x0000000003D83900
 
   vfm_obj_t { 
     obj_name = 0x0000000000000000
     obj_altname = 0x0000000000000000
     obj_orig_name = E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml[f9dd0486]
     obj_print_name = E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
     obj_configid = 0x000000000701ADC0
     obj_plugin = 0x0000000003EA04C0
     obj_libpriv = 0x0000000006CC31A0
     obj_pgnpriv = 0x000000000701AD40
   }
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: vix_map_objctl:.\libvix.cpp:1102 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapObjCtl:.\VixCoordinator.cpp:842 <VFM_ESINFO> : Entered. Cmd: -103
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapObjCtl:.\VixCoordinator.cpp:844 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixCoordinator::vixMapObjCtl:.\VixCoordinator.cpp:867 <VFM_ESINFO> : case RVP_OBJECT_TYPE_GUEST
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixMetaSave::logBinaryFile:.\VixMetaSave.cpp:173 <VFM_ESINFO> : Entered
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixMetaSave::logBinaryFile:.\VixMetaSave.cpp:223 <VFM_ESINFO> : Exited
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::loadVixConfiguration:.\VixGuest.cpp:1196 <VFM_ESINFO> : 
Successfully parsed vix xml file        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::parseAndLoadDrives:.\VixGuest.cpp:1343 <VFM_ESINFO> : SnapshotName = NBU_SNAPSHOT z1t3mxmyplw05 1313610943
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::parseAndLoadDrives:.\VixGuest.cpp:1350 <VFM_ESINFO> : SnapshotMoref = 48-snapshot-21
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::parseAndLoadDrives:.\VixGuest.cpp:1367 <VFM_ESINFO> :  Disk Key = 2000
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::parseAndLoadDrives:.\VixGuest.cpp:1379 <VFM_ESINFO> :  DiskController = 2000
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::parseAndLoadDrives:.\VixGuest.cpp:1393 <VFM_ESINFO> :  ChangeId = 
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::setupVixDiskSnapshotChains:.\VixGuest.cpp:1570 <VFM_ESINFO> : Successfully setup disk snapshot chain
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::parseAndLoadDrives:.\VixGuest.cpp:1473 <VFM_ESINFO> : Successfully parsed and loaded drives
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::openVM:.\VixGuest.cpp:707 <VFM_ESINFO> : Successfully loaded Vix configuration
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:395 <VFM_ESINFO> : Calling connectToHost(SnapMoRef = 48-snapshot-21, TransportMode = nbd)
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::connectToHost:.\VixGuest.cpp:892 <VFM_ESINFO> : TransportMode requested: <nbd>
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixGuest::connectToHost:.\VixGuest.cpp:897 <VFM_ESINFO> : Transport Modes available on this host: <file:san:hotadd:nbdssl:nbd>
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixInterface::vdConnect:.\VixInterface.cpp:410 <VFM_ESINFO> : Entered
        08/17/2011 19:57:08.0998 [TID 0x00019f1c]: VixInterface::vdConnect:.\VixInterface.cpp:474 <VFM_ESINFO> : Calling VixDiskLib_ConnectEx()
        08/17/2011 19:57:12.0914 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : UUID: SMBIOS UUID is reported as '35 38 33 39 31 34 55 53-45 30 35 30 4e 34 36 41'.
 
        08/17/2011 19:57:13.0179 [TID 0x00019f1c]: VixGuest::connectToHost:.\VixGuest.cpp:948 <VFM_ESINFO> : Setting up VMM interface
        08/17/2011 19:57:13.0179 [TID 0x00019f1c]: VixGuest::connectToHost:.\VixGuest.cpp:982 <VFM_ESINFO> : ChangeTracking is disabled/unsupported
        08/17/2011 19:57:13.0179 [TID 0x00019f1c]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:409 <VFM_ESINFO> : connectToHost() success
        08/17/2011 19:57:13.0179 [TID 0x00019f1c]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:425 <VFM_ESINFO> : Calling vdOpen(Disk = [datastore1] MXMYLA25/MXMYLA25-000002.vmdk, Flags = 0x4)
        08/17/2011 19:57:13.0179 [TID 0x00019f1c]: VixInterface::vdOpen:.\VixInterface.cpp:189 <VFM_ESINFO> : Calling VixDiskLib_Open()
        08/17/2011 19:57:13.0631 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : VixDiskLib: Trying to open disk [datastore1] MXMYLA25/MXMYLA25-000002.vmdk using mode nbd.
 
        08/17/2011 19:57:13.0631 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : NBD_Clientopen: attempting to create connection to ha-nfc://[datastore1] MXMYLA25/MXMYLA25-000002.vmdk@10.112.96.70:902!52 e6 45 67 92 bb f1 a7-83 11 78 fd 89 9a d4 99
 
        08/17/2011 19:57:13.0631 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : Started up WSA
 
        08/17/2011 19:57:13.0741 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : SSLVerifyCertAgainstSystemStore: Subject mismatch: VWMXMYLA23. vs 10.112.96.70
 
        08/17/2011 19:57:13.0741 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : SSLVerifyCertAgainstSystemStore: The remote host certificate has these problems:
 
* The host name used for the connection does not match the subject name on the host certificate
 
* The host certificate chain is not complete.
 
        08/17/2011 19:57:13.0741 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : SSLVerifyIsEnabled: failed to open the product registry key. Assuming verification is disabled. LastError = 0
 
        08/17/2011 19:57:13.0741 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : SSLVerifyCertAgainstSystemStore: Certificate verification is disabled, so connection will proceed despite the error
 
        08/17/2011 19:57:13.0881 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : Opening file [datastore1] MXMYLA25/MXMYLA25-000002.vmdk (ha-nfc://[datastore1] MXMYLA25/MXMYLA25-000002.vmdk@10.112.96.70:902!52 e6 45 67 92 bb f1 a7-83 11 78 fd 89 9a d4 99)
 
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1693 <VFM_ESWARN> : [NFC ERROR] NfcFssrvr_DiskOpen: received NFC error 11 from server: NfcFssrvrOpen: permission check failed for file [datastore1] MXMYLA25/MXMYLA25-000002.vmdk, access = 1
 
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : DISKLIB-DSCPTR: : "ha-nfc://[datastore1] MXMYLA25/MXMYLA25-000002.vmdk@10.112.96.70:902!52 e6 45 67 92 bb f1 a7-83 11 78 fd 89 9a d4 99" : Failed to open NBD extent.
 
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : DISKLIB-LINK  : "ha-nfc://[datastore1] MXMYLA25/MXMYLA25-000002.vmdk@10.112.96.70:902!52 e6 45 67 92 bb f1 a7-83 11 78 fd 89 9a d4 99" : failed to open (NBD_ERR_GENERIC).  
 
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : DISKLIB-CHAIN : "ha-nfc://[datastore1] MXMYLA25/MXMYLA25-000002.vmdk@10.112.96.70:902!52 e6 45 67 92 bb f1 a7-83 11 78 fd 89 9a d4 99" : failed to open (NBD_ERR_GENERIC).
 
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : DISKLIB-LIB   : Failed to open 'ha-nfc://[datastore1] MXMYLA25/MXMYLA25-000002.vmdk@10.112.96.70:902!52 e6 45 67 92 bb f1 a7-83 11 78 fd 89 9a d4 99' with flags 0x1e (NBD_ERR_GENERIC).
 
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixInterface::vdOpen:.\VixInterface.cpp:198 <VFM_ESERROR> [Sys Error: No error] : VixDiskLib_Open() error. Exited
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:436 <VFM_ESERROR> [Sys Error: No error] : vdOpen() error = 13. Calling closeLeafSnapshotDisks()
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixGuest::openLeafSnapshotDisks:.\VixGuest.cpp:539 <VFM_ESERROR> [Sys Error: No error] : Exited with failure
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixCoordinator::vixMapObjCtl:.\VixCoordinator.cpp:904 <VFM_ESERROR> [Sys Error: No error] : Exited with 23
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: vix_map_objctl:.\libvix.cpp:1145 <VFM_ESERROR> [Sys Error: No error] : Error 23
 
End vfm_objctl: result(23)
 
Begin: vfm_close [08/17/11 14:57:13]
 
  Input Parameters:
   vfm_obj_t { 
     obj_name = 0x0000000000000000
     obj_altname = 0x0000000000000000
     obj_orig_name = E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml[f9dd0486]
     obj_print_name = E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
     obj_configid = 0x000000000701ADC0
     obj_plugin = 0x0000000003EA04C0
     obj_libpriv = 0x0000000006CC31A0
     obj_pgnpriv = 0x000000000701AD40
   }
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: vix_map_close:.\libvix.cpp:312 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixCoordinator::vixMapClose:.\VixCoordinator.cpp:244 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixCoordinator::vixMapClose:.\VixCoordinator.cpp:265 <VFM_ESINFO> : case RVP_OBJECT_TYPE_GUEST
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixManager::closeGuest:.\VixManager.cpp:57 <VFM_ESINFO> : Obj: E:\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.Z1T3MXMYV02.dominio_1313610938.0.NBU_DATA.xml
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixManager::closeGuest:.\VixManager.cpp:90 <VFM_ESINFO> : Guest has no open file systems hence deleting it
        08/17/2011 19:57:13.0928 [TID 0x00019f1c]: VixGuest::~VixGuest:.\VixGuest.cpp:105 <VFM_ESINFO> : Entered
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: VixGuest::~VixGuest:.\VixGuest.cpp:214 <VFM_ESINFO> : Cleaned up VM State files
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: VixGuest::~VixGuest:.\VixGuest.cpp:235 <VFM_ESINFO> : Exited
 
End vfm_close: result(0)
 
Begin: vf_free_mapdomain [08/17/11 14:57:13]
 
  Input Parameters:
   vfm_mapdomain_t { 
     m_node = 0x0000000000000000
   }
 
End vf_free_mapdomain: result(0)
 
Begin: vfm_shutdown [08/17/11 14:57:13]
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: vix_map_fini:.\libvix.cpp:492 <VFM_ESINFO> : Exited with 0
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: vhd_map_fini:.\libvhd.cpp:448 <VFM_ESINFO> : Entered
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: VhdCoordinator::vhdMapFini:.\VhdCoordinator.cpp:344 <VFM_ESINFO> : Entered
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: VhdCoordinator::vhdMapFini:.\VhdCoordinator.cpp:356 <VFM_ESINFO> : Exited
        08/17/2011 19:57:13.0975 [TID 0x00019f1c]: vhd_map_fini:.\libvhd.cpp:463 <VFM_ESINFO> : Exited
 
End vfm_shutdown: result(0)
 

 

pikachu's picture

We can't really do anything about the quiescing issue. You might have to go in with perfmon to find out what's constantly reading/writing.

 

Try to disable app level quiescing.

Nothing has changed...

falti.manullang's picture

i go same problem too..

 

what is"Virtual machine quiesce" ?

Falti Manullang

 

 "If this post has helped you, please vote or mark as solution"

pikachu's picture

We flush out everything out of memory to disk.

or to make it simple... let's assume you are at a family function and would like to take a picture of your entire family. You tell them. Everybody look at the camera and smile. You get ready for everybody to smile and take a picture.

If you do not tell them to get ready you just take the picture, while Steve in the background pushes his little sister around, your mom gets your sisters hair ready.... but you still take the picture. You got the picture, but you don't know how presenteable it is.

 

Makes sense?

 

How to disable App level quiescing:

http://www.vmware.com/support/developer/vddk/VDDK-1.1.1-Relnotes.html

Windows Server 2008 backup fails due to application level quiescing

Windows Server 2008 virtual machines with the latest VMware Tools installed use application level quiescing for backup on ESX 4.1 hosts, so VDDK 1.1.1 is unable to back them up. This issue has two workarounds. The first is to power off Windows Server 2008 using the vSphere Client, select Settings > Options > General > Configuration Parameters, set disk.EnableUUID to False, save settings, and power on the virtual machine. The second workaround is to create a file in the guest at C:\ProgramData\VMware\VMware Tools\tools.conf with the following contents:

[vmbackup]
 
I prefer to do it through the VC. I have had times in which case the tools.conf didn't work

Nothing has changed...

mmeeggaann's picture

 

Thanks pikachu! I got it, very good explanation.
My insistence about the VM quiesce is because I read the following note of the NBU for VMware  Admin Guide:
 
 
" I/O on the virtual machine is quiesced before NetBackup creates the snapshot. 
Without quiescing file activity, data consistency in the snapshot cannot be guaranteed. If not consistent, the backed up data may be of little or no value. 
If this option is disabled, the snapshot is created without quiescing I/O on the virtual machine. In this case, you must perform your own checks for data consistency in the backup data. 
Caution: Symantec does not recommend that you disable quiesce. In most cases, this option should be enabled. "
 
Disable app level quiescing...
In addition to downtime to apply the change to the VM, what other implications has?

pikachu's picture

 

Disable app level quiescing...
In addition to downtime to apply the change to the VM, what other implications has?
 
=> Well first of you could try the tools.conf file, which should work, but I have had issues.
 
what other implications has?
=> Logs will not get truncated so your exchange (or any other service) will just get backed up without checking if it is ready to be backed up.
 
We released our OWN VSS writer (see nbu admin guide 7.1), which supports exchange. More features are coming in the near future.

Nothing has changed...

mmeeggaann's picture

These virtual machines run SQL Server DBs. So, do you know a problem or issue  of disable app quiesce in this case?

 

pikachu's picture

These virtual machines run SQL Server DBs. So, do you know a problem or issue  of disable app quiesce in this case?

 

Actually I have. Just recently I was working with a customer, who had a VM with SQL installed on it. We had a lot of problem at the end with the backup, because the system was still busy and deleting the snapshot didn't always work.

 

He installed the NBU client on the machine (best practice for SQL VMs) and started to backup the machine unquiesced.

Nothing has changed...

mmeeggaann's picture

Finally we decide to disable  VM quiesce feature in the backup policy and in addition we are backup the SQL databases using the NBU client.

 

Thanks a lot.

pikachu's picture

That's great! Now you have great backups AND you can restore the SQL DB.

Nothing has changed...