NetBackup 7.5.0.4 - Exchange DB Backup fails with Error 1542 -> manual Backup DOES work

[mtuertscher]

Hi!

We set up a Backupjob for an single Exchange Server (no DAG, just 3 single DBs) but it fails with Error 1542 when the Jobs starts automatically.

If I start the Backupjob manualy the Job finishes without Problems and the Backup is fine

Already restarted all Agents on the Servers and just updated to 7.5.0.5 but have to wait till today evening..

Here is the log from a failed backup, hope someone can help me

25.03.2013 21:38:16 - Info nbjm(pid=3772) starting backup job (jobid=120) for client 10.60.226.100, policy MHER_Exchange_DB_Only, schedule DLY 
25.03.2013 21:38:16 - Info nbjm(pid=3772) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=120, request id:{7975B4A2-0F72-4A74-B3DA-36AB15EDB2D1}) 
25.03.2013 21:38:16 - requesting resource AHERSRVDED02
25.03.2013 21:38:16 - requesting resource mhersrvbck01.NBU_CLIENT.MAXJOBS.10.60.226.100
25.03.2013 21:38:16 - requesting resource mhersrvbck01.NBU_POLICY.MAXJOBS.MHER_Exchange_DB_Only
25.03.2013 21:38:16 - granted resource mhersrvbck01.NBU_CLIENT.MAXJOBS.10.60.226.100
25.03.2013 21:38:16 - granted resource mhersrvbck01.NBU_POLICY.MAXJOBS.MHER_Exchange_DB_Only
25.03.2013 21:38:16 - granted resource MediaID=@aaaab;Path=\\ahersrvded02\bkup-exchange;MediaServer=mhersrvbck01
25.03.2013 21:38:16 - granted resource AHERSRVDED02
25.03.2013 21:38:16 - estimated 0 Kbytes needed
25.03.2013 21:38:16 - begin Parent Job
25.03.2013 21:38:16 - begin Snapshot, Start Notify Script
25.03.2013 21:38:16 - Info RUNCMD(pid=4108) started           
25.03.2013 21:38:16 - Info RUNCMD(pid=4108) exiting with status: 0        
Status 0
25.03.2013 21:38:16 - end Snapshot, Start Notify Script; elapsed time: 00:00:00
25.03.2013 21:38:16 - begin Snapshot, Step By Condition
Status 0
25.03.2013 21:38:16 - end Snapshot, Step By Condition; elapsed time: 00:00:00
25.03.2013 21:38:16 - begin Snapshot, Read File List
Status 0
25.03.2013 21:38:16 - end Snapshot, Read File List; elapsed time: 00:00:00
25.03.2013 21:38:16 - begin Snapshot, Create Snapshot
25.03.2013 21:38:16 - started process bpbrm (4752)
25.03.2013 21:38:16 - started
25.03.2013 21:38:23 - Info bpbrm(pid=4752) 10.60.226.100 is the host to backup data from    
25.03.2013 21:38:23 - Info bpbrm(pid=4752) reading file list from client       
25.03.2013 21:38:23 - Info bpbrm(pid=4752) start bpfis on client        
25.03.2013 21:38:23 - Info bpbrm(pid=4752) Starting create snapshot processing        
25.03.2013 21:38:24 - Info bpfis(pid=8796) Backup started          
25.03.2013 21:38:37 - end writing
Status 130
25.03.2013 21:38:37 - end Snapshot, Create Snapshot; elapsed time: 00:00:21
25.03.2013 21:38:37 - begin Snapshot, Stop On Error
Status 0
25.03.2013 21:38:37 - end Snapshot, Stop On Error; elapsed time: 00:00:00
25.03.2013 21:38:37 - begin Snapshot, Delete Snapshot
25.03.2013 21:38:37 - started process bpbrm (1604)
25.03.2013 21:38:42 - Info bpbrm(pid=1604) Starting delete snapshot processing        
25.03.2013 21:38:42 - Info bpfis(pid=0) Snapshot will not be deleted       
25.03.2013 21:38:45 - Info bpfis(pid=8748) Backup started          
25.03.2013 21:38:45 - Critical bpbrm(pid=1604) from client 10.60.226.100: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.10.60.226.100_1364243896.1.0     
25.03.2013 21:38:46 - end writing
Status 1542
25.03.2013 21:38:46 - end Snapshot, Delete Snapshot; elapsed time: 00:00:09
25.03.2013 21:38:46 - begin Snapshot, End Notify Script
25.03.2013 21:38:46 - Info RUNCMD(pid=4836) started           
25.03.2013 21:38:46 - Info RUNCMD(pid=4836) exiting with status: 0        
Status 0
25.03.2013 21:38:46 - end Snapshot, End Notify Script; elapsed time: 00:00:00
Status 1542
25.03.2013 21:38:46 - end Parent Job; elapsed time: 00:00:30
An existing snapshot is no longer valid and cannot be mounted for subsequent operations(1542)

[Mark_Solutions]

Is anything else interfacing with Exchange? Do you have the NetBackup Legacy Network Service running as an exchange admin account? The only real difference between manual and scheduled backups is the accounts that can get used. The snapshot error does indicate that a snapshot is invalid so you may just need a re-start or the replication service to clear this

[mtuertscher]

no, nothing else interfacing - or what do you mean exactly for example?

yes, the client service and the legacy client service is running as exchange admin account.

