TDP backup fails after backing up first vmdk

Status
Not open for further replies.
M

michalwu

ADSM.ORG Member
Joined
Nov 24, 2012
Messages
9
Reaction score
2
Points
0
Hi

After some issues described here I have running environment.
OS: RHEL 6.3
kernel: 2.6.32-279.14.1.el6.x86_64
TSM: 6.3.3.0
TSMforVE: 6.4
TSM client: 6.4
Virtual Center: 5.1

And now, I am trying to back up first machine.
It is called myVM3 and its disks are Thin.
Backup runs fine from both plugin GUI and CLI, but it fails unexpectedly after backing up first disk.

dsmc show vm shows:
Code: 
(S) 25.vmName:         myVM3
       guestFullName:  Red Hat Enterprise Linux 5 (64-bit)
       guestState:     notRunning	connectionState:  connected
       changeTracking: On	vmHWversion:      vmx-07
       domainKeyword:  all-vm
       domainSelected: Yes
       resourcePool:   Resources
       VMDK[1]Label:   Hard disk 1
       VMDK[1]Name:    [R10_LUN1] myVM3/myVM3.vmdk
       VMDK[1]Status:  Included
       VMDK[2]Label:   Hard disk 2
       VMDK[2]Name:    [R10_LUN1] myVM3/myVM3_1.vmdk
       VMDK[2]Status:  Included
       VMDK[3]Label:   Hard disk 3
       VMDK[3]Name:    [R10_LUN1] myVM3/myVM3_2.vmdk
       VMDK[3]Status:  Included
       VMDK[4]Label:   Hard disk 4
       VMDK[4]Name:    [R10_LUN1] myVM3/myVM3_3.vmdk
       VMDK[4]Status:  Included

REAL size of disks:
[R10_LUN1] myVM3/myVM3.vmdk --13GB
[R10_LUN1] myVM3/myVM3_1.vmdk --5GB
[R10_LUN1] myVM3/myVM3_2.vmdk --0.4GB
[R10_LUN1] myVM3/myVM3_3.vmdk --7GB



I am issuing:
dsmc backup vm myVM3 -vmbackuptype=fullvm -mode=full -asnode=VC1_DC1
and I get:
Code: 
Backup VM command started.  Total number of virtual machines to process: 1
Accessing as node: VC1_DC1
Starting Full VM backup of VMware Virtual Machine 'myVM3'
	mode:                        'Periodic Full - Full'
	target node name:            'VC1_DC1'
	data mover node name:        'VC1_DC1_DM1'
	application protection type: 'VMware'
	application(s) protected:    'n/a'

Creating snapshot for virtual machine 'myVM3'
Backing up Full VM configuration information for 'myVM3'
         19,445 VM Configuration [Sent]      
Processing snapshot
	disk:         [DS4300_R10_LUN1] myVM3/myVM3.vmdk (Hard Disk 1)
	Capacity:     16,106,127,360
	Data to Send: 13,618,905,088
	[B]Transport:     (nbd)[sending][/B]
[B]Volume --> 16,106,127,360 [DS4300_R10_LUN1] myVM3/myVM3.vmdk (Hard Disk 1) [Sent]      [/B]

ANS4174E Full VM backup of VMware Virtual Machine 'myVM3' failed with RC=115 mode=Periodic Full - Full, target node name='VC1_DC1', data mover node name='VC1_DC1_DM1'

ANS1228E Sending of object 'myVM3' failed
ANS4015E Error processing 'myVM3': unexpected TSM error (115) encountered
Statistics for Virtual Machine 'myVM3'.

Total number of objects inspected:            1
Total number of objects backed up:            0
Total number of objects updated:              0
Total number of objects rebound:              0
Total number of objects deleted:              0
Total number of objects expired:              0
Total number of objects failed:               1
Total number of bytes inspected:          15.00 GB
Total number of bytes transferred:            0  B
Data transfer time:                      277.10 sec
Network data transfer rate:           47,995.56 KB/sec
Aggregate data transfer rate:         45,381.97 KB/sec
Objects compressed by:                        0%
Total data reduction ratio:               15.45%
Elapsed processing time:               00:04:53
Removing snapshot for virtual machine 'myVM3'
Deleted directory /tmp/vmware-root/423b0201-b7c7-49d3-c579-584fe896fea1-vm-79/nbd


Where should I look for a cause?

Thanks!
mike
 
You maybe will find other information about the error in the dsmerror.log file and TSM server activity log.
 
Sorry it took so long to respond. I changed my OS to RHEL5. I saw IBM note saying that RHEL6 and TSM4VE 6.4 do not work well. So I thought moving to RHEL5 will help.
And I have same problem again!


zsoltesz said:
You maybe will find other information about the error in the dsmerror.log file and TSM server activity log.
Click to expand...

dsmerror_dm.log shows:
Code: 
11/29/2012 13:38:25 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
[B]11/29/2012 13:38:27 Unexpected error. Please check the TSM Error Log for any additional information[/B]
But I believe I configured all required passwords. Besides I can start backup and all validation commands I can think of are OK.


dsmwebcl.log
Code: 
11/29/2012 13:32:14 (dsmagent) IBM Tivoli Storage Manager 
11/29/2012 13:32:14 (dsmagent) Remote Client Agent - Built Oct 19 2012 09:29:53 
11/29/2012 13:32:14 (dsmagent) Version 6, Release 4, Level 0.0   
11/29/2012 13:32:16 (dsmagent) ANS3002I Session started for user VC1_VCLI1 (TCP/IP 10.48.105.207).
11/29/2012 13:32:17 (dsmagent) Full BACKUP VM of virtual machines 'USE_DOMAIN'.
11/29/2012 13:32:17 (dsmagent) Backup VM command started.  Total number of virtual machines to process: 1
11/29/2012 13:32:17 (dsmagent) Backup of Virtual Machine 'VM3' started
11/29/2012 13:32:22 (dsmagent) Creating snapshot for virtual machine 'VM3'
11/29/2012 13:38:28 (dsmagent) Removing snapshot for virtual machine 'VM3'
11/29/2012 13:38:29 (dsmagent) Backup VM command complete
11/29/2012 13:38:29 (dsmagent) Total number of virtual machines backed up successfully: 0
11/29/2012 13:38:29 (dsmagent) Total number of virtual machines failed: 1
11/29/2012 13:38:29 (dsmagent)   virtual machine VM3
11/29/2012 13:38:29 (dsmagent) Total number of virtual machines processed: 1


tsmcli.trace shows that CHILD bytessent is not growing any more. While backup is running, I can see this counter growing and growing, and then when first disk is backed up, there is "CHILD bytessent:0" few times and then ANS1236E (RC115) An unexpected error occurred.
Code: 
11/29/2012 13:38:24.339 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1674): totalbytes:13587467253
11/29/2012 13:38:24.339 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1683): statMsgArray[0].statMsg = Transferring...
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1613): Entering ProxyCallBack()
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1617): dsmPCBInP->tsmHandle = 1
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1619): dsmPCBInP->proxyHandle = 1
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1621): dsmPCBInP->objExamined = 1
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1623): dsmPCBInP->objComplete = 0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1625): dsmPCBInP->objFailed = 0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1627): dsmPCBInP->objDel = 0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1636): dsmPCBInP->elapTime = 12/4/1993 0:6:8
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1639): dsmPCBInP->transderRate = 0.0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1641): dsmPCBInP->aggrTransferRate = 0.0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1643): dsmPCBInP->aggrRateProgress = 0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1645): dsmPCBInP->networkRateProgress = 0
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1647): dsmPCBInP->statusMsg = 
[B]11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1654): #CHILD bytessent:31457280[/B]

11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1674): totalbytes:13618924533
11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1683): statMsgArray[0].statMsg = Transferring...
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1613): Entering ProxyCallBack()
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1617): dsmPCBInP->tsmHandle = 1
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1619): dsmPCBInP->proxyHandle = 1
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1621): dsmPCBInP->objExamined = 1
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1623): dsmPCBInP->objComplete = 0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1625): dsmPCBInP->objFailed = 0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1627): dsmPCBInP->objDel = 0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1636): dsmPCBInP->elapTime = 12/4/1993 0:6:9
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1639): dsmPCBInP->transderRate = 0.0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1641): dsmPCBInP->aggrTransferRate = 0.0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1643): dsmPCBInP->aggrRateProgress = 0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1645): dsmPCBInP->networkRateProgress = 0
11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1647): dsmPCBInP->statusMsg = 
[B]11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1654): #CHILD bytessent:0[/B]

11/29/2012 13:38:29.630 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1674): totalbytes:13618924533
11/29/2012 13:38:29.642 : tsmproxy.cpp        (1744): tsmProxySend EXIT: rc = >115<.
[B]11/29/2012 13:38:29.642 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(681): dsmProxySend() returned rc = 115, exiting....[/B]
11/29/2012 13:38:29.642 : dsmmsg.cpp          ( 763): dsmRCMsg ENTRY: tsmHandle=1 rc: 115 msg : 0x7fff8ac9dea0[B]
11/29/2012 13:38:29.642 : dsmmsg.cpp          (1167): tsmHandle=1 rc: 115 msg : >ANS1236E (RC115)  An unexpected error occurred.<[/B]
11/29/2012 13:38:29.642 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(691): tsmclibackup() Exit. rc = 115
11/29/2012 13:38:29.642 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(701): calling dsmProxyTerminate()
11/29/2012 13:38:29.642 : tsmproxy.cpp        (1253): tsmProxyTerminate ENTRY: tsmHandle=1 proxyHandle =1 
11/29/2012 13:38:29.642 : tsmproxy.cpp        (1278): tsmProxyTerminate EXIT: rc = >0<.
11/29/2012 13:38:29.642 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(710): calling dsmTerminate()
11/29/2012 13:38:29.642 : dsmterm.cpp         ( 242): dsmTerminate ENTRY: dsmHandle is 1
11/29/2012 13:38:29.642 : dsmterm.cpp         ( 276): dsmTerminate: call ApiCleanUp . rc = 0
11/29/2012 13:38:29.642 : dsminit.cpp         (3252): ApiCleanUp : handle is = 1 
11/29/2012 13:38:34.043 : apianchr.cpp        ( 726): anDeleteAnchor: Free the space for myAnchor handle is 1
11/29/2012 13:38:34.043 : dsmterm.cpp         ( 284): dsmTerminate EXIT: rc = >0<.
11/29/2012 13:38:34.043 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1024): TRACE END
11/29/2012 13:38:34.043 : dsmsetup.cpp        ( 988): dsmCleanUp ENTRY: mtFlag = 1. 
11/29/2012 13:38:34.043 : dsmsetup.cpp        ( 999): dsmCleanUp entered. 
11/29/2012 13:38:34.043 : dsminit.cpp         (3283): ApiCleanUp : Final exit

Any ideas, guys?
m.
 
I made another backup. VM with one disk only. And this one went fine!
So it seems that there is a problem with VMs having more than one disk.

tsmcli.trace
Code: 
11/29/2012 13:54:22.583 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1674): totalbytes:24556
11/29/2012 13:54:22.591 : tsmproxy.cpp        (1744): tsmProxySend EXIT: rc = >0<.
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(748): objectsExamined:1
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(750): objectsComplete:1
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(752): objectsFailed:0
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(755): totalBytes:24556
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(800): objectsexamined:1
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(804): objectscomplete:1
11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(808): objectsfailed:0
[B]11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(813): totalBytes:24556[/B]


11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(825): calling dsmProxyTerminate()
11/29/2012 13:54:22.592 : tsmproxy.cpp        (1253): tsmProxyTerminate ENTRY: tsmHandle=1 proxyHandle =1 
11/29/2012 13:54:22.592 : tsmproxy.cpp        (1278): tsmProxyTerminate EXIT: rc = >0<.
11/29/2012 13:54:22.592 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(834): calling dsmTerminate()
11/29/2012 13:54:22.592 : dsmterm.cpp         ( 242): dsmTerminate ENTRY: dsmHandle is 1
11/29/2012 13:54:22.592 : dsmterm.cpp         ( 276): dsmTerminate: call ApiCleanUp . rc = 0
11/29/2012 13:54:22.592 : dsminit.cpp         (3252): ApiCleanUp : handle is = 1 
11/29/2012 13:54:27.493 : apianchr.cpp        ( 726): anDeleteAnchor: Free the space for myAnchor handle is 1
11/29/2012 13:54:27.493 : dsmterm.cpp         ( 284): dsmTerminate EXIT: rc = >0<.
11/29/2012 13:54:27.493 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1024): TRACE END
11/29/2012 13:54:27.493 : dsmsetup.cpp        ( 988): dsmCleanUp ENTRY: mtFlag = 1. 
11/29/2012 13:54:27.493 : dsmsetup.cpp        ( 999): dsmCleanUp entered. 
11/29/2012 13:54:27.493 : dsminit.cpp         (3283): ApiCleanUp : Final exit


dsmerror_dm.log -as you can see it is still complaining about the passwd not set, but backup succeded.
Code: 
11/29/2012 13:54:07 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
11/29/2012 13:54:07 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
11/29/2012 13:54:13 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
11/29/2012 13:54:13 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
11/29/2012 13:59:12 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
11/29/2012 13:59:12 ANS9370W Use Preferences Editor or dsmc SET PASSWORD -type=VM 'VirtualCenter hostname' 'userid' 'password' to save encrypted password.
 
Status
Not open for further replies.

Data Privacy Impact Assessment

Compliance Assurance in Every Byte: Discover the Impact of Our DPIA Services.

Sponsor ADSM.ORG

If you are reading this, so are your potential customer. Advertise at ADSM.ORG right now.

Navigation Menu

Forums
   IBM TSM
   EMC Backup and Recovery
   Symantec NetBackup  
   SAN  
   NAS
   Platforms / OS
Mailing List Archives
   ADSM-L
User Groups

NordVPN 3 Months FREE

Help Support ADSM.ORG and Get NordVPN with 64% Off and 3 Months FREE.

NordVPN with 64% off + 3 months FREE

Forum statistics

Threads
31,974
Messages
135,447
Members
21,952
Latest member
gatherpc
Back
Top