Netbackup snapshot creation failed, ALL_LOCAL_DRIVES is not frozen, status 156

[ELKHOMRI]

dear expert, Can you help us please for this Snapshot problem

My environment:

Master server : netbackup 7.1 , windows 2008

Mediar server : netbackup 7.1 , windows 2008 (Hyper V )

VM   hostname : Msproj , windows 2008 

Log :

18/05/2014 20:11:06 - begin Create Snapshot

18/05/2014 20:11:09 - Info bpfis(pid=1648) Backup started          

18/05/2014 20:11:22 - Critical bpbrm(pid=16332) from client srvmsproj.onepnet.intra: FTL - snapshot creation failed, status 156  

18/05/2014 20:11:22 - Warning bpbrm(pid=16332) from client srvmsproj.onepnet.intra: WRN - ALL_LOCAL_DRIVES is not frozen   

18/05/2014 20:11:24 - Info bpfis(pid=1648) done. status: 156         

18/05/2014 20:11:24 - end Create Snapshot; elapsed time: 00:00:18

18/05/2014 20:11:26 - end writing

Status 156

18/05/2014 20:11:26 - end Flash Backup Windows, Create Snapshot; elapsed time: 00:00:28

18/05/2014 20:11:26 - begin Flash Backup Windows, Stop On Error

Status 0

18/05/2014 20:11:26 - end Flash Backup Windows, Stop On Error; elapsed time: 00:00:00

18/05/2014 20:11:26 - begin Flash Backup Windows, Delete Snapshot On Exit

18/05/2014 20:11:26 - begin Flash Backup Windows, Delete Snapshot On Exit

18/05/2014 20:11:27 - started process bpbrm (6684)

18/05/2014 20:11:31 - Info bpfis(pid=0) done. status: 156: snapshot error encountered      

18/05/2014 20:11:42 - end writing

Status 0

18/05/2014 20:11:42 - end Flash Backup Windows, Delete Snapshot On Exit; elapsed time: 00:00:16

18/05/2014 20:11:42 - begin Flash Backup Windows, End Notify Script

18/05/2014 20:11:43 - Info RUNCMD(pid=17164) started           

18/05/2014 20:11:43 - Info RUNCMD(pid=17164) exiting with status: 0        

Status 0

18/05/2014 20:11:43 - end Flash Backup Windows, End Notify Script; elapsed time: 00:00:01

Status 156

18/05/2014 20:11:43 - end Flash Backup Windows, Delete Snapshot On Exit; elapsed time: 00:00:17

snapshot error encountered(156)

bpfis:

20:00:14.116 [5148.12880] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id srvmsproj.onepnet.intra_1401393601 -bpstart_to 300 -bpend_to 300 -backup_copy 0 -ru root -pt 29 -vm_type 2 -vm_client srvmsproj.onepnet.intra -clnt hyperv.onepnet.intra -st FULL -rg root -fim Hyper-V:nameuse=0,Virtual_machine_backup=2,prov_type=0,snap_attr=0,allow_offline_backup=1,csv_timeout=0,nameuse=0 -class Msproj -sched Full -fso -S bkp-srv1
20:00:14.116 [5148.12880] <2> bpfis main: received FIM as [113] Hyper-V:nameuse=0,Virtual_machine_backup=2,prov_type=0,snap_attr=0,allow_offline_backup=1,csv_timeout=0,nameuse=0
20:00:14.272 [5148.12880] <4> bpfis: INF - BACKUP START 5148
20:00:14.272 [5148.12880] <2> bpfis main: receive filelist:<NEW_STREAM>
20:00:14.272 [5148.12880] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
20:00:14.474 [5148.12880] <2> bpfis main: receive filelist:<CONTINUE>
20:00:14.646 [5148.12880] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:00:14.646 [5148.12880] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:00:14.864 [5148.12880] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54028 TO 10.100.100.142.13724
20:00:17.672 [5148.12880] <2> get_long: (2) premature end of file (byte 1)
20:00:17.672 [5148.12880] <2> bprd_read_text_file: get_string() failed, Access is denied.  (5), premature end of file encountered
20:00:17.813 [5148.12880] <8> bpfis: WRN - VfMS error 10; see following messages:
20:00:17.813 [5148.12880] <8> bpfis: WRN - Non-fatal method error was reported
20:00:17.813 [5148.12880] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init
20:00:17.813 [5148.12880] <8> bpfis: WRN - VfMS method error 3; see following message:
20:00:17.813 [5148.12880] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.
20:00:17.875 [5148.12880] <8> bpfis: WRN - VfMS error 10; see following messages:
20:00:17.875 [5148.12880] <8> bpfis: WRN - Non-fatal method error was reported
20:00:17.875 [5148.12880] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init
20:00:17.875 [5148.12880] <8> bpfis: WRN - VfMS method error 3; see following message:
20:00:17.875 [5148.12880] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.
20:00:18.172 [5148.12880] <4> bpfis: INF - FIS_ID=srvmsproj.onepnet.intra_1401393601
20:00:18.172 [5148.12880] <4> bpfis: INF - Preparing freeze of ALL_LOCAL_DRIVES using snapshot method Hyper-V.
20:00:18.172 [5148.12880] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_5148
20:00:18.172 [5148.12880] <2> read_vfm_conf: options=0x2
20:00:18.172 [5148.12880] <2> read_vfm_conf: Reading file: C:\Program Files\Veritas\NetBackup\vfm.conf
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: auto
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_auto.dll
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: Hyper-V
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libvfms.dll
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword nameuse
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification client_name_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='client_name_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default client_name_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Client Name Selection
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword Virtual_machine_backup
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification hyperv_backup_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='hyperv_backup_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default hyperv_backup_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Virtual Machine Backup
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword prov_type
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification vss_provider_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='vss_provider_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default vss_provider_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Provider Type
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword snap_attr
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification snapshot_attribute_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='snapshot_attribute_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default snapshot_attribute_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Snapshot Attribute
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword allow_offline_backup
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %b
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Allow Offline Backup of VM
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword csv_timeout
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0-:0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0-:0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt CSV Timeout in Minutes
20:00:18.172 [5148.12880] <2> map_integer_value: virtual_machine_supported=Hyper-V, converted value=2, status=1
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: VSS
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libvfms.dll
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword prov_type
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0-3:0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0-3:0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Provider Type (0-auto 1-system 2-software 3-hardware)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword snap_attr
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0-2:0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0-2:0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Snapshot Attribute(0-unspecified 1-differential 2-plex)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword max_snapshots
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: FlashSnap
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_FlashSnap.dll
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword keep_fi
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %b
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Keep snapshot after backup (not Instant Recovery)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword async_resync
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %b
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Resynchronize mirror in background (not Instant Recovery)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword max_snapshots
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword dg_split_retry_times
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Number of times to retry disk group split
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword dg_split_retry_wait_period
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 60-:60
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='60-:60'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 60
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Delay in seconds between disk group split retries
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword num_sync_vols
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-32:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-32:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Maximum number of volumes to resynchronize concurrently
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword iosize
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-128:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-128:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Sync region size in MB (UNIX only)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword slow
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0-:0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0-:0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Sync I/O delay in milliseconds (UNIX only)
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: vxvm
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_vxvm.dll
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword async_resync
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %b
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Resynchronize mirror in background (not Instant Recovery)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword max_snapshots
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword sync_wait
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %b
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Wait for mirror sync completion (Data Mover backups only)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword num_sync_vols
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-32:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-32:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Maximum number of volumes to resynchronize concurrently
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword iosize
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-128:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-128:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Sync region size in MB (UNIX only)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword slow
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 0-:0
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='0-:0'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 0
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Sync I/O delay in milliseconds (UNIX only)
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: VMware
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_VMware.dll
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword nameuse
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification client_name_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='client_name_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default client_name_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Client name selection
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword Virtual_machine_backup
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification vmware_backup_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='vmware_backup_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default vmware_backup_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Virtual machine backup
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword trantype
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification VMware_transfer_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='VMware_transfer_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default VMware_transfer_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Transfer type
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword disable_quiesce
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification enabled_disable_quiesce_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='enabled_disable_quiesce_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default enabled_disable_quiesce_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Virtual machine quiesce
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword file_system_optimization
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification enabled_disabled_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='enabled_disabled_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default enabled_disabled_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Exclude unused and deleted blocks
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword snapact
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification snapshot_handling_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='snapshot_handling_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default snapshot_handling_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Existing snapshot handling
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword vmmono
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %dd
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification disabled_enabled_type_list
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='disabled_enabled_type_list'
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default disabled_enabled_type_list
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Monolithic export (VCB only)
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword mntpt
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %s
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Snapshot mount point (VCB only)
20:00:18.172 [5148.12880] <2> map_integer_value: virtual_machine_supported=VMware, converted value=1, status=1
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: NAS_Snapshot
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_NAS_Snapshot.dll
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found keyword max_snapshots
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found data type %d
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found value specification 1-:1
20:00:18.172 [5148.12880] <2> parse_value_specification: Value specification='1-:1'
20:00:18.172 [5148.12880] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:00:18.172 [5148.12880] <2> parse_value_specification: Found default 1
20:00:18.172 [5148.12880] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found FIM: VSS_Writer
20:00:18.172 [5148.12880] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_vss_writer.dll
20:00:25.067 [5148.12880] <32> bpfis: FTL - VfMS error 11; see following messages:
20:00:25.067 [5148.12880] <32> bpfis: FTL - Fatal method error was reported
20:00:25.067 [5148.12880] <32> bpfis: FTL - vfm_freeze_commit: method: Hyper-V, type: FIM, function: Hyper-V_gentree
20:00:25.067 [5148.12880] <32> bpfis: FTL - VfMS method error 6; see following message:
20:00:25.067 [5148.12880] <32> bpfis: FTL - snapshot services: snapshot target analysis failed: provider-private error.
20:00:25.067 [5148.12880] <32> bpfis: FTL - VfMS error 11; see following messages:
20:00:25.067 [5148.12880] <32> bpfis: FTL - Fatal method error was reported
20:00:25.067 [5148.12880] <32> bpfis: FTL - vfm_freeze_commit: method: Hyper-V, type: FIM, function: Hyper-V_gentree
20:00:25.067 [5148.12880] <32> bpfis: FTL - VfMS method error 6; see following message:
20:00:25.067 [5148.12880] <32> bpfis: FTL - snapshot services: snapshot target analysis failed: provider-private error.
20:00:25.067 [5148.12880] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method Hyper-V.
20:00:27.079 [5148.12880] <4> bpfis: INF - do_thaw return value: 5
20:00:27.079 [5148.12880] <32> bpfis: FTL - VfMS error 5; see following messages:
20:00:27.079 [5148.12880] <32> bpfis: FTL - File open failed
20:00:27.079 [5148.12880] <32> bpfis: FTL - do_reaccess: cannot open reaccess file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.srvmsproj.onepnet.intra_1401393601.0.fiid
20:00:27.079 [5148.12880] <16> bpfis: FTL - snapshot creation failed, status 156
20:00:27.079 [5148.12880] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method Hyper-V.
20:00:27.079 [5148.12880] <8> bpfis: WRN - ALL_LOCAL_DRIVES is not frozen
20:00:27.079 [5148.12880] <8> bpfis: WRN - snapshot delete returned status 20
20:00:27.095 [5148.12880] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:00:27.095 [5148.12880] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:00:27.329 [5148.12880] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54034 TO 10.100.100.142.13724
20:00:28.811 [5148.12880] <4> bpfis: INF - EXIT STATUS 156: snapshot error encountered
20:00:40.168 [6996.6968] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe delete -nbu -id srvmsproj.onepnet.intra_1401393601 -bpstart_to 300 -bpend_to 300 -clnt hyperv.onepnet.intra -pt 29 -st FULL -status 156 -S bkp-srv1
20:00:40.199 [6996.6968] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:00:40.199 [6996.6968] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:00:40.417 [6996.6968] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54049 TO 10.100.100.142.13724
20:00:41.868 [6996.6968] <4> bpfis: INF - BACKUP START 6996
20:00:41.868 [6996.6968] <32> bpfis: FTL - cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.srvmsproj.onepnet.intra_1401393601.0
20:00:41.899 [6996.6968] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:00:41.899 [6996.6968] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:00:42.134 [6996.6968] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54052 TO 10.100.100.142.13724
20:00:43.553 [6996.6968] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed
20:10:55.801 [6876.10932] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id srvmsproj.onepnet.intra_1401394246 -bpstart_to 300 -bpend_to 300 -backup_copy 0 -ru root -pt 29 -vm_type 2 -vm_client srvmsproj.onepnet.intra -clnt hyperv.onepnet.intra -st FULL -rg root -fim Hyper-V:nameuse=0,Virtual_machine_backup=2,prov_type=0,snap_attr=0,allow_offline_backup=1,csv_timeout=0,nameuse=0 -class Msproj -sched Full -fso -S bkp-srv1
20:10:55.801 [6876.10932] <2> bpfis main: received FIM as [113] Hyper-V:nameuse=0,Virtual_machine_backup=2,prov_type=0,snap_attr=0,allow_offline_backup=1,csv_timeout=0,nameuse=0
20:10:55.817 [6876.10932] <4> bpfis: INF - BACKUP START 6876
20:10:55.817 [6876.10932] <2> bpfis main: receive filelist:<NEW_STREAM>
20:10:55.817 [6876.10932] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
20:10:56.035 [6876.10932] <2> bpfis main: receive filelist:<CONTINUE>
20:10:56.066 [6876.10932] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:10:56.066 [6876.10932] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:10:56.300 [6876.10932] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54307 TO 10.100.100.142.13724
20:10:58.734 [6876.10932] <2> get_long: (2) premature end of file (byte 1)
20:10:58.734 [6876.10932] <2> bprd_read_text_file: get_string() failed, Access is denied.  (5), premature end of file encountered
20:10:58.734 [6876.10932] <8> bpfis: WRN - VfMS error 10; see following messages:
20:10:58.734 [6876.10932] <8> bpfis: WRN - Non-fatal method error was reported
20:10:58.734 [6876.10932] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init
20:10:58.734 [6876.10932] <8> bpfis: WRN - VfMS method error 3; see following message:
20:10:58.734 [6876.10932] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.
20:10:58.734 [6876.10932] <8> bpfis: WRN - VfMS error 10; see following messages:
20:10:58.734 [6876.10932] <8> bpfis: WRN - Non-fatal method error was reported
20:10:58.734 [6876.10932] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init
20:10:58.734 [6876.10932] <8> bpfis: WRN - VfMS method error 3; see following message:
20:10:58.734 [6876.10932] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.
20:10:58.781 [6876.10932] <4> bpfis: INF - FIS_ID=srvmsproj.onepnet.intra_1401394246
20:10:58.781 [6876.10932] <4> bpfis: INF - Preparing freeze of ALL_LOCAL_DRIVES using snapshot method Hyper-V.
20:10:58.781 [6876.10932] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_6876
20:10:58.781 [6876.10932] <2> read_vfm_conf: options=0x2
20:10:58.781 [6876.10932] <2> read_vfm_conf: Reading file: C:\Program Files\Veritas\NetBackup\vfm.conf
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: auto
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_auto.dll
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: Hyper-V
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libvfms.dll
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword nameuse
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification client_name_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='client_name_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default client_name_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Client Name Selection
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword Virtual_machine_backup
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification hyperv_backup_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='hyperv_backup_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default hyperv_backup_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Virtual Machine Backup
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword prov_type
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification vss_provider_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='vss_provider_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default vss_provider_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Provider Type
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword snap_attr
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification snapshot_attribute_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='snapshot_attribute_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default snapshot_attribute_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Snapshot Attribute
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword allow_offline_backup
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %b
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Allow Offline Backup of VM
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword csv_timeout
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0-:0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0-:0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt CSV Timeout in Minutes
20:10:58.781 [6876.10932] <2> map_integer_value: virtual_machine_supported=Hyper-V, converted value=2, status=1
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: VSS
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libvfms.dll
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword prov_type
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0-3:0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0-3:0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Provider Type (0-auto 1-system 2-software 3-hardware)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword snap_attr
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0-2:0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0-2:0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Snapshot Attribute(0-unspecified 1-differential 2-plex)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword max_snapshots
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: FlashSnap
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_FlashSnap.dll
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword keep_fi
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %b
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Keep snapshot after backup (not Instant Recovery)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword async_resync
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %b
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Resynchronize mirror in background (not Instant Recovery)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword max_snapshots
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword dg_split_retry_times
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Number of times to retry disk group split
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword dg_split_retry_wait_period
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 60-:60
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='60-:60'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 60
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Delay in seconds between disk group split retries
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword num_sync_vols
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-32:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-32:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Maximum number of volumes to resynchronize concurrently
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword iosize
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-128:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-128:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Sync region size in MB (UNIX only)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword slow
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0-:0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0-:0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Sync I/O delay in milliseconds (UNIX only)
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: vxvm
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_vxvm.dll
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword async_resync
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %b
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Resynchronize mirror in background (not Instant Recovery)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword max_snapshots
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword sync_wait
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %b
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Wait for mirror sync completion (Data Mover backups only)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword num_sync_vols
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-32:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-32:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Maximum number of volumes to resynchronize concurrently
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword iosize
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-128:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-128:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Sync region size in MB (UNIX only)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword slow
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 0-:0
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='0-:0'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 0
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Sync I/O delay in milliseconds (UNIX only)
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: VMware
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_VMware.dll
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword nameuse
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification client_name_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='client_name_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default client_name_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Client name selection
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword Virtual_machine_backup
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification vmware_backup_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='vmware_backup_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default vmware_backup_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Virtual machine backup
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword trantype
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification VMware_transfer_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='VMware_transfer_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default VMware_transfer_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Transfer type
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword disable_quiesce
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification enabled_disable_quiesce_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='enabled_disable_quiesce_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default enabled_disable_quiesce_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Virtual machine quiesce
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword file_system_optimization
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification enabled_disabled_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='enabled_disabled_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default enabled_disabled_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Exclude unused and deleted blocks
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword snapact
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification snapshot_handling_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='snapshot_handling_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default snapshot_handling_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Existing snapshot handling
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword vmmono
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %dd
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification disabled_enabled_type_list
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='disabled_enabled_type_list'
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default disabled_enabled_type_list
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Monolithic export (VCB only)
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword mntpt
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %s
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Snapshot mount point (VCB only)
20:10:58.781 [6876.10932] <2> map_integer_value: virtual_machine_supported=VMware, converted value=1, status=1
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: NAS_Snapshot
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_NAS_Snapshot.dll
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found keyword max_snapshots
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found data type %d
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found value specification 1-:1
20:10:58.781 [6876.10932] <2> parse_value_specification: Value specification='1-:1'
20:10:58.781 [6876.10932] <2> parse_value_specification: Null maximum value; using INT_MAX (2147483647)
20:10:58.781 [6876.10932] <2> parse_value_specification: Found default 1
20:10:58.781 [6876.10932] <2> parse_ssm_parms: Found prompt Maximum Snapshots (Instant Recovery only)
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found FIM: VSS_Writer
20:10:58.781 [6876.10932] <2> read_vfm_conf: Found library: C:\Program Files\Veritas\NetBackup\bin\libfi_vss_writer.dll
20:11:04.319 [6876.10932] <32> bpfis: FTL - VfMS error 11; see following messages:
20:11:04.319 [6876.10932] <32> bpfis: FTL - Fatal method error was reported
20:11:04.319 [6876.10932] <32> bpfis: FTL - vfm_freeze_commit: method: Hyper-V, type: FIM, function: Hyper-V_gentree
20:11:04.319 [6876.10932] <32> bpfis: FTL - VfMS method error 6; see following message:
20:11:04.319 [6876.10932] <32> bpfis: FTL - snapshot services: snapshot target analysis failed: provider-private error.
20:11:04.319 [6876.10932] <32> bpfis: FTL - VfMS error 11; see following messages:
20:11:04.319 [6876.10932] <32> bpfis: FTL - Fatal method error was reported
20:11:04.319 [6876.10932] <32> bpfis: FTL - vfm_freeze_commit: method: Hyper-V, type: FIM, function: Hyper-V_gentree
20:11:04.319 [6876.10932] <32> bpfis: FTL - VfMS method error 6; see following message:
20:11:04.319 [6876.10932] <32> bpfis: FTL - snapshot services: snapshot target analysis failed: provider-private error.
20:11:04.319 [6876.10932] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method Hyper-V.
20:11:06.331 [6876.10932] <4> bpfis: INF - do_thaw return value: 5
20:11:06.331 [6876.10932] <32> bpfis: FTL - VfMS error 5; see following messages:
20:11:06.331 [6876.10932] <32> bpfis: FTL - File open failed
20:11:06.331 [6876.10932] <32> bpfis: FTL - do_reaccess: cannot open reaccess file C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.srvmsproj.onepnet.intra_1401394246.0.fiid
20:11:06.331 [6876.10932] <16> bpfis: FTL - snapshot creation failed, status 156
20:11:06.331 [6876.10932] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method Hyper-V.
20:11:06.331 [6876.10932] <8> bpfis: WRN - ALL_LOCAL_DRIVES is not frozen
20:11:06.331 [6876.10932] <8> bpfis: WRN - snapshot delete returned status 20
20:11:06.363 [6876.10932] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:11:06.363 [6876.10932] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:11:06.581 [6876.10932] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54310 TO 10.100.100.142.13724
20:11:08.016 [6876.10932] <4> bpfis: INF - EXIT STATUS 156: snapshot error encountered
20:11:19.560 [7632.11024] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe delete -nbu -id srvmsproj.onepnet.intra_1401394246 -bpstart_to 300 -bpend_to 300 -clnt hyperv.onepnet.intra -pt 29 -st FULL -status 156 -S bkp-srv1
20:11:19.592 [7632.11024] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:11:19.592 [7632.11024] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:11:19.826 [7632.11024] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54326 TO 10.100.100.142.13724
20:11:21.276 [7632.11024] <4> bpfis: INF - BACKUP START 7632
20:11:21.276 [7632.11024] <32> bpfis: FTL - cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.srvmsproj.onepnet.intra_1401394246.0
20:11:21.308 [7632.11024] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
20:11:21.308 [7632.11024] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
20:11:21.526 [7632.11024] <2> logconnections: BPRD CONNECT FROM 10.100.1.116.54329 TO 10.100.100.142.13724
20:11:22.977 [7632.11024] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed

[Will_Restore]

Try changing Provider Type to System.  This dialog appears when you click Advanced on the Hyper-V policy tab.

[Nate_D1 · Accepted solution]

This looks like this might be a fix: http://www.symantec.com/business/support/index?page=content&id=TECH152313

Do you have the 'snapshot attribute' set to 'no' ? (policy options, options button, snapshot attribute). We use VMware but 156 all_local_drives frozen is the most common error I get. I almost always just look over the target VM and find an issue - low disk space, excessive snapshots, alarms in vCenter, etc. etc. 'look at whats changed'.