Video Screencast Help

Error during backup of shadow copy components

Created: 30 Jul 2012 | 8 comments

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:

 
[...]
 
but nothing of them is usefull for me.
 
My client is a file server and during the backup anyone works.
Any software in installed from the server.
Also config of volume shadow copy in according with Microsoft.
Not all W.E. the backup fails.
I don't have any error messages releated of shadow copy components from win events.
 
Does anyone help me for this issue?
 
Thanks a lot
 
Christian

Comments 8 CommentsJump to latest comment

Marianne's picture

Have you done as suggested in Job details?

Please check the state of VSS and associated Writers.

 

vssadmin list writers
vssadmin list providers

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. 

 

Supporting Storage Foundation and VCS on Unix and Windows as well as NetBackup on Unix and Windows
Handy NBU Links

Mark_Solutions's picture

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

Authorised Symantec Consultant

Don't forget to "Mark as Solution" if someones advice has solved your issue - and please bring back the Thumbs Up!!.

bonovox73's picture

The server ir real, phisical and I tried to find updates for win srv 2008 ...

Mark_Solutions's picture

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

Authorised Symantec Consultant

Don't forget to "Mark as Solution" if someones advice has solved your issue - and please bring back the Thumbs Up!!.

bonovox73's picture

Thanks a lot for this article.

Now I'll check if will solve my issue

 

Christian

NOC_N3RDS's picture

Any updates? I am having the same issue on a file server using shadow copy components.

I plan to install a hotfix this weekend.

JohnnyBB's picture

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.

bonovox73's picture

I solved the problem upgrading NBU, disabling DFS and moving the client on a network with better performances.