Netbackup FlashBackup-Windows Failed with Error 13 and Error 11

[Jason_Aaron]

Hi Guys,

I've been troubleshooting this one problem since last week and found many road blocks, solving them, and another come up. And now I'm still facing another one.

Back to the topic, I hope any expert here can help me in this.

I have been trying to configure a FlashBackup-Windows policy for a server. Knowing that the data is huge, I decided to go with FlashBackup-Windows. The server has two drives, C and D. I don't care so much about drive C as it has already been configured with a standart MS-Windows policy. My concern is drive D. It has 1.66TB of data. So here's what bpbkar log looks like.

 1:16:26.864 AM: [1284.8148] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = BACKUP \\.\D:\ USING \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy41\ OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_5276,FITYPE=MIRROR,MNTPOINT=\\.\D:\,FSTYPE=NTFS

1:16:26.864 AM: [1284.3760] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds

1:16:26.864 AM: [1284.8148] <2> tar_backup_vxbsa::add: INF - called with 'BACKUP \\.\D:\ USING \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy41\ OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_5276,FITYPE=MIRROR,MNTPOINT=\\.\D:\,FSTYPE=NTFS'

1:16:26.864 AM: [1284.8148] <4> V_Snapshot::V_Snapshot_AddMappings: INF - Volume Snapshot Mapping: \\?\Volume{51f45df5-41e1-11e0-8216-806e6f6e6963}\ --> GLOBALROOT\Device\HarddiskVolumeShadowCopy41

1:16:26.864 AM: [1284.8148] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '\\.\D:\' --> 00000000

1:16:30.161 AM: [1284.8148] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'

1:16:30.161 AM: [1284.8148] <4> dos_backup::tfs_startraw: INF - checking for: D:\

1:16:30.161 AM: [1284.8148] <4> V_DetermineMountInfo: INF - Checking Volume \\?\Volume{51f45df5-41e1-11e0-8216-806e6f6e6963}\ for '\'

1:16:30.161 AM: [1284.8148] <4> V_DetermineMountInfo: INF -   Adding NTFS Volume \\.\D: ==> \\?\Volume{51f45df5-41e1-11e0-8216-806e6f6e6963}\

1:16:30.161 AM: [1284.8148] <4> dos_backup::tfs_startraw: INF - RAW: \\.\

1:16:30.161 AM: [1284.8148] <4> dos_backup::tfs_startraw: INF - RAW: D:

1:16:30.161 AM: [1284.8148] <4> tar_backup_tfi::flash_start_state: FlashBackup of Raw partition 

1:16:30.192 AM: [1284.8148] <4> tar_backup_tfi::flash_start_state: FlashBackup of Raw partition isFlashBackup 0 

1:16:30.848 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - FIML startup time = 0

1:16:30.848 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Windows filesystem

1:16:56.677 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - arg list: rawdisk D:\ inctime 0 Startblk 0

1:16:56.677 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF -   clientname client.server.name, buid client.server.name_1299690968, filnum 0

1:16:56.693 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog D:\.

1:16:56.693 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - iDataLength == 0

1:16:56.693 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog D:\.

2:29:23.729 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog D:\.

2:29:23.729 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog D:\.

2:29:23.745 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Map completion time: 4347

2:29:23.745 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - scan_fs time: 4347

2:29:23.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - VxMS Performance stats: 

2:29:23.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Write Buffer Time: 0, Get Buffer Time: 0

2:29:23.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Get Metadata Time: 58, Write Catalog Time: 290

2:29:23.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Create Names Time: 171, Put Tape Time: 247

2:29:23.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Build Map Time: 2, Extract Stat Time: 10

2:29:23.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - Build Image Time: 3545, Next Index Time: 798

2:29:23.776 AM: [1284.8148] <4> dos_backup::tfs_readopen: INF - Snapshot name - GLOBALROOT\Device\HarddiskVolumeShadowCopy41

2:29:24.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: WRN - can't open raw device: \\.\D: (\\.\GLOBALROOT\Device\HarddiskVolumeShadowCopy41) (WIN32 2: The system cannot find the file specified. )

2:29:24.776 AM: [1284.8148] <4> tar_backup::backup_done_state: INF - number of file directives not found: 0

