VM backup are failing with 4239 Error

[H_Sharma]

Hello Experts,

VMBackups are failing with 4239 error. Backup is done via vmhost.Pls find the log. Master is 2008 server and netbackup is 7.6

2014 7:49:42 AM - granted resource xxxx-hcart3-robot-tld-0

7/17/2014 7:49:42 AM - estimated 48490352 Kbytes needed

7/17/2014 7:49:42 AM - begin Parent Job

7/17/2014 7:49:42 AM - begin VMware, Start Notify Script

7/17/2014 7:49:42 AM - Info RUNCMD(pid=15272) started           

7/17/2014 7:49:42 AM - Info RUNCMD(pid=15272) exiting with status: 0        

Status 0

7/17/2014 7:49:42 AM - end VMware, Start Notify Script; elapsed time: 0:00:00

7/17/2014 7:49:42 AM - begin VMware, Step By Condition

Status 0

7/17/2014 7:49:42 AM - end VMware, Step By Condition; elapsed time: 0:00:00

7/17/2014 7:49:42 AM - begin VMware, Read File List

Status 0

7/17/2014 7:49:42 AM - end VMware, Read File List; elapsed time: 0:00:00

7/17/2014 7:49:42 AM - begin VMware, Create Snapshot

7/17/2014 7:49:42 AM - started

7/17/2014 7:49:43 AM - Info bpbrm(pid=3560) 10.84.0.25 is the host to backup data from    

7/17/2014 7:49:43 AM - Info bpbrm(pid=3560) reading file list for client       

7/17/2014 7:49:43 AM - Info bpbrm(pid=3560) start bpfis on client        

7/17/2014 7:49:43 AM - started process bpbrm (3560)

7/17/2014 7:49:44 AM - Info bpbrm(pid=3560) Starting create snapshot processing        

7/17/2014 7:49:45 AM - Info bpfis(pid=17112) Backup started          

7/17/2014 7:49:46 AM - snapshot backup of client 10.84.0.25 using method VMware_v2

7/17/2014 7:49:48 AM - Critical bpbrm(pid=3560) from client 10.84.0.25: FTL - find_virtual_server_vm: Unable to Login to server: xxxx.: SYM_VMC_FAILED_TO_CREATE_SNAPSHOT

7/17/2014 7:49:48 AM - Critical bpbrm(pid=3560) from client 10.84.0.25: FTL - VMware_freeze: Unable to locate VM 10.84.0.25 using VM hostname

7/17/2014 7:49:48 AM - Critical bpbrm(pid=3560) from client 10.84.0.25: FTL - vfm_freeze: method: VMware_v2, type: FIM, function: VMware_v2_freeze

7/17/2014 7:49:48 AM - Critical bpbrm(pid=3560) from client 10.84.0.25: FTL - vfm_freeze: method: VMware_v2, type: FIM, function: VMware_v2_freeze

7/17/2014 7:49:48 AM - Critical bpbrm(pid=3560) from client 10.84.0.25: FTL - snapshot processing failed, status 4239  

7/17/2014 7:49:48 AM - Critical bpbrm(pid=3560) from client 10.84.0.25: FTL - snapshot creation failed, status 4239  

7/17/2014 7:49:48 AM - Warning bpbrm(pid=3560) from client 10.84.0.25: WRN - ALL_LOCAL_DRIVES is not frozen   

7/17/2014 7:49:48 AM - Info bpfis(pid=17112) done. status: 4239         

7/17/2014 7:49:48 AM - end VMware, Create Snapshot; elapsed time: 0:00:06

7/17/2014 7:49:48 AM - Info bpfis(pid=17112) done. status: 4239: Unable to find the virtual machine   

7/17/2014 7:49:48 AM - end writing

Status 4239

7/17/2014 7:49:48 AM - end Parent Job; elapsed time: 0:00:06

7/17/2014 7:49:48 AM - begin VMware, Stop On Error

Status 0

7/17/2014 7:49:48 AM - end VMware, Stop On Error; elapsed time: 0:00:00

7/17/2014 7:49:48 AM - begin VMware, Delete Snapshot

7/17/2014 7:49:48 AM - started process bpbrm (6732)

7/17/2014 7:49:49 AM - Info bpbrm(pid=6732) Starting delete snapshot processing        

7/17/2014 7:49:50 AM - Info bpfis(pid=14896) Backup started          

7/17/2014 7:49:50 AM - Critical bpbrm(pid=6732) from client 10.84.0.25: cannot open E:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.10.84.0.25_1405559982.1.0     

7/17/2014 7:49:50 AM - Info bpfis(pid=14896) done. status: 4207         

7/17/2014 7:49:50 AM - end VMware, Delete Snapshot; elapsed time: 0:00:02

