Netbackup 6.5.4 Backups Fail

[mrtba]

I keep getting this error on a domain controller of ours. 


Faulting application bpbkar32.exe, version 6.5.2009.430, faulting module MSVCR71.dll, version 7.10.3052.4, fault address 0x00010440.

The backup fails, with this in the activity monitor

11/23/2009 10:31:38 PM - Error bptm(pid=1900) socket operation failed - 10054 (at child.c.1294)     
11/23/2009 10:31:38 PM - Error bptm(pid=1900) unable to perform read from client socket, connection may have been broken


Any ideas?


What I have done in the past is restart the netbackup client service on the client, but it's getting pretty annoying....  It's happend a few times already, then our backup doesn't run for the night.


Thanks in advance.

[Marianne]

Client O/S version?
Do you have bpbkar and bpfis logs on the client?
Any evidence in the logs of snapshot failures?
Is this client using VSS or VSP for snapshots? If you have not explicitly specified VSS the default is VSP.
You might also want to have a look at this TN: seer.entsupport.symantec.com/docs/327105.htm

[mrtba]

Marianne,

I apoligize as I have been really busy, and I haven't had that errror out on my again.  As soon as I get some time I will post the answers to your questions.




Thanks,

Tim

[mrtba]

OS= Windows 2003 Server Sp2 (Domain Controller)

I'm not sure about those logs.  I see some logs but they don't seem to tell me anything.  The name of the log is 51216-200-22321815-090803-0000000000.log. 

I'm pretty sure its using VSP, although I'm not sure becuase I'm not sure if we rebooted the server or not after we installed the  client.  So it may be using VSS.  We plan on rebooting the server, but we have been under water recently.  

[mrtba]

I noticed the error now I'm several on my servers.  It's not really affecting anything major.  We plan on rebooting some of the servers tonight, some of them can never really be rebooted....  It's qutie comical that the servers with the errors are the most heavily used servers.... 


All the servers are the same OS Win2k3 SP2

[Tim_Hansen]

do you have any hung bpbkar processes on the server?

[mrtba]

No I don't believe so, just the application error above.  In the activity monitor I see this error alot


11/30/2009 8:43:37 PM - Warning bpbrm(pid=12588) from client : WRN - can't open file: C:\WINDOWS\system32\config\AppEvent.Evt (WIN32 3: The system cannot find the path specified. )
11/30/2009 8:43:37 PM - Warning bpbrm(pid=12588) from client : WRN - can't open file: C:\WINDOWS\system32\config\SecEvent.Evt (WIN32 3: The system cannot find the path specified. )
11/30/2009 8:43:37 PM - Warning bpbrm(pid=12588) from client : WRN - can't open file: C:\WINDOWS\system32\config\SysEvent.Evt (WIN32 3: The system cannot find the path specified. )

This error on some

11/30/2009 9:05:23 PM - Warning bpbrm(pid=13636) from client : WRN - Removable Storage Management: unable to export database (WIN32 21: The device is not ready. )
11/30/2009 9:05:39 PM - Error bpbrm(pid=13636) from client : ERR - failure reading file: C:\plntware\NetLic\Log\netlic.log (WIN32 13: The data is invalid. )

And this error on some.  These are 64bit XP machines...

11/30/2009 8:01:56 PM - Warning bpbrm(pid=12028) from client : WRN - can't open file: System State:\Internet Information Services\IISMETABASE (WIN32 -536832991: Unknown error)
11/30/2009 8:01:56 PM - Error bpbrm(pid=12028) from client : ERR - Error encountered while attempting to get additional files for System State:\
11/30/2009 8:06:55 PM - Warning bpbrm(pid=12028) from client : WRN - Removable Storage Management: unable to export database (WIN32 21: The device is not ready. )

[Marianne]

The logs that you refer to are the unified logs on the master sever.
You enable logging on the client by creating the directories under ...\veritas\netbackup\logs.
Windows Open File backup method is specified by adding the client name in Host Properties > Master Server > Client Attributes. Once the name is added, you can select snapshot method in the Windows Open File Backup tab. If you have never done this, the default is VSP. You should specify VSS for W2003 and W2008 clients.

[mrtba]

Do I need to restart anything to switch from VSP to VSS?  Can I restart just the service or do I need to restart the whole server?

[Andy_Welburn]

then you're good to go. No need to restart following these changes to client attributes.

[J_H_Is_gone]

I know I got this from a tech note - but my notes don't say which one.
I have used this.

If you get errors trying to backup “Removable Storage Management” you can exclude:

Windows 2000: <system drive>:\Winnt\system32\ntmsdata

Windows 2003 <system drive>:\WINDOWS\system32\NtmsData

[mrtba]

Does Anyone have any recommendations for Windows XP 64bit as far as Snapshot providers.  Should I use VSS or VSP?  I have tried both and the backups fail with ither one.  

[Manoj_Siricilla]

Here is an article recommending VSS over VSP.

http://seer.entsupport.symantec.com/docs/292787.htm


Are you still having problems with backups?

If you want to switch from VSP to VSS on a windows 2003, do the following.

C:\> vssadmin list providers

If you see veritas listed in the output, unregister it by running the command "vxvssprovider /unregserver"

Now, next time when you run backup it should use VSS by default.

[Alzoo]

I too have the same problem with Faulting application bpbkar32.exe, version 6.5.2009.430 on a windows 2008 64bit

Here is the log from
bpfis
00:00:32.622 [4212.3156] <2> logparams: bpfis query -id waxpstse01ancy.fr.sopra_1260831670
00:00:32.673 [4212.3156] <4> bpfis: INF - BACKUP START 4212
00:00:32.675 [4212.3156] <32> fis_rebuild_from_db: cannot open C:\Program Files (x86)\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.waxpstse01ancy.fr.sopra_1260831670.0
00:00:32.675 [4212.3156] <4> bpfis: INF - EXIT STATUS 12: file open failed
00:22:44.690 [4604.3020] <2> logparams: bpfis query -id waxpstse01ancy.fr.sopra_1260831670
00:22:44.835 [4604.3020] <4> bpfis: INF - BACKUP START 4604
00:22:44.860 [4604.3020] <32> fis_rebuild_from_db: cannot open C:\Program Files (x86)\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.waxpstse01ancy.fr.sopra_1260831670.0
00:22:44.860 [4604.3020] <4> bpfis: INF - EXIT STATUS 12: file open failed

bpbkar
0:00:31.299: [1992.3896] <4> ov_log::OVInit: INF - Starting log file: C:\Program Files (x86)\Veritas\NetBackup\logs\BPBKAR\121509.LOG

00:00:31.299: [1992.3896] <4> ov_log::OVInit: GENERAL Log Level: 0
00:00:31.299: [1992.3896] <4> ov_log::OVInit: TCP Log Level: 0
00:00:31.299: [1992.3896] <4> ov_log::OVInit: INF - the log mutex: 244
BPBKAR  NetBackup Backup/Archive  6.5GA  [May  1 2009]
Copyright 1993 - 2007 VERITAS Software Corporation
All Rights Reserved.

00:00:31.300: [1992.3896] <2> WinMain: DAT - _pgmptr = 'C:\Program Files (x86)\Veritas\NetBackup\bin\bpbkar32.exe'
00:00:31.300: [1992.3896] <2> WinMain: DAT - lpCmdLine = '-r 1814400 -ru root -dt 691492 -to 0 -clnt waxpstse01.ancy.fr.sopra -class FR-ANCY-PL-MSWINDOWS -sched DIFF -st INCR -bpstart_to 900 -bpend_to 900 -read_to 900 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -b waxpstse01.ancy.fr.sopra_1260831670 -kl 28 -WOFB_enabled -WOFB_fim 0 -WOFB_usage 0 -WOFB_error 0 -ct 13 -use_ofb '
00:00:31.301: [1992.3896] <2> date_debug: DAT - timezone: Romance Standard Time, offset=-3600, dst: Romance Daylight Time
00:00:31.301: [1992.3896] <2> date_debug: DAT - current time: 1260831631, 15/12/2009 00:00:31
00:00:31.301: [1992.3896] <2> date_debug: DAT - 01/01/94 UCT:  757382400, 01/01/1994 01:00:00
00:00:31.301: [1992.3896] <2> date_debug: DAT - 07/01/94 UCT:  773020800, 01/07/1994 01:00:00
00:00:31.301: [1992.3896] <2> WinMain: DAT - standard input handle = 476
00:00:31.301: [1992.3896] <2> WinMain: DAT - standard output handle = 144
00:00:31.301: [1992.3896] <2> WinMain: DAT - standard error handle = 280
00:00:31.492: [1992.3896] <4> tar_backup::V_SetupJobData: INF - dwJobData: ffffffff
00:00:31.492: [1992.3896] <4> tar_backup::V_SetupJobData: INF -     dwJob: ffffffff
00:00:31.504: [1992.3896] <4> dos_backup::V_PreProcessing: INF - backup privileges enabled, previous = 0
00:00:31.504: [1992.3896] <4> dos_backup::V_PreProcessing: INF - restore privileges enabled, previous = 0
00:00:31.504: [1992.3896] <4> dos_backup::V_PreProcessing: INF - security privileges enabled, previous = 0
00:00:31.504: [1992.3896] <4> dos_backup::V_PreProcessing: INF - tcb privileges enabled, previous = 0
00:00:31.505: [1992.3896] <4> dos_backup::V_PreProcessing: INF - create token privileges enabled, previous = 0
00:00:31.505: [1992.3896] <4> dos_backup::V_PreProcessing: INF - user name: root
00:00:31.505: [1992.3896] <4> dos_backup::V_PreProcessing: INF - no access token: scheduled backup
00:00:31.513: [1992.3896] <2> ov_log::V_GlobalLog: INF - BEDS_Init() Enter InitFlags:0x0
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: C:
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: D:
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Z:
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Terminal Services
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Windows Network
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Shadow?Copy?Components
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: System?State
00:00:32.410: [1992.3896] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Active Directory Application Mode
00:00:32.441: [1992.3896] <2> tar_backupt_tfi::create: TAR - Incremental backup using the archive bit
00:00:32.443: [1992.3896] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received
00:00:32.443: [1992.3896] <4> tar_backup_cpr::start: INF - checkpoint thread started
00:00:32.443: [1992.3896] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = ALL_LOCAL_DRIVES
00:00:32.443: [1992.3276] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds
00:00:32.504: [1992.3896] <4> V_Snapshot::V_Snapshot_Query: INF - Attempting to query volume snapshots: bpfis query -id waxpstse01.ancy.fr.sopra_1260831670
00:00:33.572: [1992.3896] <4> V_Snapshot::V_Snapshot_ParseBpfisOutput: INF - Snapshot creation, FIS_ID: waxpstse01.ancy.fr.sopra_1260831670
00:00:33.572: [1992.3896] <2> tar_backup_vxbsa::add: INF - called with '/'
00:00:33.572: [1992.3896] <4> dos_backup::V_VerifyFileSystem: INF - Added: C:\
00:00:33.572: [1992.3896] <4> dos_backup::V_VerifyFileSystem: INF - Added: D:\
00:00:33.572: [1992.3896] <4> dos_backup::V_VerifyFileSystem: INF - Added: Z:\
00:00:33.572: [1992.3896] <4> dos_backup::V_VerifyFileSystem: INF - Added: Shadow Copy Components:\
00:00:33.572: [1992.3896] <4> dos_backup::V_VerifyFileSystem: INF - Added: System State:\
00:00:42.170: [1992.3896] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'System State:\' --> 1002002d
00:00:42.171: [1992.3896] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '_BACKUP_SPECIAL_OBJECTS AFTER System State:' --> 1002002d
00:00:42.171: [1992.3896] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'D:\' --> 10020002
00:00:42.171: [1992.3896] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'Z:\' --> 10020002
00:00:43.681: [1992.3896] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'Shadow Copy Components:\' --> 10020027
00:00:43.681: [1992.3896] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'C:\' --> 10020002
00:00:45.036: [1992.3896] <4> VssSnapshot::V_VssSetMetadata(): INF - Unable to locate DFSR metadata
00:00:45.743: [1992.3896] <4> dos_backup::V_InitializeShadowCopy: INF - ============================================
00:00:45.743: [1992.3896] <4> dos_backup::V_InitializeShadowCopy: INF - ShadowCopy PrePost: Begin
00:00:47.935: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'C:' added to VSS Volume Set
00:00:47.940: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:00:47.940: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:00:47.949: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume
00:00:47.951: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'D:' added to VSS Volume Set
00:00:47.952: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:00:47.952: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "D:\"
00:00:47.960: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume
00:00:53.099: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - VSS Volume Set snapped
00:00:53.100: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks
00:00:53.103: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:00:53.103: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:00:53.111: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - Too large association limit being set to the maximum
00:00:53.111: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - attempting to set association free space to 1048576000
00:00:53.115: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - Association limit changed successfully
00:00:53.115: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:00:53.120: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:00:53.120: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "D:\"
00:00:53.130: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - Too large association limit being set to the maximum
00:00:53.130: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - attempting to set association free space to 1048576000
00:00:53.133: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - Association limit changed successfully
00:00:53.134: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:00:53.134: [1992.3896] <4> dos_backup::V_InitializeShadowCopy: INF - ShadowCopy PrePost: End
00:00:53.134: [1992.3896] <4> dos_backup::V_InitializeShadowCopy: INF - ============================================
00:00:53.135: [1992.3896] <4> VssSnapshot::V_VssSetMetadata(): INF - Unable to locate DFSR metadata
00:01:01.565: [1992.3896] <4> dos_backup::tfs_scanstart: INF - Backup Special Objects request AFTER System State:
00:01:02.700: [1992.3896] <4> dos_backup::tfs_getinfo: INF - current object (System State:) is a parent of previous (object (System State:\COM+ Class Registration Database\COM+ REGDB)
00:01:03.272: [1992.3896] <4> dos_backup::tfs_findfirst: WRN - unable to find first file: 'System State:\'
00:01:03.279: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'C:' added to VSS Volume Set
00:01:03.281: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:01:03.281: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:01:03.289: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:01:03.289: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:01:03.292: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'c:' added to VSS Volume Set
00:01:03.293: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:01:03.293: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "c:\"
00:01:03.302: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:01:03.302: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:01:05.329: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - VSS Volume Set snapped
00:01:05.330: [1992.3896] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks
00:01:05.333: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:01:05.333: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:01:05.341: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:01:05.342: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:01:05.345: [1992.3896] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:01:05.345: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "c:\"
00:01:05.354: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:01:05.354: [1992.3896] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:01:05.401: [1992.3896] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files (x86)\Veritas\\NetBackup\Temp'
00:01:06.861: [1992.3896] <4> dos_backup::tfs_include: INF - folder (System State:) has been created recently (since 06/12/2009 22:55:40).  It will be backed up in full.
00:01:07.219: [1992.3896] <2> ov_log::V_GlobalLogEx: INF - beds_ss_access::V_OpenForRead(): FS_OpenObj() Successful.
00:01:08.452: [1992.3896] <2> ov_log::V_GlobalLogEx: INF - beds_ss_access::V_OpenForRead(): FS_OpenObj() Successful.

00:22:43.786: [3620.3232] <4> ov_log::OVInit: INF - Starting log file: C:\Program Files (x86)\Veritas\NetBackup\logs\BPBKAR\121509.LOG

00:22:43.786: [3620.3232] <4> ov_log::OVInit: GENERAL Log Level: 0
00:22:43.786: [3620.3232] <4> ov_log::OVInit: TCP Log Level: 0
00:22:43.786: [3620.3232] <4> ov_log::OVInit: INF - the log mutex: 244
BPBKAR  NetBackup Backup/Archive  6.5GA  [May  1 2009]
Copyright 1993 - 2007 VERITAS Software Corporation
All Rights Reserved.

00:22:43.787: [3620.3232] <2> WinMain: DAT - _pgmptr = 'C:\Program Files (x86)\Veritas\NetBackup\bin\bpbkar32.exe'
00:22:43.787: [3620.3232] <2> WinMain: DAT - lpCmdLine = '-r 1814400 -ru root -dt 692825 -to 0 -clnt waxpstse01.ancy.fr.sopra -class FR-ANCY-PL-MSWINDOWS -sched DIFF -st INCR -bpstart_to 900 -bpend_to 900 -read_to 900 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -b waxpstse01.ancy.fr.sopra_1260831670 -kl 28 -WOFB_enabled -WOFB_fim 0 -WOFB_usage 0 -WOFB_error 0 -ct 13 -use_ofb '
00:22:43.788: [3620.3232] <2> date_debug: DAT - timezone: Romance Standard Time, offset=-3600, dst: Romance Daylight Time
00:22:43.788: [3620.3232] <2> date_debug: DAT - current time: 1260832963, 15/12/2009 00:22:43
00:22:43.788: [3620.3232] <2> date_debug: DAT - 01/01/94 UCT:  757382400, 01/01/1994 01:00:00
00:22:43.788: [3620.3232] <2> date_debug: DAT - 07/01/94 UCT:  773020800, 01/07/1994 01:00:00
00:22:43.788: [3620.3232] <2> WinMain: DAT - standard input handle = 476
00:22:43.788: [3620.3232] <2> WinMain: DAT - standard output handle = 144
00:22:43.788: [3620.3232] <2> WinMain: DAT - standard error handle = 280
00:22:43.893: [3620.3232] <4> tar_backup::V_SetupJobData: INF - dwJobData: ffffffff
00:22:43.893: [3620.3232] <4> tar_backup::V_SetupJobData: INF -     dwJob: ffffffff
00:22:43.920: [3620.3232] <4> dos_backup::V_PreProcessing: INF - backup privileges enabled, previous = 0
00:22:43.921: [3620.3232] <4> dos_backup::V_PreProcessing: INF - restore privileges enabled, previous = 0
00:22:43.921: [3620.3232] <4> dos_backup::V_PreProcessing: INF - security privileges enabled, previous = 0
00:22:43.921: [3620.3232] <4> dos_backup::V_PreProcessing: INF - tcb privileges enabled, previous = 0
00:22:43.921: [3620.3232] <4> dos_backup::V_PreProcessing: INF - create token privileges enabled, previous = 0
00:22:43.921: [3620.3232] <4> dos_backup::V_PreProcessing: INF - user name: root
00:22:43.921: [3620.3232] <4> dos_backup::V_PreProcessing: INF - no access token: scheduled backup
00:22:43.937: [3620.3232] <2> ov_log::V_GlobalLog: INF - BEDS_Init() Enter InitFlags:0x0
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: C:
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: D:
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Z:
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Terminal Services
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Windows Network
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Shadow?Copy?Components
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: System?State
00:22:44.142: [3620.3232] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Active Directory Application Mode
00:22:44.157: [3620.3232] <2> tar_backupt_tfi::create: TAR - Incremental backup using the archive bit
00:22:44.158: [3620.3232] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received
00:22:44.158: [3620.3232] <4> tar_backup_cpr::start: INF - checkpoint thread started
00:22:44.158: [3620.3232] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = ALL_LOCAL_DRIVES
00:22:44.159: [3620.2560] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds
00:22:44.591: [3620.3232] <4> V_Snapshot::V_Snapshot_Query: INF - Attempting to query volume snapshots: bpfis query -id waxpstse01.ancy.fr.sopra_1260831670
00:22:45.606: [3620.3232] <4> V_Snapshot::V_Snapshot_ParseBpfisOutput: INF - Snapshot creation, FIS_ID: waxpstse01.ancy.fr.sopra_1260831670
00:22:45.606: [3620.3232] <2> tar_backup_vxbsa::add: INF - called with '/'
00:22:45.606: [3620.3232] <4> dos_backup::V_VerifyFileSystem: INF - Added: C:\
00:22:45.606: [3620.3232] <4> dos_backup::V_VerifyFileSystem: INF - Added: D:\
00:22:45.606: [3620.3232] <4> dos_backup::V_VerifyFileSystem: INF - Added: Z:\
00:22:45.606: [3620.3232] <4> dos_backup::V_VerifyFileSystem: INF - Added: Shadow Copy Components:\
00:22:45.606: [3620.3232] <4> dos_backup::V_VerifyFileSystem: INF - Added: System State:\
00:22:49.603: [3620.3232] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'System State:\' --> 1002002d
00:22:49.603: [3620.3232] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '_BACKUP_SPECIAL_OBJECTS AFTER System State:' --> 1002002d
00:22:49.603: [3620.3232] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'D:\' --> 10020002
00:22:49.603: [3620.3232] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'Z:\' --> 10020002
00:22:51.056: [3620.3232] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'Shadow Copy Components:\' --> 10020027
00:22:51.056: [3620.3232] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'C:\' --> 10020002
00:22:52.387: [3620.3232] <4> VssSnapshot::V_VssSetMetadata(): INF - Unable to locate DFSR metadata
00:22:53.069: [3620.3232] <4> dos_backup::V_InitializeShadowCopy: INF - ============================================
00:22:53.069: [3620.3232] <4> dos_backup::V_InitializeShadowCopy: INF - ShadowCopy PrePost: Begin
00:22:55.178: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'C:' added to VSS Volume Set
00:22:55.181: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:22:55.181: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:22:55.190: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:22:55.190: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:22:55.192: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'D:' added to VSS Volume Set
00:22:55.193: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:22:55.193: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "D:\"
00:22:55.202: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:22:55.202: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:22:58.642: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - VSS Volume Set snapped
00:22:58.642: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks
00:22:58.645: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:22:58.645: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:22:58.653: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:22:58.654: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:22:58.657: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:22:58.657: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "D:\"
00:22:58.665: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:22:58.665: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:22:58.665: [3620.3232] <4> dos_backup::V_InitializeShadowCopy: INF - ShadowCopy PrePost: End
00:22:58.665: [3620.3232] <4> dos_backup::V_InitializeShadowCopy: INF - ============================================
00:22:58.665: [3620.3232] <4> VssSnapshot::V_VssSetMetadata(): INF - Unable to locate DFSR metadata
00:23:07.004: [3620.3232] <4> dos_backup::tfs_scanstart: INF - Backup Special Objects request AFTER System State:
00:23:08.128: [3620.3232] <4> dos_backup::tfs_getinfo: INF - current object (System State:) is a parent of previous (object (System State:\Registry\Registry)
00:23:08.691: [3620.3232] <4> dos_backup::tfs_findfirst: WRN - unable to find first file: 'System State:\'
00:23:08.698: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'C:' added to VSS Volume Set
00:23:08.700: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:23:08.700: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:23:08.708: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:23:08.708: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:23:08.711: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'c:' added to VSS Volume Set
00:23:08.712: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:23:08.712: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "c:\"
00:23:08.721: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:23:08.721: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:23:12.507: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - VSS Volume Set snapped
00:23:12.507: [3620.3232] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks
00:23:12.511: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:23:12.511: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\"
00:23:12.520: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:23:12.520: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:23:12.524: [3620.3232] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations
00:23:12.524: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "c:\"
00:23:12.533: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - ingoring association which is not unbounded
00:23:12.533: [3620.3232] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - enumeration finished, vemo->Next returned S_FALSE
00:23:12.535: [3620.3232] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files (x86)\Veritas\\NetBackup\Temp'
00:23:13.974: [3620.3232] <4> dos_backup::tfs_include: INF - folder (System State:) has been created recently (since 06/12/2009 22:55:39).  It will be backed up in full.
00:23:14.310: [3620.3232] <2> ov_log::V_GlobalLogEx: INF - beds_ss_access::V_OpenForRead(): FS_OpenObj() Successful.
00:23:15.458: [3620.3232] <2> ov_log::V_GlobalLogEx: INF - beds_ss_access::V_OpenForRead(): FS_OpenObj() Successful.


For the client attributes of the master server
the settings for open file backup is enabled, we use VSS, the snapshot usage is individual and the error control is disbale & continue.  I noticed my server waxpstse01.ancy.fr.sopra was not in the list of windows servers, I've added it in and will check if the backup is successful overnight.