do you mean restarting the exchange server? how do i you the replication service to clear this?

[Mark_Solutions · Accepted solution]

I meant any other form of backup running against exchange - NT or any internal exchange backup plan. And it is the NetBackup Legacy NETWORK Service that needs to be set as an account, not the NetBackup Legacy Client Service (though you can leave that one set if you wish) Usually in a DAG is the Exchange Replication Service - it is usually this that needs re-starting to clear the writer errors - or, if possible, the Information Store service Hope this helps

[mtuertscher]

oh, i changed the legacy network service to logon with the service account and also the netbackup client and netbackup legacy client service

no, no other backup runs at the same time and there is no DAG configured in this case..

thanks for your help, i will see tonight if the backup runs through, else i post the log tomorrow here

[mtuertscher]

the backup is still failing with error 1542.

-> its the only backup which is scheduled
-> the services client/legacy/legacy network are running as the service account for exchange backup
 

this is the log

27.03.2013 21:17:56 - Info nbjm(pid=3948) starting backup job (jobid=143) for client 10.60.226.100, policy MHER_Exchange_DB_Only, schedule DLY 
27.03.2013 21:17:56 - Info nbjm(pid=3948) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=143, request id:{7EC4A745-757A-4813-8CDB-6FD8E08FA1EC}) 
27.03.2013 21:17:56 - requesting resource AHERSRVDED02
27.03.2013 21:17:56 - requesting resource mhersrvbck01.NBU_CLIENT.MAXJOBS.10.60.226.100
27.03.2013 21:17:56 - requesting resource mhersrvbck01.NBU_POLICY.MAXJOBS.MHER_Exchange_DB_Only
27.03.2013 21:17:56 - granted resource mhersrvbck01.NBU_CLIENT.MAXJOBS.10.60.226.100
27.03.2013 21:17:56 - granted resource mhersrvbck01.NBU_POLICY.MAXJOBS.MHER_Exchange_DB_Only
27.03.2013 21:17:56 - granted resource MediaID=@aaaab;Path=\\ahersrvded02\bkup-exchange;MediaServer=mhersrvbck01
27.03.2013 21:17:56 - granted resource AHERSRVDED02
27.03.2013 21:17:56 - estimated 0 Kbytes needed
27.03.2013 21:17:56 - begin Parent Job
27.03.2013 21:17:56 - begin Snapshot, Start Notify Script
27.03.2013 21:17:56 - Info RUNCMD(pid=816) started           
27.03.2013 21:17:56 - Info RUNCMD(pid=816) exiting with status: 0        
Status 0
27.03.2013 21:17:56 - end Snapshot, Start Notify Script; elapsed time: 00:00:00
27.03.2013 21:17:56 - begin Snapshot, Step By Condition
Status 0
27.03.2013 21:17:56 - end Snapshot, Step By Condition; elapsed time: 00:00:00
27.03.2013 21:17:56 - begin Snapshot, Read File List
Status 0
27.03.2013 21:17:56 - end Snapshot, Read File List; elapsed time: 00:00:00
27.03.2013 21:17:56 - begin Snapshot, Create Snapshot
27.03.2013 21:17:56 - started
27.03.2013 21:17:57 - started process bpbrm (2124)
27.03.2013 21:18:03 - Info bpbrm(pid=2124) 10.60.226.100 is the host to backup data from    
27.03.2013 21:18:03 - Info bpbrm(pid=2124) reading file list from client       
27.03.2013 21:18:03 - Info bpbrm(pid=2124) start bpfis on client        
27.03.2013 21:18:03 - Info bpbrm(pid=2124) Starting create snapshot processing        
27.03.2013 21:18:05 - Info bpfis(pid=900) Backup started          
27.03.2013 21:23:35 - end writing
Status 130
27.03.2013 21:23:35 - end Snapshot, Create Snapshot; elapsed time: 00:05:39
27.03.2013 21:23:35 - begin Snapshot, Stop On Error
Status 0
27.03.2013 21:23:35 - end Snapshot, Stop On Error; elapsed time: 00:00:00
27.03.2013 21:23:35 - begin Snapshot, Delete Snapshot
27.03.2013 21:23:35 - started process bpbrm (3940)
27.03.2013 21:23:40 - Info bpbrm(pid=3940) Starting delete snapshot processing        
27.03.2013 21:23:40 - Info bpfis(pid=0) Snapshot will not be deleted       
27.03.2013 21:23:43 - Info bpfis(pid=9076) Backup started          
27.03.2013 21:23:43 - Critical bpbrm(pid=3940) from client 10.60.226.100: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.10.60.226.100_1364415476.1.0     
27.03.2013 21:23:44 - end writing
Status 1542
27.03.2013 21:23:44 - end Snapshot, Delete Snapshot; elapsed time: 00:00:09
27.03.2013 21:23:44 - begin Snapshot, End Notify Script
27.03.2013 21:23:44 - Info RUNCMD(pid=3872) started           
27.03.2013 21:23:44 - Info RUNCMD(pid=3872) exiting with status: 0        
Status 0
27.03.2013 21:23:44 - end Snapshot, End Notify Script; elapsed time: 00:00:00
Status 1542
27.03.2013 21:23:44 - end Parent Job; elapsed time: 00:05:48
An existing snapshot is no longer valid and cannot be mounted for subsequent operations(1542)