Server 2003, netbackup 7.0
Backing up a server 2008 R2 server
The folder that is being backed up is 28 MB, and is a robocopy of the "data" directory. I have a scheduled task that stops a service that has the files open. It then robocopies the directory into my Daily Backup folder. It then starts the service. This runs 30 minutes before the backup is due to start. I am using the /B switch which sets the backup bit with robocopy - so that only newer files are copied into the folder that is too be backed up by netbackup.
:: Stop the Services
NET STOP "Actuate 11 BIRT iServer"
timeout 60
SET _source=D:\Actuate\iServer\data
SET _dest=D:\Actuate\iServer\DailyBackup
SET _what=/COPYALL /B /SEC /MIR
:: /COPYALL :: COPY ALL file info
:: /B :: copy files in Backup mode
:: /SEC :: copy files with SECurity
:: /MIR :: MIRror a directory tree
SET _options=/R:0 /W:0 /LOG:D:\RWScripts\RoboCopyLog.txt /NFL /NDL
:: /R:n :: number of Retries
:: /W:n :: Wait time between retries
:: /LOG :: Output log file
:: /NFL :: No file logging
:: /NDL :: No dir logging
ROBOCOPY %_source% %_dest% %_what% %_options%
:: Start Services
NET START "Actuate 11 BIRT iServer"
There is a monthly(full), weekly(full) and daily (cumulative incremental) that runs on this server. The activity monitor always reports the YEllow man, that some files were in use and to examine the client logs. Which I have pasted below.
ACtivity Monitor Job:
18/12/2011 03:37:34 - estimated 0 Kbytes needed
18/12/2011 03:37:35 - started process bpbrm (6224)
18/12/2011 03:37:40 - connecting
18/12/2011 03:37:44 - connected; connect time: 00:00:04
18/12/2011 03:37:48 - mounting CLU245
18/12/2011 03:38:37 - mounted; mount time: 00:00:49
18/12/2011 03:38:40 - positioning CLU245 to file 7
18/12/2011 03:39:27 - positioned CLU245; position time: 00:00:47
18/12/2011 03:39:27 - begin writing
18/12/2011 03:39:42 - end writing; write time: 00:00:15
the requested operation was successfully completed(0)
Activity Monitor "-":
8/12/2011 03:39:59 - ended process 0 (8880)
Status 0
18/12/2011 03:39:59 - end Snapshot, End Notify Script; elapsed time: 00:00:00
Status 1
18/12/2011 03:39:59 - end Parent Job; elapsed time: 00:03:33
the requested operation was partially successful(1)
The job was successfully completed, but some files may have been
busy or unaccessible. See the problems report or the client's logs for more details.
This is from the bpbkar log.
03:37:44.929: [3120.4856] <4> ov_log::OVInit: INF - Starting log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\121811.LOG
03:37:44.929: [3120.4856] <4> ov_log::OVInit: GENERAL Log Level: 0
03:37:44.929: [3120.4856] <4> ov_log::OVInit: TCP Log Level: 0
03:37:44.929: [3120.4856] <4> ov_log::OVInit: INF - the log mutex: 448
BPBKAR NetBackup Backup/Archive 6.5GA [Jan 4 2010]
Copyright 1993 - 2007 VERITAS Software Corporation
All Rights Reserved.
03:37:44.929: [3120.4856] <2> WinMain: DAT - _pgmptr = 'C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe'
03:37:44.929: [3120.4856] <2> WinMain: DAT - lpCmdLine = '-r 1814400 -ru root -dt 0 -to 0 -clnt Actuate-Lon -class Actuate-Lon -sched Full -st FULL -bpstart_to 600 -bpend_to 600 -read_to 3600 -stream_count 1 -stream_number 1 -jobgrpid 18133 -blks_per_buffer 128 -tir -tir_plus -use_otm -fso -Z -b Actuate-Lon_1324179454 -kl 28 -WOFB_enabled -WOFB_fim 0 -WOFB_usage 0 -WOFB_error 0 -ct 13 -use_ofb '
03:37:44.929: [3120.4856] <2> date_debug: DAT - timezone: GMT Standard Time, offset=0, dst: GMT Daylight Time
03:37:44.929: [3120.4856] <2> date_debug: DAT - current time: 1324179464, 18/12/2011 03:37:44
03:37:44.929: [3120.4856] <2> date_debug: DAT - 01/01/94 UCT: 757382400, 01/01/1994 00:00:00
03:37:44.929: [3120.4856] <2> date_debug: DAT - 07/01/94 UCT: 773020800, 01/07/1994 00:00:00
03:37:44.929: [3120.4856] <2> WinMain: DAT - standard input handle = 432
03:37:44.929: [3120.4856] <2> WinMain: DAT - standard output handle = 320
03:37:44.929: [3120.4856] <2> WinMain: DAT - standard error handle = 484
03:37:46.054: [3120.4856] <4> tar_backup::V_SetupJobData: INF - dwJobData: ffffffff
03:37:46.054: [3120.4856] <4> tar_backup::V_SetupJobData: INF - dwJob: ffffffff
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - backup privileges enabled, previous = 0
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - restore privileges enabled, previous = 0
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - security privileges enabled, previous = 0
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - tcb privileges enabled, previous = 0
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - create token privileges enabled, previous = 0
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - user name: root
03:37:46.086: [3120.4856] <4> dos_backup::V_PreProcessing: INF - no access token: scheduled backup
03:37:46.086: [3120.4856] <2> ov_log::V_GlobalLog: ERR - ubsDetermineExchangeVersion():RegQueryValueEx() failed - 0x2.
03:37:46.086: [3120.4856] <2> ov_log::V_GlobalLog: INF - BEDS_Init() Enter InitFlags:0x0
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - BEDS_Init() BEDS debgging will be enabled - dwDebugLevel = 0.
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: C:
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: D:
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Terminal Services
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Windows Network
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Shadow?Copy?Components
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: System?State
03:37:46.117: [3120.4856] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Active Directory Application Mode
03:37:46.336: [3120.4856] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received
03:37:46.554: [3120.4856] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = SET SNAP_ID=Actuate-Lon_1324179386
03:37:46.554: [3120.4856] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = BACKUP D:\Actuate\iServer\DailyBackup USING \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy5\Actuate\iServer\DailyBackup OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_3420,FITYPE=MIRROR,MNTPOINT=D:\,FSTYPE=NTFS
03:37:46.554: [3120.4856] <2> tar_base::V_vTarMsgW: INF - File data will be compressed when appropriate
03:37:46.554: [3120.4996] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds
03:37:46.679: [3120.4856] <2> tar_backup_vxbsa::add: INF - called with 'SET SNAP_ID=Actuate-Lon_1324179386'
03:37:46.679: [3120.4856] <2> tar_backup_vxbsa::add: INF - called with 'BACKUP D:\Actuate\iServer\DailyBackup USING \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy5\Actuate\iServer\DailyBackup OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_3420,FITYPE=MIRROR,MNTPOINT=D:\,FSTYPE=NTFS'
03:37:46.679: [3120.4856] <4> V_Snapshot::V_Snapshot_AddMappings: INF - Volume Snapshot Mapping: \\?\Volume{34db30ec-d562-11e0-af33-005056970054}\ --> GLOBALROOT\Device\HarddiskVolumeShadowCopy5
03:37:46.695: [3120.4856] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'D:\Actuate\iServer\DailyBackup' --> 10020002
03:37:47.742: [3120.4856] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'
03:37:47.742: [3120.4856] <4> tar_backup_tfi::UpdateExcludeListWithVHD: INF - UpdateExludeListWithVHD begin
03:37:47.929: [3120.4856] <2> ov_log::V_GlobalLogEx: INF - file_access (constructor): 0 non-NTFS volumes
03:39:29.275: [3120.4856] <2> tar_base::backup_finish: TAR - backup: 1092 files
03:39:29.275: [3120.4856] <2> tar_base::backup_finish: TAR - backup: compressed data: 10200305 bytes
03:39:29.275: [3120.4856] <2> tar_base::backup_finish: TAR - backup: uncompressed data: 0 bytes
03:39:29.275: [3120.4856] <2> tar_base::backup_finish: TAR - backup: file data: 26429822 bytes
03:39:29.275: [3120.4856] <2> tar_base::backup_finish: TAR - backup: image data: 13426688 bytes
03:39:29.275: [3120.4856] <2> tar_base::backup_finish: TAR - backup: elapsed time: 102 secs 131634 bps
03:39:29.275: [3120.4856] <4> tar_backup::backup_done_state: INF - number of file directives not found: 0
03:39:29.275: [3120.4856] <4> tar_backup::backup_done_state: INF - number of file directives found: 1
03:39:29.275: [3120.4996] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0)
03:39:29.275: [3120.4856] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0)
03:39:29.275: [3120.4856] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 0: the requested operation was successfully completed
03:39:40.275: [3120.4856] <4> dos_backup::tfs_reset: INF - Snapshot deletion start
03:39:40.275: [3120.4856] <4> OVStopCmd: INF - EXIT - status = 0
03:39:40.275: [3120.4856] <2> tar_base::V_Close: closing...
03:39:40.275: [3120.4856] <4> dos_backup::tfs_reset: INF - Snapshot deletion start
03:39:40.275: [3120.4856] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): enter - InitFlags:0x00000101
03:39:40.275: [3120.4856] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): ubs specifics: 0x001d0000
03:39:41.275: [3120.4856] <4> OVShutdown: INF - Finished process
03:39:41.275: [3120.4856] <4> WinMain: INF - Exiting C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe
03:39:43.275: [3120.4856] <4> ov_log::OVClose: INF - Closing log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\121811.LOG
I do not see anything that points to these files being in use?
Where would these be?
This folder is about to jump to 20 GB so I need to get this right before it goes live.
Could it be a problem with the /B switch in robocopy? Or are there really files in use?