Video Screencast Help

Exchange Backup Failure

Created: 03 May 2013 | 1 comment

Hello,

all the sudden our exchange backups begin failing. Below is the Details from both the mbx02 and dag01 backups.

5/2/2013 5:59:15 PM - Info nbjm(pid=6568) starting backup job (jobid=322849) for client MBX02, policy Exchange, schedule Full 
5/2/2013 5:59:15 PM - Info nbjm(pid=6568) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=322849, request id:{C747D6AD-EE1D-4BEA-93E8-D63EE24F772F}) 
5/2/2013 5:59:15 PM - requesting resource Any
5/2/2013 5:59:15 PM - requesting resource horus.NBU_CLIENT.MAXJOBS.MBX02
5/2/2013 5:59:15 PM - requesting resource horus.NBU_POLICY.MAXJOBS.Exchange
5/2/2013 5:59:15 PM - granted resource horus.NBU_CLIENT.MAXJOBS.MBX02
5/2/2013 5:59:15 PM - granted resource horus.NBU_POLICY.MAXJOBS.Exchange
5/2/2013 5:59:15 PM - granted resource 093752
5/2/2013 5:59:15 PM - granted resource IBM.ULTRIUM-TD4.005
5/2/2013 5:59:15 PM - granted resource horus-hcart-robot-tld-1
5/2/2013 5:59:15 PM - estimated 248456322 Kbytes needed
5/2/2013 5:59:15 PM - begin Parent Job
5/2/2013 5:59:15 PM - begin Exchange 14 Snapshot, Step By Condition
Status 0
5/2/2013 5:59:15 PM - end Exchange 14 Snapshot, Step By Condition; elapsed time: 00:00:00
5/2/2013 5:59:15 PM - begin Exchange 14 Snapshot, Read File List
Status 0
5/2/2013 5:59:15 PM - end Exchange 14 Snapshot, Read File List; elapsed time: 00:00:00
5/2/2013 5:59:15 PM - begin Exchange 14 Snapshot, Create Snapshot
5/2/2013 5:59:15 PM - started process bpbrm (7168)
5/2/2013 5:59:15 PM - started
5/2/2013 5:59:20 PM - Info bpbrm(pid=7168) MBX02 is the host to backup data from    
5/2/2013 5:59:20 PM - Info bpbrm(pid=7168) reading file list from client       
5/2/2013 5:59:20 PM - Info bpbrm(pid=7168) start bpfis on client        
5/2/2013 5:59:20 PM - Info bpbrm(pid=7168) Starting create snapshot processing        
5/2/2013 5:59:22 PM - Info bpfis(pid=6428) Backup started          
5/2/2013 5:59:33 PM - Critical bpbrm(pid=7168) from client MBX02: FTL - snapshot creation failed - Error attempting to gather metadata., status 130
5/2/2013 5:59:33 PM - Info bpbrm(pid=7168) DB_BACKUP_STATUS is 156         
5/2/2013 5:59:33 PM - Warning bpbrm(pid=7168) from client MBX02: WRN - NEW_STREAM0 is not frozen   
5/2/2013 5:59:33 PM - Warning bpbrm(pid=7168) from client MBX02: WRN - Microsoft Information Store:\MDB02 is not frozen 
5/2/2013 5:59:33 PM - Info bpfis(pid=6428) done. status: 130         
5/2/2013 5:59:33 PM - end Exchange 14 Snapshot, Create Snapshot; elapsed time: 00:00:18
5/2/2013 5:59:33 PM - Info bpfis(pid=0) done. status: 130: system error occurred      
5/2/2013 5:59:33 PM - end writing
Status 130
5/2/2013 5:59:33 PM - end Parent Job; elapsed time: 00:00:18
5/2/2013 5:59:33 PM - begin Exchange 14 Snapshot, Stop On Error
Status 0
5/2/2013 5:59:33 PM - end Exchange 14 Snapshot, Stop On Error; elapsed time: 00:00:00
5/2/2013 5:59:33 PM - begin Exchange 14 Snapshot, Delete Snapshot
5/2/2013 5:59:34 PM - started process bpbrm (7664)
5/2/2013 5:59:39 PM - Info bpbrm(pid=7664) Starting delete snapshot processing        
5/2/2013 5:59:39 PM - Info bpfis(pid=0) Snapshot will not be deleted       
5/2/2013 5:59:42 PM - Info bpfis(pid=5384) Backup started          
5/2/2013 5:59:42 PM - Critical bpbrm(pid=7664) from client MBX02: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.DAG01_1367531955.1.0     
5/2/2013 5:59:43 PM - Info bpfis(pid=5384) done. status: 1542         
5/2/2013 5:59:43 PM - end Exchange 14 Snapshot, Delete Snapshot; elapsed time: 00:00:10
5/2/2013 5:59:43 PM - Info bpfis(pid=0) done. status: 1542: An existing snapshot is no longer valid and cannot be mounted for subsequent operations
5/2/2013 5:59:43 PM - end writing
Status 1542
5/2/2013 5:59:43 PM - end operation
Status 130
5/2/2013 5:59:43 PM - end operation
system error occurred(130)

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

