Results 1 to 5 of 5
  1. #1
    Member
    Join Date
    Nov 2012
    Posts
    8
    Thanks
    0
    Thanked 0 Times in 0 Posts

    Default TDP backup fails after backing up first vmdk

    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
    	Transport:     (nbd)[sending]
    Volume --> 16,106,127,360 [DS4300_R10_LUN1] myVM3/myVM3.vmdk (Hard Disk 1) [Sent]      
    
    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

  2. #2
    Member zsoltesz's Avatar
    Join Date
    Feb 2008
    Location
    Hungary
    Posts
    101
    Thanks
    0
    Thanked 2 Times in 2 Posts

    Default

    You maybe will find other information about the error in the dsmerror.log file and TSM server activity log.

  3. #3
    Member
    Join Date
    Nov 2012
    Posts
    8
    Thanks
    0
    Thanked 0 Times in 0 Posts

    Default

    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!


    Quote Originally Posted by zsoltesz View Post
    You maybe will find other information about the error in the dsmerror.log file and TSM server activity log.
    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.
    11/29/2012 13:38:27 Unexpected error. Please check the TSM Error Log for any additional information
    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 = 
    11/29/2012 13:38:25.340 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1654): #CHILD bytessent:31457280
    
    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 = 
    11/29/2012 13:38:26.343 : dsmtrace.cpp        ( 146): TSMCLI - utility.cpp(1654): #CHILD bytessent:0
    
    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<.
    11/29/2012 13:38:29.642 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(681): dsmProxySend() returned rc = 115, exiting....
    11/29/2012 13:38:29.642 : dsmmsg.cpp          ( 763): dsmRCMsg ENTRY: tsmHandle=1 rc: 115 msg : 0x7fff8ac9dea0
    11/29/2012 13:38:29.642 : dsmmsg.cpp          (1167): tsmHandle=1 rc: 115 msg : >ANS1236E (RC115)  An unexpected error occurred.<
    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.

  4. #4
    Member
    Join Date
    Nov 2012
    Posts
    8
    Thanks
    0
    Thanked 0 Times in 0 Posts

    Default

    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
    11/29/2012 13:54:22.591 : dsmtrace.cpp        ( 146): TSMCLI - backup.cpp(813): totalBytes:24556
    
    
    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.

  5. #5
    Member
    Join Date
    Nov 2012
    Posts
    8
    Thanks
    0
    Thanked 0 Times in 0 Posts

    Default

    Hi

    After struggle it came out that bug IC88237 (which should be related only to RHEL6 and Suse) happened on RHEL5 as well.
    http://www-01.ibm.com/support/docvie...id=swg1IC88237

    So we need to check for 6.4.0.1
    m.

Similar Threads

  1. TSM TDP BACKUP !!! fails again Need Help
    By zolagbr in forum TSM Client
    Replies: 10
    Last Post: 04-15-2013, 01:38 PM
  2. TDP R3 backup fails with RC 30
    By bprrajeev in forum Backup / Archive Discussion
    Replies: 2
    Last Post: 07-29-2012, 12:08 AM
  3. VCB is backing up the wrong vmdk file
    By gerardo2475 in forum VCB - VMware Consolidated Backup
    Replies: 2
    Last Post: 11-14-2011, 11:00 AM
  4. VMDK backup/restore query script
    By Cxloud in forum Scripting
    Replies: 0
    Last Post: 02-11-2011, 07:26 AM
  5. Replies: 6
    Last Post: 06-21-2005, 07:43 AM

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •