NBU 7.1.0.3, Exchange 2007 SP3, status 130 errors when doing Fulls or Diff Inc Backups

[SimonAnderson]

Hi,

We currently have NetBackup 7.1.0.3 installed in our environment, trying to backup an Exchange 2007 SP3 CCR Cluster (passive only).

We have multiple Media servers in our environment, but as we have only recently migrated our Exchange backups from another software product, we are only using one Media Server/Storage Unit to backup our environment. We backup to disk using OST with DataDomains.

We are having a lot of random issues with our Exchange Backups, but I thought I would start with one particular issue and work from there.

Currently we randomly get 130 errors after several successful backups (whether the previous backup was a Full or Differential Incremental Backup). This can occur whether the backups are run as per the set schedule in the Backup Policy, or if the jobs are run manually.

The following is a snippet from a failed parent job:

07/22/2012 14:02:11 - Info nbjm (pid=8724) starting backup job (jobid=101801) for client mail1.acp.net, policy HOF-EXCH-GROUP2, schedule Annual_Full
07/22/2012 14:02:11 - Info nbjm (pid=8724) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=101801, request id:{C397B662-382D-4240-BCBC-2D3B4229D010})
07/22/2012 14:02:11 - requesting resource hof-ms01-exchannual-su
07/22/2012 14:02:11 - requesting resource acphofnbuma01.acp.net.NBU_CLIENT.MAXJOBS.mail1.acp.net
07/22/2012 14:02:11 - requesting resource acphofnbuma01.acp.net.NBU_POLICY.MAXJOBS.HOF-EXCH-GROUP2
07/22/2012 14:02:11 - granted resource  acphofnbuma01.acp.net.NBU_CLIENT.MAXJOBS.mail1.acp.net
07/22/2012 14:02:11 - granted resource  acphofnbuma01.acp.net.NBU_POLICY.MAXJOBS.HOF-EXCH-GROUP2
07/22/2012 14:02:11 - granted resource  MediaID=@aaaaA;Path=\\acphofdda01\ExchAnnualBACKUP;MediaServer=acphofnbums01.acp.net
07/22/2012 14:02:11 - granted resource  hof-ms01-exchannual-su
07/22/2012 14:02:11 - estimated 0 kbytes needed
07/22/2012 14:02:11 - begin Parent Job
07/22/2012 14:02:11 - begin Snapshot: Start Notify Script
07/22/2012 14:02:11 - Info RUNCMD (pid=3952) started
07/22/2012 14:02:11 - Info RUNCMD (pid=3952) exiting with status: 0
Operation Status: 0
07/22/2012 14:02:11 - end Snapshot: Start Notify Script; elapsed time 0:00:00
07/22/2012 14:02:11 - begin Snapshot: Step By Condition
Operation Status: 0
07/22/2012 14:02:11 - end Snapshot: Step By Condition; elapsed time 0:00:00
07/22/2012 14:02:11 - begin Snapshot: Stream Discovery
Operation Status: 0
07/22/2012 14:02:11 - end Snapshot: Stream Discovery; elapsed time 0:00:00
07/22/2012 14:02:11 - begin Snapshot: Read File List
Operation Status: 0
07/22/2012 14:02:11 - end Snapshot: Read File List; elapsed time 0:00:00
07/22/2012 14:02:11 - begin Snapshot: Create Snapshot
07/22/2012 14:02:13 - started process bpbrm (pid=30004)
07/22/2012 14:02:21 - Info bpbrm (pid=30004) mail1.acp.net is the host to backup data from
07/22/2012 14:02:21 - Info bpbrm (pid=30004) reading file list from client
07/22/2012 14:02:21 - Info bpbrm (pid=30004) start bpfis on client
07/22/2012 14:02:21 - begin Create Snapshot
07/22/2012 14:02:22 - Info bpfis (pid=14428) Backup started
07/22/2012 14:02:51 - Info bpbrm (pid=30004) from client mail1.acp.net: TRV - Redirecting snapshot backup to server (ACPHOFEXCM01)
07/22/2012 14:02:51 - Info bpbrm (pid=30004) Read redirected snapshot host ACPHOFEXCM01 from client mail1.acp.netINF - BACKUP_HOST=ACPHOFEXCM01
07/22/2012 14:02:52 - Info bpfis (pid=14428) done. status: 0
07/22/2012 14:02:52 - end Create Snapshot; elapsed time 0:00:31
07/22/2012 14:02:53 - begin Delete Snapshot
07/22/2012 14:02:55 - Info bpfis (pid=1376) Backup started
07/22/2012 14:02:55 - Critical bpbrm (pid=30004) from client mail1.acp.net: FTL - cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.mail1.acp.net_1342929731.0
07/22/2012 14:02:56 - Info bpfis (pid=1376) done. status: 0
07/22/2012 14:02:56 - end Delete Snapshot; elapsed time 0:00:03
07/22/2012 14:02:56 - Info bpbrm (pid=30004) start bpfis on client
07/22/2012 14:02:56 - begin Create Snapshot
07/22/2012 14:02:56 - Info bpfis (pid=7112) Backup started
07/22/2012 14:03:32 - Critical bpbrm (pid=30004) from client mail1.acp.net: FTL - snapshot creation failed - SNAPSHOT_NOTIFICATION::SnapshotPrepare failed., status 130
07/22/2012 14:03:32 - Critical bpbrm (pid=30004) from client mail1.acp.net: FTL - snapshot creation failed, status 130
07/22/2012 14:03:32 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM0 is not frozen
07/22/2012 14:03:32 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 18 is not frozen
07/22/2012 14:03:32 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM1 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 20 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM2 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 21 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM3 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 22 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM4 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 23 is not frozen
07/22/2012 14:03:33 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM5 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 24 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM6 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 25 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM7 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 26 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM8 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 27 is not frozen
07/22/2012 14:03:34 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM9 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 28 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM10 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 29 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM11 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 31 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM12 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 32 is not frozen
07/22/2012 14:03:35 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM13 is not frozen
07/22/2012 14:03:36 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Storage Group 33 is not frozen
07/22/2012 14:03:36 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - NEW_STREAM14 is not frozen
07/22/2012 14:03:36 - Warning bpbrm (pid=30004) from client mail1.acp.net: WRN - Microsoft Information Store:\Meeting Rooms is not frozen
07/22/2012 14:03:36 - Info bpfis (pid=7112) done. status: 130
07/22/2012 14:03:36 - end Create Snapshot; elapsed time 0:00:40
07/22/2012 14:03:38 - end writing
Operation Status: 130
07/22/2012 14:03:38 - end Snapshot: Create Snapshot; elapsed time 0:01:27
07/22/2012 14:03:38 - begin Snapshot: Stop On Error
Operation Status: 0
07/22/2012 14:03:38 - end Snapshot: Stop On Error; elapsed time 0:00:00
07/22/2012 14:03:38 - begin Snapshot: Delete Snapshot On Exit
07/22/2012 14:03:38 - begin Snapshot: Delete Snapshot On Exit
07/22/2012 14:03:39 - started process bpbrm (pid=69836)
07/22/2012 14:03:50 - end writing
Operation Status: 0
07/22/2012 14:03:50 - end Snapshot: Delete Snapshot On Exit; elapsed time 0:00:12
07/22/2012 14:03:50 - begin Snapshot: End Notify Script
07/22/2012 14:03:50 - Info RUNCMD (pid=13748) started
07/22/2012 14:03:50 - Info RUNCMD (pid=13748) exiting with status: 0
Operation Status: 0
07/22/2012 14:03:50 - end Snapshot: End Notify Script; elapsed time 0:00:00
Operation Status: 130
07/22/2012 14:03:50 - end Snapshot: Delete Snapshot On Exit; elapsed time 0:00:12
system error occurred  (130)

From what I have read regarding a lot of Exchange 2007 and 2010 issues regarding exchange back ups via VSS, the Storage Group status gets stuck in a "BackupInProgress" phase, when no backup is actually running.

You can resolve the issue by either restarting the passive node or restarting the "Microsoft Exchange Replication Service". Once this has been restarted, either a manual or schedule backup is usually successful.

While this restart is a workaround, I would prefer to find out if anyone else has had a similar issue and if someone has managed to find a permanent solution, as this is currently occurring at least once a week, and we have never had these types of issues with our old backup software.

More details of our Exchange environment:

• Exchange 2007 SP3
• 2 x Mailbox/CAS Servers in CCR Cluster (Installed on Windows Server 2003 R2 64-bit Enterprise Edition, Service Pack 2). Servers are physical
• 4 x Hub Transports  (Installed on Windows Server 2003 R2 64-bit Enterprise Edition, Service Pack 2). 2 x Servers are physical, and 2 are virtual.
• 2 x Public Folder server ( no issues with Backups for Public Folders, just mailbox).

• NetBackup Enterprise Server 7.1.0.3 (Installed on EMM/Master Server, Media Server and all Clients)
• Exchange Client installed on servers in CCR Cluster, policies configured to backup passive only
• Storage Group Backups broken up into 2 Groups.
• Group1 Full Backups run on a Thursday night, with Diff Inc's running every other day.
• Group2 Full Backups run on a Saturday night, with Diff Incs running every other day.
• GRT is configured for Backup Policies.

Any ideas or assistance for this would be greatly appreciated.

I currently have a call open with Symantec Support, but thought I would post up my issue as well to see if anyone else is aware of a fix to this issue.

Thanks in Advance,

Simon

[Marianne]

GRT is configured for Backup Policies.

Only supported with DataDomain as from NBU 7.5.

According to latest HCL:   http://www.symantec.com/docs/TECH76495     
GRT is supported with plug-in version 2.5 and NBU 7.5.
It does not mention DDOS version. Best to check with DD.

Also see: http://www.symantec.com/docs/TECH187356

Statement of support for Granular Restore Technology (GRT) for NetBackup with 3rd-party OpenStorage Secondary Storage Solutions

[SimonAnderson]

Hi Marianne,

Thanks for your response.

I dug a little deeper into the setup for our Exchange Backups, and as you're right regarding the Data Domain support for GRT, we are actually backing up our Exchange Backups to the DataDomains via CIFS shares which have been created on the DD's, not via the OST Plug-in.

Upgrading our NetBackup environment to 7.5 is on the cards, but not for a little while as we have only just completed our Implementation of 7.1.0.3.

Are there any known issues backing up Exchange 2007 via CIFS shares?

Regards,

Simon

[SimonAnderson]

An update.

My Full backups completed successfully.

The diff backup jobs kicked off last night as expected, but the parent jobs were just sitting there.

I did a little digging on the Exchange Server and found the following informational events in the App Event Log. There was one listed for each Storage Group that was being backed up:

=====

Event Type: Information
Event Source: MSExchangeRepl
Event Category: Exchange VSS Writer
Event ID: 2111
Date:  24/07/2012
Time:  10:03:23 PM
User:  N/A
Computer: ACPHOFEXCM01
Description:
The Microsoft Exchange Replication Service VSS writer (instance f0600a09-eabc-4c12-9385-421e916e5d2a) has successfully prepared for an incremental or differential backup of storage group 'Storage Group 33'. The following database is mounted, although it will not be backed up: Mailbox Database 33.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

=====

I have cancelled the jobs as they have been sitting there for at least 12 hours. After trying to re-run the backup, we are now getting status 130 errors.

[SimonAnderson]

I've done some more reading and found the following, which i feel related to my issue that I'm experiencing:

http://www.symantec.com/business/support/index?page=content&id=TECH61607

Although I'm not using Backup Exec to complete backups, the exact same thing is happening.

I'm not overly keen to run Backups on the Active Node, as that is one of the main reasons we have a passive node in our CCR Cluster (i.e. to perform backups).

Has this issue been resolved at all?