VMware Cloud Community
madliv
Contributor
Contributor
‎06-20-2007 08:28 AM

VCB Backup Issue

Using latest VCB with a MSA1000 SAN, backup is stopping when I reach the around 50% mark. after looking at the backup folder on the proxy server, the backup is dying when trying to backup the foobar.vmdk file, the foobar-flat.vmdk file, and all other files backup fine. Here is the log

**********************************************************

C:\Program Files\VMware\VMware Consolidated Backup Framework>vcbmounter.exe -h ottavc01.otta.local -u backup -p XXXXXX

-a ipaddr:ottaweb03.otta.local -r e:\vmbackup\test -t fullvm -m san -M 1 -F 1 -L6

\[2007-06-19 16:02:04.041 'App' 1588 info] Current working directory: C:\Program Files\VMware\VMware Consolidated Backup

Framework

\[2007-06-19 16:02:04.072 'vcbMounter' 1588 trivia] Initializing SSL context

\[2007-06-19 16:02:04.072 'BaseLibs' 1588 info] Using system libcrypto, version 90703F

\[2007-06-19 16:02:04.603 'App' 1588 info] Vmacore::InitSSL: doVersionCheck = true, handshakeTimeoutUs = 120000000

\[2007-06-19 16:02:04.603 'vcbMounter' 1588 info] Connecting to host ottavc01.otta.local on port 902

\[2007-06-19 16:02:04.853 'vcbMounter' 1588 verbose] Connected to stream: \[class Vmacore::Ssl::SSLStreamImpl:018F3B60]

\[2007-06-19 16:02:04.853 'BaseLibs' 3864 warning] \[Vmdb_Unset] Unsetting unknown path: /vmomi/

\[2007-06-19 16:02:04.900 'vcbMounter' 1588 info] Authenticating user backup

\[2007-06-19 16:02:05.994 'vcbMounter' 1588 info] Logged in!

\[2007-06-19 16:02:05.994 'vcbMounter' 1588 info] Performing SearchIndex find.

\[2007-06-19 16:02:06.104 'vcbMounter' 1588 info] Attempting index search.

\[2007-06-19 16:02:06.104 'vcbMounter' 1588 info] Found VM using index search.

\[2007-06-19 16:02:06.104 'vcbMounter' 1588 info] Got VM MoRef

\[2007-06-19 16:02:06.885 'vcbMounter' 1588 info] Got access method

\[2007-06-19 16:02:06.885 'vcbMounter' 1588 info] Got coordinator object

\[2007-06-19 16:02:06.885 'vcbMounter' 1588 info] Attempting data access.

\[2007-06-19 16:02:07.088 'vcbMounter' 1588 info] No snapshot info for this VM, nothing to do.

\[2007-06-19 16:02:07.088 'vcbMounter' 1588 info] Creating snapshot

\[2007-06-19 16:02:10.792 'vcbMounter' 1588 info] Snapshot created, ID: snapshot-890

\[2007-06-19 16:02:10.792 'vcbMounter' 1588 info] Mount operation created snapshot.

\[2007-06-19 16:02:10.824 'vcbMounter' 1588 verbose] Found a device: vim.vm.device.VirtualBusLogicController

\[2007-06-19 16:02:10.824 'vcbMounter' 1588 verbose] Found a device: vim.vm.device.VirtualDisk

\[2007-06-19 16:02:10.839 'vcbMounter' 1588 info] Mount operation obtained backup info.

\[2007-06-19 16:02:10.839 'vcbMounter' 1588 info] Creating export directory

\[2007-06-19 16:02:10.839 'vcbMounter' 1588 info] Writing restore config file

\[2007-06-19 16:02:17.138 'vcbMounter' 1588 info] Exporting VM config files

Copying "\[OTTAPROD1] OTTAWEB03/OTTAWEB03.vmx":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03/OTTAWEB03.nvram":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-14.log":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-15.log":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-17.log":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-18.log":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-19.log":

0%=====================50%=====================100%

*************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-20.log":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware-16.log":

0%=====================50%=====================100%

**************************************************

Copying "\[OTTAPROD1] OTTAWEB03//vmware.log":

0%=====================50%=====================100%

**************************************************

\[2007-06-19 16:02:18.200 'vcbMounter' 1588 info] Exporting disks

\[2007-06-19 16:02:18.200 'vcbMounter' 1588 info] Filenames: blklst://snapshot-890\[OTTAPROD1] OTTAWEB03/OTTAWEB03.vmdk@ot

tavc01.otta.local?backup/XXXXX --> e:\vmbackup\test\scsi0-0-0-OTTAWEB03.vmdk

\[2007-06-19 16:02:18.247 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:02:18.247 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_hp&prod_logical_volume&rev_2.26#6&2dee

a60a&0&040#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:18.247 'App' 1588 info] Now using Path
?\scsi#disk&ven_hp&prod_logical_volume&rev_2.26#6&2deea60a&0&

040#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:18.247 'App' 1588 trivia] Reading 32256 bytes from offset 0.

\[2007-06-19 16:02:18.247 'App' 1588 trivia] Found 1 partition(s) on this device.

\[2007-06-19 16:02:18.263 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:02:18.263 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_hp&prod_logical_volume&rev_2.26#6&2dee

a60a&0&050#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:18.263 'App' 1588 info] Now using Path
?\scsi#disk&ven_hp&prod_logical_volume&rev_2.26#6&2deea60a&0&

050#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:18.263 'App' 1588 trivia] Reading 32256 bytes from offset 0.

\[2007-06-19 16:02:18.263 'App' 1588 trivia] Found 1 partition(s) on this device.

\[2007-06-19 16:02:18.263 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:02:18.263 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000004#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:19.388 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000004#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:19.388 'App' 1588 trivia] Reading 32256 bytes from offset 0.

\[2007-06-19 16:02:19.404 'App' 1588 trivia] Found 1 partition(s) on this device.

\[2007-06-19 16:02:19.404 'App' 1588 info] Partition #1 is a VMFS partition.

\[2007-06-19 16:02:19.404 'App' 1588 trivia] Reading 1574400 bytes from offset 1114112.

\[2007-06-19 16:02:25.108 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:02:25.108 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000004#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:02:25.108 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000004#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:03:06.399 'App' 1588 trivia] Cannot read 1574400 bytes from offset 1114112.

\[2007-06-19 16:03:06.399 'App' 1588 trivia] Looking for VMFS3 signature.

\[2007-06-19 16:03:06.399 'App' 1588 trivia] Reading 512 bytes from offset 2162688.

\[2007-06-19 16:03:12.900 'App' 1588 trivia] Reading 512 bytes from offset 131072.

\[2007-06-19 16:03:12.900 'App' 1588 trivia] No VMFS or LVM signatures found on partition 1.

\[2007-06-19 16:03:12.900 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:03:12.900 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:03:13.401 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:03:13.401 'App' 1588 trivia] Reading 32256 bytes from offset 0.

\[2007-06-19 16:03:14.073 'App' 1588 trivia] Found 1 partition(s) on this device.

\[2007-06-19 16:03:14.073 'App' 1588 info] Partition #1 is a VMFS partition.

\[2007-06-19 16:03:14.073 'App' 1588 trivia] Reading 1574400 bytes from offset 1114112.

\[2007-06-19 16:03:19.902 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:03:19.902 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:03:19.902 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:19:25.331 'App' 1588 trivia] Cannot read 1574400 bytes from offset 1114112.

\[2007-06-19 16:19:25.331 'App' 1588 trivia] Looking for VMFS3 signature.

\[2007-06-19 16:19:25.331 'App' 1588 trivia] Reading 512 bytes from offset 2162688.

\[2007-06-19 16:19:25.331 'App' 1588 trivia] Reading 512 bytes from offset 131072.

\[2007-06-19 16:19:25.346 'App' 1588 trivia] No VMFS or LVM signatures found on partition 1.

\[2007-06-19 16:19:25.346 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:19:25.346 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000006#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:19:25.846 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000006#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:19:25.846 'App' 1588 trivia] Reading 32256 bytes from offset 0.

\[2007-06-19 16:19:27.128 'App' 1588 trivia] Found 1 partition(s) on this device.

\[2007-06-19 16:19:27.128 'App' 1588 info] Partition #1 is a VMFS partition.

\[2007-06-19 16:19:27.128 'App' 1588 trivia] Reading 1574400 bytes from offset 1114112.

\[2007-06-19 16:19:32.847 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:19:32.847 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000006#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:19:32.847 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000006#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:19:38.567 'App' 1588 trivia] Cannot read 1574400 bytes from offset 1114112.

\[2007-06-19 16:19:38.567 'App' 1588 trivia] Looking for VMFS3 signature.

\[2007-06-19 16:19:38.567 'App' 1588 trivia] Reading 512 bytes from offset 2162688.

\[2007-06-19 16:19:38.567 'App' 1588 trivia] Reading 512 bytes from offset 131072.

\[2007-06-19 16:19:38.567 'App' 1588 trivia] No VMFS or LVM signatures found on partition 1.

\[2007-06-19 16:19:38.567 'App' 1588 trivia] Obtained list of SCSI disk devices.

\[2007-06-19 16:19:38.567 'BlockList' 1588 info] Establishing new connection for ottavc01.otta.local:backup

\[2007-06-19 16:19:38.567 'blocklist' 1588 trivia] Initializing SSL context

\[2007-06-19 16:19:38.582 'blocklist' 1588 info] Connecting to host ottavc01.otta.local on port 902

\[2007-06-19 16:19:38.801 'blocklist' 1588 verbose] Connected to stream: \[class Vmacore::Ssl::SSLStreamImpl:0190FFF8]

\[2007-06-19 16:19:38.801 'BaseLibs' 3960 warning] \[Vmdb_Unset] Unsetting unknown path: /vmomi/

\[2007-06-19 16:19:38.832 'blocklist' 1588 info] Authenticating user backup

\[2007-06-19 16:19:39.114 'blocklist' 1588 info] Logged in!

\[2007-06-19 16:19:39.536 'App' 1588 trivia] Attempting to open NAA:600508b30091c4a0a3f24a874593000a4d5341313030/5.

\[2007-06-19 16:19:39.536 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:19:39.536 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:19:40.161 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

Converting "e:\vmbackup\test\scsi0-0-0-OTTAWEB03.vmdk" (flat file):

0%=====================50%=====================100%

*************************\[2007-06-19 16:28:18.307 'App' 1588 trivia] Evaluating 1 paths.

\[2007-06-19 16:28:18.307 'App' 1588 trivia] Trying to open path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&

38d664f7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

\[2007-06-19 16:28:18.307 'App' 1588 info] Now using Path
?\scsi#disk&ven_compaq&prod_msa1000_volume&rev_4.96#6&38d664f

7&0&000005#\{53f56307-b6bf-11d0-94f2-00a0c91efb8b}.

*************************

\[2007-06-19 16:28:24.260 'BlockList' 1588 info] Closing connection ottavc01.otta.local:backup

\[2007-06-19 16:28:24.276 'App' 1588 verbose] Got vmdb error -14 (Pipe connection has been broken) when invoking \[logout]

on \[vim.SessionManager:SessionManager]

\[2007-06-19 16:28:24.292 'BlockList' 1588 warning] Could not log out (ottavc01.otta.local:backup)

\[2007-06-19 16:28:24.307 'App' 1588 verbose] Got vmdb error -14 (Pipe connection has been broken) when invoking \[logout]

on \[vim.SessionManager:SessionManager]

\[2007-06-19 16:28:24.307 'blocklist' 1588 info] Error on logout (ignored): vmodl.fault.HostNotReachable

\[2007-06-19 16:28:24.307 'blocklist' 1588 verbose] Shutting down VMDB service...

\[2007-06-19 16:28:24.307 'blocklist' 1588 verbose] Unregistering callback...

\[2007-06-19 16:28:24.323 'blocklist' 1588 verbose] ...done

\[2007-06-19 16:28:24.323 'vcbMounter' 1588 error] Error: Failed to export the disk: The request could not be performed b

ecause of an I/O device error

\[2007-06-19 16:28:24.323 'vcbMounter' 1588 error] An error occured, cleaning up...

\[2007-06-19 16:28:29.307 'App' 1588 verbose] Got vmdb error -14 (Pipe connection has been broken) when invoking \[logout]

on \[vim.SessionManager:SessionManager]

\[2007-06-19 16:28:29.307 'vcbMounter' 1588 info] Error on logout (ignored): vmodl.fault.HostNotReachable

\[2007-06-19 16:28:29.307 'vcbMounter' 1588 verbose] Shutting down VMDB service...

\[2007-06-19 16:28:29.307 'vcbMounter' 1588 verbose] Unregistering callback...

\[2007-06-19 16:28:29.307 'vcbMounter' 1588 verbose] ...done

PS C:\Program Files\VMware\VMware Consolidated Backup Framework>

************************************************************

TIA for any pointers given!!

0 Kudos
10 Replies
AskChiz
Contributor
Contributor
‎06-20-2007 11:47 AM

When presenting the LUN's to VCB and ESX host make sure the LUN ID is the same. If the lun ids are different vcb will fail when it comes to transfer the vmdk file

ie LUNx is presented to ESX host with ID1 and also presented to the VCB server with ID1.

0 Kudos
madliv
Contributor
Contributor
‎06-20-2007 11:59 AM

The LUN ID's are correct, and I currently only have 1 fiber SAN switch, so I am not doing any multipathing there. I am checking into my Harddrive bays, I have two of them, the logical drive is made up of 4 hard drives, with 2 drives installed in the top bay, and 2 drives installed into the bottom bay. Would this be considered multipathing?

0 Kudos
msimms
Enthusiast
Enthusiast
‎06-20-2007 12:25 PM

No, multipathing is needed when you have two host bus adapter cards in the back of the server that connect to the MSA. However with VCB, multipathing software isn't used, make sure you've also uninstalled any multipathing software on the server (ie, autopath, securepath and mpio) and disable any redundant disk paths in the server's Windows Device Manager.

0 Kudos
AskChiz
Contributor
Contributor
‎06-20-2007 12:47 PM

I wouldnt have thought with a single switch that it would be mulitipathing,

however you can check in the esx host configuration --> storage (scsi, san.... in properties you can see all paths active and any standby.

you probably know this but.

also make sure windows sees the drive in disk management and rescan disks if not. obviously dont assign a drive letter or format it, would be vbad.

0 Kudos
madliv
Contributor
Contributor
‎06-20-2007 12:55 PM

I have HP BL20p's, and even though they have 2 hba's, I am only connected to 1 FC switch, so I believe that there is no multipathing happening. AskChiz, I have 3 LUN's/Drives, and I can see all 3 of them in Disk Management. I am able to see files written to my VCB proxy, it just stops when the config vmdk starts to get written.

0 Kudos
dconvery
Champion
Champion
‎06-20-2007 05:31 PM

The latest version of VCB allows MPIO. Make sure you follow the install instructions explicitly. The are in the VM backup guide. There is alos a readme for the integration piece.

Dave Convery, VCDX-DCV #20 ** http://www.tech-tap.com ** http://twitter.com/dconvery ** "Careful. We don't want to learn from this." -Bill Watterson, "Calvin and Hobbes"
0 Kudos
dconvery
Champion
Champion
‎06-20-2007 05:36 PM

Make sure you have sufficient disk space on the proxy to perform a fullvm backup as well.

Dave Convery, VCDX-DCV #20 ** http://www.tech-tap.com ** http://twitter.com/dconvery ** "Careful. We don't want to learn from this." -Bill Watterson, "Calvin and Hobbes"
0 Kudos
madliv
Contributor
Contributor
‎06-21-2007 06:22 AM

I have plenty of space, still do not fully understand the MPIO stuff. The install for VCB seems very straight forward, not alot of room for making mistakes. Also checking with HP

0 Kudos
dconvery
Champion
Champion
‎06-21-2007 08:32 AM

In a nutshell:

MPIO is multipathing. Multipathing CAN be two FC adapters in a server attached to one fabric switch or to on storage system. If you only have one Fibre Channel path between the BL20 and the MSA, you are not using MPIO.

Other things to try: It is Winders, try a reboot. Also, make sure that the previous snapshot has been removed.

Dave Convery, VCDX-DCV #20 ** http://www.tech-tap.com ** http://twitter.com/dconvery ** "Careful. We don't want to learn from this." -Bill Watterson, "Calvin and Hobbes"
0 Kudos
madliv
Contributor
Contributor
‎06-28-2007 11:00 AM

Problem ended up being a bad HBA card! Should have know when I saw the "I/O Device Error" in the logs!!!

0 Kudos