5/2/2013 5:58:55 PM - Info nbjm(pid=6568) starting backup job (jobid=322848) for client DAG01, policy Exchange, schedule Full 
5/2/2013 5:58:55 PM - Info nbjm(pid=6568) requesting MEDIA_SERVER_ONLY resources from RB for backup job (jobid=322848, request id:{98DDDC82-222F-4C52-8948-AD0512454131}) 
5/2/2013 5:58:55 PM - requesting resource Any
5/2/2013 5:58:55 PM - requesting resource horus.NBU_CLIENT.MAXJOBS.DAG01
5/2/2013 5:58:55 PM - requesting resource horus.NBU_POLICY.MAXJOBS.Exchange
5/2/2013 5:58:55 PM - requesting resource EXCHANGE_RESOLVER.horus.Exchange.DAG01
5/2/2013 5:58:55 PM - granted resource horus.NBU_CLIENT.MAXJOBS.DAG01
5/2/2013 5:58:55 PM - granted resource horus.NBU_POLICY.MAXJOBS.Exchange
5/2/2013 5:58:55 PM - granted resource EXCHANGE_RESOLVER.horus.Exchange.DAG01
5/2/2013 5:58:56 PM - estimated 0 Kbytes needed
5/2/2013 5:58:56 PM - begin Parent Job
5/2/2013 5:58:56 PM - begin Exchange 14 Resolver, Start Notify Script
5/2/2013 5:58:56 PM - Info RUNCMD(pid=8328) started           
5/2/2013 5:58:56 PM - Info RUNCMD(pid=8328) exiting with status: 0        
Status 0
5/2/2013 5:58:56 PM - end Exchange 14 Resolver, Start Notify Script; elapsed time: 00:00:00
5/2/2013 5:58:56 PM - begin Exchange 14 Resolver, Step By Condition
Status 0
5/2/2013 5:58:56 PM - end Exchange 14 Resolver, Step By Condition; elapsed time: 00:00:00
5/2/2013 5:58:56 PM - begin Exchange 14 Resolver, Read File List
Status 0
5/2/2013 5:58:56 PM - end Exchange 14 Resolver, Read File List; elapsed time: 00:00:00
5/2/2013 5:58:56 PM - begin Exchange 14 Resolver, Resolver Discovery
5/2/2013 5:58:57 PM - started process bpbrm (2644)
5/2/2013 5:58:58 PM - Info bpbrm(pid=2644) DAG01 is the host to restore to     
5/2/2013 5:58:58 PM - Info bpbrm(pid=2644) reading file list from client       
5/2/2013 5:59:07 PM - Info bpbrm(pid=2644) client_pid=8680           
5/2/2013 5:59:07 PM - Info bpbrm(pid=2644) from client DAG01: TRV - BPRESOLVER has executed on server (MBX02) 
5/2/2013 5:59:13 PM - Info bpresolver(pid=8680) done.  status: 0        
5/2/2013 5:59:13 PM - Info bpresolver(pid=8680) done. status: 0: the requested operation was successfully completed   
Status 0
5/2/2013 5:59:13 PM - end Exchange 14 Resolver, Resolver Discovery; elapsed time: 00:00:17
5/2/2013 5:59:13 PM - begin Exchange 14 Resolver, Persist Discovery
Status 0
5/2/2013 5:59:13 PM - end Exchange 14 Resolver, Persist Discovery; elapsed time: 00:00:00
5/2/2013 5:59:13 PM - begin Exchange 14 Resolver, Policy Execution Manager Preprocessed
Status 130
5/2/2013 5:59:43 PM - end Exchange 14 Resolver, Policy Execution Manager Preprocessed; elapsed time: 00:00:30
5/2/2013 5:59:43 PM - begin Exchange 14 Resolver, Stop On Error
Status 0
5/2/2013 5:59:43 PM - end Exchange 14 Resolver, Stop On Error; elapsed time: 00:00:00
5/2/2013 5:59:43 PM - begin Exchange 14 Resolver, End Notify Script
5/2/2013 5:59:44 PM - Info RUNCMD(pid=9396) started           
5/2/2013 5:59:44 PM - Info RUNCMD(pid=9396) exiting with status: 0        
Status 0
5/2/2013 5:59:44 PM - end Exchange 14 Resolver, End Notify Script; elapsed time: 00:00:01
Status 130
5/2/2013 5:59:44 PM - end Parent Job; elapsed time: 00:00:48
system error occurred(130)

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

thanks

Operating Systems:

Comments 1 CommentJump to latest comment

Mark_Solutions's picture

Usually this happens after a snapshot has failed or replication is out of sync

Run vssadmin list writers to see what state they are in and if any failed either re-start the exchange replication service or reboot

You could also run bpfis query to see if any snapshots have been left behind that need to be deleted

Authorised Symantec Consultant . Expert Partner.

Don't forget to "Mark as Solution" if someones advice has solved your issue - and please bring back the Thumbs Up!!.