7/17/2014 7:49:50 AM - Info bpfis(pid=14896) done. status: 4207: Could not fetch snapshot metadata or state files 

7/17/2014 7:49:50 AM - end writing

Status 4207

7/17/2014 7:49:50 AM - end operation

Status 4239

7/17/2014 7:49:50 AM - end operation

Unable to find the virtual machine(4239)

 Pls help.

[H_Sharma]

There is one more error... In other server. Same like that

7/17/2014 7:34:16 AM - Info nbjm(pid=3724) starting backup job (jobid=39436) for client 10.84.0.24, policy VAS, schedule cumulative_incremental  
7/17/2014 7:34:16 AM - Info nbjm(pid=3724) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=39436, request id:{54DEBA9C-1F79-4F4D-811D-C56052983303})  
7/17/2014 7:34:16 AM - requesting resource xxxx-hcart3-robot-tld-0
7/17/2014 7:34:16 AM - requesting resource xxxx.NBU_CLIENT.MAXJOBS.10.84.0.24
7/17/2014 7:34:16 AM - requesting resource xxxx.NBU_POLICY.MAXJOBS.VAS
7/17/2014 7:34:18 AM - awaiting resource xxxx-hcart3-robot-tld-0 Reason: Drives are in use, Media Server: xxxxx, 
     Robot Number: 0, Robot Type: TLD, Media ID: N/A, Drive Name: N/A, 
     Volume Pool: V, Storage Unit: xxxx-hcart3-robot-tld-0, Drive Scan Host: N/A
    
