β07-30-2012 07:54 AM
Hi everyone,
I have a strange problem and I hope that anyone can help me.
I use NBU 7.5.0.3 for my backups.
The problem regards the bck of a phisical server with nbu policy type "MS-windos" with backup of "all_local_drives" and so also shadow copy components.
The client is a win srv 2008 R2 Standard and I backup it every week only the saturday.
Not all W.E. but sometimes, backup of Shadow copy components fail wih retur code 69. From job details I can find only general info about the error:
[...]
28/07/2012 05:38:25 - end Snapshot, Stop On Error; elapsed time: 00:00:00
28/07/2012 05:38:25 - begin Snapshot, Delete Snapshot
28/07/2012 05:38:27 - started process bpbrm (4472)
28/07/2012 05:38:29 - Info bpbrm(pid=4472) Starting delete snapshot processing
28/07/2012 05:38:29 - Info bpfis(pid=0) Snapshot will not be deleted
Status 69
28/07/2012 05:38:32 - Info bpfis(pid=5256) Backup started
28/07/2012 05:38:35 - end writing
Status 0
28/07/2012 05:38:35 - end Snapshot, Delete Snapshot; elapsed time: 00:00:10
28/07/2012 05:38:35 - begin Snapshot, End Notify Script
28/07/2012 05:38:35 - Info RUNCMD(pid=2344) started
28/07/2012 05:38:35 - Info RUNCMD(pid=2344) exiting with status: 0
Status 0
28/07/2012 05:38:35 - end Snapshot, End Notify Script; elapsed time: 00:00:00
Status 69
28/07/2012 05:38:35 - end operation
invalid filelist specification(69)
and the other log releated to the shadow copy component is:
28/07/2012 04:00:54 - Info nbjm(pid=5740) starting backup job (jobid=146707) for client altair, policy altair-all_PD, schedule Full_sporadico
28/07/2012 04:00:54 - estimated 0 Kbytes needed
28/07/2012 04:00:54 - Info nbjm(pid=5740) started backup (backupid=altair_1343440854) job for client altair, policy altair-all_PD, schedule Full_sporadico on storage unit arcadia-DP-deduplica
28/07/2012 04:00:56 - started process bpbrm (2972)
28/07/2012 04:01:06 - Info bpbrm(pid=2972) altair is the host to backup data from
28/07/2012 04:01:06 - Info bpbrm(pid=2972) reading file list from client
28/07/2012 04:01:07 - connecting
28/07/2012 04:01:09 - connected; connect time: 00:00:02
28/07/2012 04:01:10 - Info bpbrm(pid=2972) starting bpbkar32 on client
28/07/2012 04:01:14 - Info bpbkar32(pid=3344) Backup started
28/07/2012 04:01:14 - Info bptm(pid=2112) start
28/07/2012 04:01:15 - Info bptm(pid=2112) using 262144 data buffer size
28/07/2012 04:01:15 - Info bptm(pid=2112) setting receive network buffer to 262144 bytes
28/07/2012 04:01:15 - Info bptm(pid=2112) using 128 data buffers
28/07/2012 04:01:15 - Info arcadia(pid=2112) Using OpenStorage client direct to backup from client altair to arcadia
28/07/2012 04:01:19 - begin writing
28/07/2012 04:34:54 - Error bpbrm(pid=2972) from client altair: ERR - Unable to backup System State or Shadow Copy. Please check the state of VSS and associated Writers.ERR - Unable to backup System State or Shadow Copy. Please check the state of VSS and associated Writers.INF - Estimate:-1 -1
28/07/2012 04:34:54 - Warning bpbrm(pid=2972) from client altair: WRN - can't open object: Shadow Copy Components: (BEDS 0xE000FECB: A failure occurred accessing the backup component document.)
28/07/2012 04:34:54 - Error bpbrm(pid=2972) from client altair: ERR - Unable to backup System State or Shadow Copy. Please check the state of VSS and associated Writers.JBD - bpbkar waited 0 times for empty buffer, delayed 0 times.
28/07/2012 04:39:13 - Info arcadia(pid=2112) StorageServer=PureDisk:arcadia; Report=PDDO Stats for (arcadia): scanned: 1 KB, CR sent: 0 KB, CR sent over FC: 0 KB, dedup: 100.0%, cache hits: 0 (0.0%)
28/07/2012 04:39:19 - Error bpbrm(pid=2972) could not send server status message
28/07/2012 04:39:21 - end writing; write time: 00:38:02
invalid filelist specification(69)
I have increased logging from the client and from bpbkar I can see:
[...]
04:34:53.442: [3344.3620] <2> ov_log::V_GlobalLog: INF - Status VSS_E_BAD_STATE (0x80042301) getting writer metadata count in SHADOW::GenerateLogicalBackupDirectoryTree
04:34:53.442: [3344.3620] <2> ov_log::V_GlobalLog: INF -
04:34:53.442: [3344.3620] <2> ov_log::V_GlobalLog: INF - ****** Tree - "SHADOW::LogicalDirectoryTree" ******
04:34:53.442: [3344.3620] <2> ov_log::V_GlobalLog: INF - -----------------------------------------------------------------------------------
04:34:53.442: [3344.3620] <2> ov_log::V_GlobalLog: INF -
04:34:53.458: [3344.3620] <2> ov_log::V_GlobalLog: INF - Status FS_WRITER_METADATA_FAILURE (0xE000FEC9) generating logical directory tree when attaching to Shadow?Copy?Components Dle
04:34:53.458: [3344.3620] <2> ov_log::V_GlobalLog: INF - AD:Status FS_WRITER_METADATA_FAILURE (0xE000FEC9) attaching 'Shadow?Copy?Components' in SystemState::InitializeShadowCopy:368
04:34:53.458: [3344.3620] <2> ov_log::V_GlobalLog: INF - AD:Status FS_WRITER_METADATA_FAILURE (0xE000FEC9) initializing Shadow Copy in SystemState::AttachToDLE:710
04:34:53.473: [3344.3620] <2> ov_log::V_GlobalLog: ERR - BEDS_AttachToDLE():FS_AttachToDLE() DeviceName:'System?State' BackupReason:0x400 Failed! (0xE000FEC9:A failure occurred accessing the Writer metadata.
)
04:34:53.473: [3344.3620] <2> ov_log::V_GlobalLog: INF - v_beds::V_FindFirst() EXIT Name: bRC:false LastError:0xFFFFFEC9:0xa000fec9 (2684419785)
04:34:53.473: [3344.3620] <4> tar_base::V_vTarMsgW: INF - tar message received from dos_backup::tfs_startdir
04:34:53.473: [3344.3620] <2> tar_base::V_vTarMsgW: ERR - Unable to backup System State or Shadow Copy. Please check the state of VSS and associated Writers.04:34:53.473: [3344.3620] <4> dos_backup::tfs_scanstart: INF - Backup Special Objects request AFTER System State:
04:34:53.473: [3344.3620] <4> dos_backup::tfs_scanstart: INF - starting scan for file directive:<_BACKUP_SPECIAL_OBJECTS AFTER System State:>
04:34:53.473: [3344.3620] <4> dos_backup::tfs_scanstart: INF - starting scan using name:<System State:\>
04:34:53.473: [3344.3620] <4> dos_backup::tfs_scanstart: INF - in 'pre-backup' mode
04:34:53.473: [3344.3620] <4> dos_backup::tfs_startdir: INF - volume guid:<>
04:34:53.473: [3344.3620] <4> dos_backup::tfs_startdir: INF - volume mount point:<>
04:34:53.473: [3344.3620] <2> ov_log::V_GlobalLog: INF - v_beds::V_FindFirst() ENTER Name:System State: Mode:4
04:34:53.473: [3344.3620] <2> ov_log::V_GlobalLog: DBG - v_beds::V_FindFirst() Device:System State: Obj: Pattern:(null)
[...]
I found a lot of thech notes:
Solved! Go to Solution.
β07-30-2012 08:41 AM
here is the first one i have found: http://support.microsoft.com/kb/975688
Really need to look in the System and Application event logs after a failure to see what it is reporting
In general you will need a reboot to get them stable again anyway
β07-30-2012 08:11 AM
Have you done as suggested in Job details?
Please check the state of VSS and associated Writers.
This should be done at the time when the backup is failing - it won't help to do this afterwards as the problem is intermittent.
β07-30-2012 08:17 AM
As well as Mariannes excllent advice it is always worth checking for Windows Update / Hotfixes - there were many for Windows 2003 and no doubt 2008 will have its share of issues as well.
Is it a "real" server or virtual? VSS is tied into VMWare tools if virtual
Hope this helps
β07-30-2012 08:27 AM
The server ir real, phisical and I tried to find updates for win srv 2008 ...
β07-30-2012 08:41 AM
here is the first one i have found: http://support.microsoft.com/kb/975688
Really need to look in the System and Application event logs after a failure to see what it is reporting
In general you will need a reboot to get them stable again anyway
β07-31-2012 03:28 AM
Thanks a lot for this article.
Now I'll check if will solve my issue
Christian
β11-15-2012 04:18 PM
Any updates? I am having the same issue on a file server using shadow copy components.
I plan to install a hotfix this weekend.
β04-15-2013 10:07 AM
I have run into the same problem but with an error code of 50. The problem was always that Shadow Copy was still running from the last time NBU ran. If the Virtual Disk Service is disabled it happens all the time, but it also happens randomly for certain servers (have not found out why yet). The fix is to stop the Shadow Copy service (make sure it is set to manually start), and rerun the backup.
β04-16-2013 03:22 AM
I solved the problem upgrading NBU, disabling DFS and moving the client on a network with better performances.