2:29:24.776 AM: [1284.8148] <4> tar_backup::backup_done_state: INF -     number of file directives found: 1

2:29:24.776 AM: [1284.3760] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0)

2:29:24.776 AM: [1284.8148] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0)

2:29:24.776 AM: [1284.8148] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 13: file read failed 

There's a line that get my attention - WRN - can't open raw device: \\.\D: --> I think this is the cause for the backup failure.

I will be very happy if somebody can help me on this. Thanks. :)

Regards,

Jason Aaron

[j083418]

Have you configured the backup using the following path:

\\.\d:\

if so it needs to be

\\.\d:

This is from the Flashbackup guide:

11 On the Backup Selections tab, specify the drive letter or mounted volume (Windows) or the raw disk partition (UNIX) containing the files to back up. Windows examples:

\\.\E:

\\.\E:\mounted_volume

where:

■ \\.\E: is a Windows disk volume mounted on a drive letter

■ \\.\E:\mounted_volume is a Windows disk volume without a drive letter mounted on a directory (Windows reparse point)

Note: The drive must be designated exactly as shown (E:\ is not correct). Backing up the drive containing the Windows system files (usually the C drive) is not supported.

[Jason_Aaron]

Wow that was fast! Thanks for the reply.

I've been checking and gone through the FlashBackup guide for many times since last week. Just to check if I missed something. And I followed the steps. But the result still same.

I also tried \\.\D: and \\.\D:\ ... Either way, backup failed with the same error.

Maybe this was caused by this:

WRN - can't open raw device: \\.\D: (\\.\GLOBALROOT\Device\HarddiskVolumeShadowCopy41) (WIN32 2: The system cannot find the file specified. )

 But I still don't understand why the backup failed...

[Marianne]

Please post your policy config:

bppllist <policy-name> -L

Please also create bpfis log directory - we need to see if snapshot of volume is attempted and which method is used.

[Jason_Aaron]

bpplist

 C:\Documents and Settings\id123>bppllist XXX-ServerName-D -L

Policy Name:       XXX-ServerName-D
Options:           0x0
template:          FALSE
c_unused1:         ?
Names:             (none)
Policy Type:       FlashBackup-Windows (29)
Active:            yes
Effective date:    03/10/2011 18:10:57
File Restore Raw:  yes
Mult. Data Stream: yes
Perform Snapshot Backup:   yes
Snapshot Method:           VSS
Snapshot Method Arguments: prov_type=0,snap_attr=0,max_snapshots=1
Perform Offhost Backup:    no
Backup Copy:               0
Use Data Mover:            no
Data Mover Type:           2
Use Alternate Client:      no
Alternate Client Name:     (none)
Use Virtual Machine:      0
Hyper-V Server Name:     (none)
Enable Instant Recovery:   no
Policy Priority:   0
Max Jobs/Policy:   Unlimited
Disaster Recovery: 0
Collect BMR Info:  no
Keyword:           (none specified)
Data Classification:       -
Residence is Storage Lifecycle Policy:    no
Client Encrypt:    no
Checkpoint:        no
Residence:         master-hcart-robot-tld-0
Volume Pool:       MSTR_File
Server Group:      *ANY*
Granular Restore Info:  no
Exchange Source attributes:              no
Exchange 2010 Preferred Server: (none defined)
Generation:      3
Ignore Client Direct:  no
Client/HW/OS/Pri:  client.server.name Windows-x86 Windows2003 0 0 0 0 ?
Include:           \\.\D:
Schedule:          Full
  Type:            FULL (0)
  Frequency:       7 day(s) (604800 seconds)
  Maximum MPX:     1
  Synthetic:       0
  PFI Recovery:    0
  Retention Level: 1 (2 weeks)
  u-wind/o/d:      0 0
  Incr Type:       DELTA (0)
  Alt Read Host:   (none defined)
  Max Frag Size:   0 MB
  Number Copies:   1
  Fail on Error:   0
  Residence:       (specific storage unit not required)
  Volume Pool:     (same as policy volume pool)
  Server Group:    (same as specified for policy)
  Residence is Storage Lifecycle Policy:     0
  Daily Windows:
  Day         Open       Close       W-Open     W-Close
  Sunday      000:00:00  000:00:00
  Monday      000:00:00  000:00:00
  Tuesday     000:00:00  000:00:00
  Wednesday   000:00:00  000:00:00
  Thursday    000:00:00  000:00:00
  Friday      000:00:00  000:00:00
  Saturday    018:00:00  029:00:00   162:00:00  173:00:00 005:00:00 

bpfis log. I think this should be sufficient. The snapshot method is VSS.

 17:29:37.605 [7576.7828] <2> read_vfm_conf: Found FIM: VSS_Writer

17:29:37.605 [7576.7828] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_vss_writer.dll

17:30:11.575 [7576.7828] <4> bpfis: INF - Deleted mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img___._D__7576

17:30:13.575 [7576.7828] <2> determine_vss_provider_type: Get the VSS provider type used for the snapshot

17:30:13.575 [7576.7828] <2> determine_vss_provider_type: VSS provider type was not given to bpfis, and could not be determined.

17:30:13.575 [7576.7828] <4> bpfis: INF - REMAP FILE BACKUP NEW_STREAM

17:30:13.575 [7576.7828] <4> bpfis: INF - REMAP FILE BACKUP \\.\D:\ USING \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy36\ OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_7576,FITYPE=MIRROR,MNTPOINT=\\.\D:\,FSTYPE=NTFS

17:30:13.762 [7576.7828] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006

17:30:13.778 [7576.7828] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd

17:30:13.950 [7576.7828] <2> logconnections: BPRD CONNECT FROM 1.2.3.4.567 TO 1.2.3.4.567

17:30:15.591 [7576.7828] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed

17:30:15.591 [7576.7828] <8> bpfis: WRN - Error closing stdout

23:43:05.897 [7496.7568] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id client.server.name_1299685361 -bpstart_to 300 -bpend_to 300 -backup_copy 0 -ru root -pt 13 -clnt client.server.name -rg root -class 050-ttt-Servers-5 -sched Incremental -fso -S master.server.name -WOFB -fim VSS 

23:43:05.913 [7496.7568] <2> bpfis main: received FIM as [3] VSS

23:43:06.256 [7496.7568] <4> bpfis: INF - BACKUP START 7496

23:43:06.256 [7496.7568] <2> bpfis main: receive filelist:<NEW_STREAM> 

23:43:06.272 [7496.7568] <2> bpfis main: receive filelist:<Shadow Copy Components:\> 

23:43:06.272 [7496.7568] <2> bpfis main: receive filelist:<NEW_STREAM> 

23:43:06.272 [7496.7568] <2> bpfis main: receive filelist:<C:\> 

23:43:06.272 [7496.7568] <2> bpfis main: receive filelist:<NEW_STREAM> 

23:43:06.272 [7496.7568] <2> bpfis main: receive filelist:<D:\> 

23:43:06.272 [7496.7568] <2> bpfis main: receive filelist:<CONTINUE> 

23:43:06.756 [7496.7568] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006

23:43:06.756 [7496.7568] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd

23:43:06.928 [7496.7568] <2> logconnections: BPRD CONNECT FROM 1.2.3.4.8910 TO 1.2.3.4.567

23:43:11.663 [7496.7568] <2> get_long: (2) premature end of file (byte 1)

23:43:11.663 [7496.7568] <2> bprd_read_text_file: get_string() failed, Access is denied.  (5), premature end of file encountered 

23:43:11.960 [7496.7568] <8> bpfis: WRN - VfMS error 10; see following messages:

23:43:11.960 [7496.7568] <8> bpfis: WRN - Non-fatal method error was reported

23:43:11.960 [7496.7568] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init

23:43:11.960 [7496.7568] <8> bpfis: WRN - VfMS method error 3; see following message:

23:43:11.960 [7496.7568] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.

23:43:12.038 [7496.7568] <8> bpfis: WRN - VfMS error 10; see following messages:

23:43:12.038 [7496.7568] <8> bpfis: WRN - Non-fatal method error was reported

23:43:12.038 [7496.7568] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init

23:43:12.038 [7496.7568] <8> bpfis: WRN - VfMS method error 3; see following message:

23:43:12.038 [7496.7568] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.

23:43:12.991 [7496.7568] <4> bpfis: INF - FIS_ID=client.server.name_1299685361

23:43:12.991 [7496.7568] <2> AdjustUnboundedAssociations: Registry value VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations

23:43:12.991 [7496.7568] <2> AdjustUnboundedAssociations: Modified override_fim=VSS:shadow_storage_size=-1

23:43:12.991 [7496.7568] <4> bpfis: INF - Preparing freeze of C:\ using snapshot method VSS.

23:43:12.991 [7496.7568] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_C__7496 

If you need any other info, don't hesitate to inform me. Thanks a lot!

[Nicolai]

You can attach files in a post. I think we need to see the hole BPFIS file.

[Jason_Aaron]

Oh.. I missed the file attachement button down there.

Just for your info, I just trigger the backup again and it still failed with error 13.

Anyway, here's my bpfis log.

[Marianne]

Please let us know the OS and NBU version on this client.

Some TN's:

http://www.symantec.com/docs/TECH54319
http://www.symantec.com/docs/TECH66930

[Jason_Aaron]

Hi Marianne,

Here's the details:

• Master Server - Netbackup 7.0 Enterprise Server
• Client running on Windows 2003
• Netbackup on the client is 7.0 as well

[Jason_Aaron]

I guess I got to wait till you guys come back online.. :D

[Marianne]

The TN's that I found do not seem to be applicable to your situation.

According to bpfis, the VSS snapshot method was successful:

11:38:09.935 [1652.6868] <4> bpfis: INF - Testing freeze of \\.\D:\ using snapshot method VSS.
11:38:09.935 [1652.6868] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img___._D__1652
11:38:11.997 [1652.6868] <4> bpfis: INF - Deleted mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img___._D__1652
11:38:11.997 [1652.6868] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed

But the whole process seemed to be started all over, this time failing:

11:52:09.467 [5820.7688] <32> bpfis: FTL - VfMS error 11; see following messages:
11:52:09.467 [5820.7688] <32> bpfis: FTL - Fatal method error was reported
11:52:09.467 [5820.7688] <32> bpfis: FTL - vfm_freeze: method: VSS, type: FIM, function: VSS_vfm_freeze_commit
11:52:09.467 [5820.7688] <32> bpfis: FTL - VfMS method error 1054; see following message:
11:52:09.467 [5820.7688] <32> bpfis: FTL - snapshot services: snapshot target analysis failed: resource not claimed by any provider.
11:52:09.467 [5820.7688] <32> bpfis: FTL - No snapshot method available for \\.\D:\*
11:52:09.467 [5820.7688] <32> bpfis: FTL - Cannot process filesystem \\.\D:\*
11:52:09.467 [5820.7688] <16> bpfis: FTL - process_fs_list() failed, status 20
11:52:09.467 [5820.7688] <4> bpfis: INF - EXIT STATUS 20: invalid command parameter

Maybe best to log a call with Symantec Support?

[Jason_Aaron]

Yeah,

I think it's best to log a call to Symantec too. I just want to get somebody opinion here 1st before I log a call to Symantec.

Anyway, thanks for your time and help!

Regards,

Jason Aaron

[Jason_Aaron]

Hi,

I logged a case with Symantec and was told that this might be caused by insuffiency of shadow copy storage.

For flashbackup, we need 15% of the disk space. For example, in my case I have 1.7TB of disk capacity. So I will need 15% (255GB) of my disk capacity for snapshot creation.

The reason why my flashbackup failed was because it might be caused by lack of disk space for shadow storage. At the moment, the disk I'm trying to backup has only 12% of disk space. I can move the shadow storage to another drive but unfortunately the server only have one other drive (C:) which only has 60GB of disk space left.

Personally, I think this explain why my backup failed. But I still haven't confirm it. I'm creating another test policy for another server and I will see if this really the cause.

I will post the update if this is the solution.

Regards,

Jason

[Jason_Aaron · Accepted solution]

Ok guys,

After several attempts, it seems that the problem has been solved. Here's the solution:

Tthe initial test backup failed due to high IO load on the disk and thus making the disk busy. So I presented 350GB of disk (15% of the disk capacity) dedicated for the shadow copy storage. Then I change the original location of shadow copy of the drive to the newly presented disk. This will reduce the IO load on the disk being backed up.

I hope this will be good info for anyone who facing the same problem.

Regards,
Jason