7/17/2014 7:48:29 AM - granted resource xxxx.NBU_CLIENT.MAXJOBS.10.84.0.24
7/17/2014 7:48:29 AM - granted resource xxxx.NBU_POLICY.MAXJOBS.VAS
7/17/2014 7:48:29 AM - granted resource TNM060
7/17/2014 7:48:29 AM - granted resource Drive007
7/17/2014 7:48:29 AM - granted resource xxxx-hcart3-robot-tld-0
7/17/2014 7:48:29 AM - started
7/17/2014 7:48:30 AM - estimated 23944591 Kbytes needed
7/17/2014 7:48:30 AM - begin Parent Job
7/17/2014 7:48:30 AM - begin VMware, Start Notify Script
7/17/2014 7:48:30 AM - Info RUNCMD(pid=15336) started            
7/17/2014 7:48:30 AM - Info RUNCMD(pid=15336) exiting with status: 0         
Status 0
7/17/2014 7:48:30 AM - end VMware, Start Notify Script; elapsed time: 0:00:00
7/17/2014 7:48:30 AM - begin VMware, Step By Condition
Status 0
7/17/2014 7:48:30 AM - end VMware, Step By Condition; elapsed time: 0:00:00
7/17/2014 7:48:30 AM - begin VMware, Read File List
Status 0
7/17/2014 7:48:30 AM - end VMware, Read File List; elapsed time: 0:00:00
7/17/2014 7:48:30 AM - begin VMware, Create Snapshot
7/17/2014 7:48:31 AM - started process bpbrm (14572)
7/17/2014 7:48:35 AM - Info bpbrm(pid=14572) 10.84.0.24 is the host to backup data from     
7/17/2014 7:48:35 AM - Info bpbrm(pid=14572) reading file list for client        
7/17/2014 7:48:35 AM - Info bpbrm(pid=14572) start bpfis on client         
7/17/2014 7:48:37 AM - Info bpbrm(pid=14572) Starting create snapshot processing         
7/17/2014 7:48:39 AM - Info bpfis(pid=4464) Backup started           
7/17/2014 7:48:40 AM - snapshot backup of client 10.84.0.24 using method VMware_v2
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: RetrieveObjPropertiesEx: for mor = vm-412 failed, SYM_VMC_ERROR:  SOAP_ERROR 
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: SOAP 1.1 fault: SOAP-ENV:Client [no subcode]    
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: getObjectProperties: Could not get properties for Mor=<vm-412><VirtualMachine>   
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: getObjectProperties: SYM_VMC_ERROR:  FAILED_TO_GET_OBJECT_PROPERTY      
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: RetrieveFolderContents: SYM_VMC_ERROR:  FAILED_TO_GET_OBJECT_PROPERTY      
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: RetrieveFolderContents: SYM_VMC_ERROR:  FAILED_TO_GET_OBJECT_PROPERTY      
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: RetrieveFolderContents: SYM_VMC_ERROR:  FAILED_TO_GET_OBJECT_PROPERTY      
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: RetrieveDatacenterContents: SYM_VMC_ERROR:  FAILED_TO_GET_OBJECT_PROPERTY      
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: BuildHostsAndClustersView: SYM_VMC_ERROR:  FAILED_TO_GET_OBJECT_PROPERTY      
7/17/2014 7:49:17 AM - Info bpbrm(pid=14572) INF - vmwareLogger: BuildDatabases: SYM_VMC_ERROR:  FAILED_TO_GET_DSHM_PROPERTIES      
7/17/2014 7:49:17 AM - Critical bpbrm(pid=14572) from client 10.84.0.24: FTL - VMware_freeze: VIXAPI freeze failed unknown client 10.84.0.24: SYM_VMC_FAILED_TO_GET_DSHM_PROPERTIES
7/17/2014 7:49:17 AM - Critical bpbrm(pid=14572) from client 10.84.0.24: FTL - VMware error received: No connection could be made because the target machine actively refused it.7/17/2014 7:49:18 AM - Info bpbrm(pid=14572) INF - vmwareLogger: SOAP 1.1 fault: SOAP-ENV:Client [no subcode]    
7/17/2014 7:49:18 AM - end writing
Status 4239
7/17/2014 7:49:18 AM - end VMware, Create Snapshot; elapsed time: 0:00:48
7/17/2014 7:49:18 AM - begin VMware, Stop On Error
Status 0
7/17/2014 7:49:18 AM - end VMware, Stop On Error; elapsed time: 0:00:00
7/17/2014 7:49:18 AM - begin VMware, Delete Snapshot
7/17/2014 7:49:18 AM - Critical bpbrm(pid=14572) from client 10.84.0.24: FTL - vfm_freeze: method: VMware_v2, type: FIM, function: VMware_v2_freeze 
7/17/2014 7:49:18 AM - Critical bpbrm(pid=14572) from client 10.84.0.24: FTL - vfm_freeze: method: VMware_v2, type: FIM, function: VMware_v2_freeze 
7/17/2014 7:49:18 AM - Critical bpbrm(pid=14572) from client 10.84.0.24: FTL - snapshot processing failed, status 4239   
7/17/2014 7:49:18 AM - Critical bpbrm(pid=14572) from client 10.84.0.24: FTL - snapshot creation failed, status 4239   
7/17/2014 7:49:18 AM - Warning bpbrm(pid=14572) from client 10.84.0.24: WRN - ALL_LOCAL_DRIVES is not frozen    
7/17/2014 7:49:18 AM - Info bpfis(pid=4464) done. status: 4239          
7/17/2014 7:49:18 AM - end VMware, Delete Snapshot; elapsed time: 0:00:00
7/17/2014 7:49:18 AM - Info bpfis(pid=4464) done. status: 4239: Unable to find the virtual machine    
7/17/2014 7:49:18 AM - started process bpbrm (15216)
7/17/2014 7:49:24 AM - Info bpbrm(pid=15216) Starting delete snapshot processing         
7/17/2014 7:49:27 AM - Info bpfis(pid=3800) Backup started           
7/17/2014 7:49:27 AM - Critical bpbrm(pid=15216) from client 10.84.0.24: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.10.84.0.24_1405559909.1.0      
7/17/2014 7:49:27 AM - Info bpfis(pid=3800) done. status: 4207          
7/17/2014 7:49:27 AM - end Parent Job; elapsed time: 0:00:57
7/17/2014 7:49:27 AM - Info bpfis(pid=3800) done. status: 4207: Could not fetch snapshot metadata or state files  
7/17/2014 7:49:27 AM - end writing
Status 4207
7/17/2014 7:49:27 AM - end operation
Status 4239
7/17/2014 7:49:27 AM - end operation
Unable to find the virtual machine(4239)

[John_Meaders]

Status 4239 means it is unable to find the virtual machine. Have you tried picking a different method (e.g. display name, DNS name, etc.)?

[H_Sharma]

Hi John,

Our windows guys have observed this.

"During the call with VMWare Technical Support, it was identified that snapshot delta files are not being removed from the data store after successful or failed backup. 

We have servers on which we have more than 90 snapshot files and all these servers need to be consolidated. It will take some time and manual efforts from team"

It is happening due to this ? Machines are failing...? Whose issue is this files are not getting deleted Vmware or Netbackup?

[DG-2005]

would like to see an answer to this , as we are seeing similar issues with snapshot files as well.

my guess is NBU tries to remove it, but there's a lock within vCenter that prevents it, since it sees it still as an 'active' snapshot and therefore, cannot be removed.

[NBU35 · Accepted solution]

Are you facing issue with backups of all virtual machines, which are configured through same Vcenter or ESX host ?

Also check for the error in vcenter console, also try to validate the credential of Vmware server under credentials section of the Netbackup.

[RiaanBadenhorst]

Are your credentials still valid? find_virtual_server_vm: Unable to Login to server: xxxx.: