hyper-v backups failing 4207/4201

[noneatnoone]

14:23:55.459 [31606.31606] <2> dump_proxy_info: local_proxy_info:
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----pid: 11705
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----connection_id: {2181A948-5D50-11E9-BF83-DC144838C133}:OUTBOUND
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----ca_roots: 62c6785f-7010-436d-b140-ebb9843d84b1
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----ca_roots_excluded: UNCONSTRAINED
14:23:55.459 [31606.31606] <2> dump_proxy_info: remote_proxy_info:
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----pid: 11856
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----connection_id: {405A96F3-31B2-4044-B103-2FC5EA45E697}:INBOUND
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----ca_roots: 62c6785f-7010-436d-b140-ebb9843d84b1
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----ca_roots_excluded: UNCONSTRAINED
14:23:55.459 [31606.31606] <2> dump_proxy_info: remote_endpoint_info:
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----pid: 23064
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----local_hostname: vme02.hidden
14:23:55.459 [31606.31606] <2> dump_proxy_info: domain_constraints_set:
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----process_hint_server_name: netbackup02.hidden
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----process_hint: 62c6785f-7010-436d-b140-ebb9843d84b1
14:23:55.459 [31606.31606] <2> dump_proxy_info: ----process_hint_reason: there was no inherited hint, the connected peer was not a master server, so defaulted to primary master
14:23:55.459 [31606.31606] <2> is_connection_INBOUND: Connection-Is-INBOUND:[FALSE]
14:23:55.459 [31606.31606] <2> vnet_same_host_and_update: [vnet_addrinfo.c:3021] Comparing name1:[localhost] name2:[127.0.0.1]
14:23:55.460 [31606.31606] <2> is_connection_INBOUND: Connection-Is-INBOUND:[FALSE]
14:23:55.460 [31606.31606] <8> do_pbx_service: [vnet_connect.c:2579] via PBX VNETD CONNECT FROM 172.31.7.235.53661 TO 172.31.7.209.1556 fd = 6
14:23:55.461 [31606.31606] <2> is_connection_INBOUND: Connection-Is-INBOUND:[FALSE]
14:23:55.461 [31606.31606] <2> async_connect: [vnet_connect.c:2072] connect async CONNECT FROM 172.31.7.235.53661 TO 172.31.7.209.1556 fd = 6
14:23:55.461 [31606.31606] <2> connect_to_service: connect succeeded STATUS (0) SUCCESS FROM 0.0.0.0 TO vme02 172.31.7.209 vnetd VIA pbx
14:23:55.461 [31606.31606] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
14:23:55.469 [31606.31606] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 53028
14:23:55.470 [31606.31606] <2> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:494] hash_str1 14946a33a34a31100786ed01d94a02ea
14:23:55.601 [31606.31606] <2> is_connection_INBOUND: Connection-Is-INBOUND:[FALSE]
14:23:55.630 [31606.31606] <2> bpcr_get_version_rqst: bpcd version: 08100000
14:23:55.630 [31606.31606] <2> ddns_check: Entering
14:23:55.630 [31606.31606] <2> is_connection_INBOUND: Connection-Is-INBOUND:[FALSE]
14:23:55.830 [31606.31606] <2> bpcr_get_hostname_rqst: Server hostname length = 19
14:23:55.830 [31606.31606] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 5
14:23:55.830 [31606.31606] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 6
14:23:55.831 [31606.31606] <2> pfi_start_client: command = /usr/openv/netbackup/bin/bpfis bpfis delete -nbu -id ex-onprem01_1555093374 -bpstart_to 300 -bpend_to 300 -clnt vme02 -jobgrpid 293 -jobid 293 -copy 1 -pt 41 -st FULL -status 4201 -S netbackup02.hidden -fim Hyper-V_v2:allow_offline_backup=1,prov_type=0,csv_timeout=180,nameuse=1,Virtual_machine_backup=2,snap_attr=0
14:23:55.831 [31606.31606] <2> pfi_start_client: (../bpbrm.c:27069) (Jobid: 293) Using bpcr_fork_cmd_rqst to start bpfis
14:23:55.831 [31606.31606] <2> pfi_start_client: (../bpbrm.c:27112) (Jobid: 293) Connected to bpfis, data socket 5 is proxied, name socket 6 is proxied
14:23:55.831 [31606.31606] <2> pfi_start_client: received bpcd success message
14:23:58.184 [31606.31606] <2> pfi_start_client: read start message from vme02, msg=<INF - BACKUP START 25684>
14:23:58.184 [31606.31606] <2> set_job_details: Tfile (293): LOG 1555093438 4 bpfis 25684 Backup started
14:23:58.184 [31606.31606] <2> send_job_file: job ID 293, ftype = 3 msg len = 44, msg = LOG 1555093438 4 bpfis 25684 Backup started
14:23:58.185 [31606.31606] <2> get_bpfis_msg: bpfis buff: WRN - cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ex-onprem01_1555093374.1.0
14:23:58.185 [31606.31606] <8> get_bpfis_msg: from client ex-onprem01: WRN - cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ex-onprem01_1555093374.1.0
14:23:58.185 [31606.31606] <2> set_job_details: Tfile (293): LOG 1555093438 8 bpbrm 31606 from client ex-onprem01: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ex-onprem01_1555093374.1.0
14:23:58.185 [31606.31606] <2> send_job_file: job ID 293, ftype = 3 msg len = 158, msg = LOG 1555093438 8 bpbrm 31606 from client ex-onprem01: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ex-onprem01_1555093374.1.0
14:23:58.185 [31606.31606] <4> db_error_add_to_file: from client ex-onprem01: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ex-onprem01_1555093374.1.0
14:23:58.186 [31606.31606] <2> set_job_details: Tfile (293): LOG 1555093438 4 bpfis 25684 done. status: 4207
14:23:58.186 [31606.31606] <2> send_job_file: job ID 293, ftype = 3 msg len = 48, msg = LOG 1555093438 4 bpfis 25684 done. status: 4207
14:23:58.186 [31606.31606] <2> set_job_details: Tfile (293): END_OPERATION 1555093438
14:23:58.186 [31606.31606] <2> send_job_file: job ID 293, ftype = 3 msg len = 25, msg = END_OPERATION 1555093438
14:23:58.187 [31606.31606] <2> set_job_details: Tfile (293): LOG 1555093438 4 bpfis 25684 done. status: 4207: Could not fetch snapshot metadata or state files
14:23:58.187 [31606.31606] <2> send_job_file: job ID 293, ftype = 3 msg len = 98, msg = LOG 1555093438 4 bpfis 25684 done. status: 4207: Could not fetch snapshot metadata or state files
14:23:58.187 [31606.31606] <2> bpbrm Exit: client snapshot EXIT STATUS 4207: Could not fetch snapshot metadata or state files
14:23:58.187 [31606.31606] <2> vnet_close_socket_safely_ex: [vnet.c:1176] safe close 0 0x0
14:23:58.187 [31606.31606] <4> JobdSockList::UnregisterSocket: Unregister socket (4).
14:23:58.187 [31606.31606] <2> job_monitoring_exex: ACK disconnect
 status: 4207: Could not fetch snapshot metadata or state files
14:23:58.187 [31606.31606] <2> job_disconnect: Disconnected
~
~
________________________________________________
additional logs

Apr 12, 2019 2:34:39 PM - Info nbjm (pid=12770) starting backup job (jobid=294) for client ex-onprem01, policy exon, schedule Full
Apr 12, 2019 2:34:39 PM - Info nbjm (pid=12770) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=294, request id:{A165EE48-5D51-11E9-A660-EA8D4063A3A0})
Apr 12, 2019 2:34:39 PM - requesting resource  stu_disk_netbackup02
Apr 12, 2019 2:34:39 PM - requesting resource  netbackup02.centric.local.NBU_CLIENT.MAXJOBS.ex-onprem01
Apr 12, 2019 2:34:39 PM - requesting resource  netbackup02.centric.local.NBU_POLICY.MAXJOBS.exon
Apr 12, 2019 2:34:39 PM - granted resource  netbackup02.centric.local.NBU_CLIENT.MAXJOBS.ex-onprem01
Apr 12, 2019 2:34:39 PM - granted resource  netbackup02.centric.local.NBU_POLICY.MAXJOBS.exon
Apr 12, 2019 2:34:39 PM - granted resource  MediaID=@aaaab;DiskVolume=PureDiskVolume;DiskPool=dp_disk_netbackup02;Path=PureDiskVolume;StorageServer=netbackup02.centric.local;MediaServer=netbackup02.centric.local
Apr 12, 2019 2:34:39 PM - granted resource  stu_disk_netbackup02
Apr 12, 2019 2:34:39 PM - estimated 0 kbytes needed
Apr 12, 2019 2:34:39 PM - begin Parent Job
Apr 12, 2019 2:34:39 PM - begin Hyper-V: Start Notify Script
Apr 12, 2019 2:34:39 PM - Info RUNCMD (pid=34474) started
Apr 12, 2019 2:34:39 PM - Info RUNCMD (pid=34474) exiting with status: 0
Operation Status: 0
Apr 12, 2019 2:34:39 PM - end Hyper-V: Start Notify Script; elapsed time 0:00:00
Apr 12, 2019 2:34:39 PM - begin Hyper-V: Step By Condition
Operation Status: 0
Apr 12, 2019 2:34:39 PM - end Hyper-V: Step By Condition; elapsed time 0:00:00
Apr 12, 2019 2:34:39 PM - begin Hyper-V: Read File List
Operation Status: 0
Apr 12, 2019 2:34:39 PM - end Hyper-V: Read File List; elapsed time 0:00:00
Apr 12, 2019 2:34:39 PM - begin Hyper-V: Create Snapshot
Apr 12, 2019 2:34:39 PM - started process bpbrm (pid=34483)
Apr 12, 2019 2:34:45 PM - Info bpbrm (pid=34483) ex-onprem01 is the host to backup data from
Apr 12, 2019 2:34:45 PM - Info bpbrm (pid=34483) reading file list for client
Apr 12, 2019 2:34:46 PM - Info bpbrm (pid=34483) start bpfis on client
Apr 12, 2019 2:34:46 PM - Info bpbrm (pid=34483) Starting create snapshot processing
Apr 12, 2019 2:34:48 PM - Info bpfis (pid=14428) Backup started
Apr 12, 2019 2:35:37 PM - Info bpfis (pid=14428) Unexpected error. The error code is logged in the error log file
Apr 12, 2019 2:35:37 PM - Critical bpbrm (pid=34483) from client ex-onprem01: FTL - vfm_freeze_commit: method: Hyper-V_v2, type: FIM, function: Hyper-V_v2_make
Apr 12, 2019 2:35:37 PM - Critical bpbrm (pid=34483) from client ex-onprem01: FTL - snapshot services: snapshot creation failed: provider-private error.
Apr 12, 2019 2:35:37 PM - Critical bpbrm (pid=34483) from client ex-onprem01: FTL - vfm_freeze_commit: method: Hyper-V_v2, type: FIM, function: Hyper-V_v2_make
Apr 12, 2019 2:35:37 PM - Critical bpbrm (pid=34483) from client ex-onprem01: FTL - snapshot services: snapshot creation failed: provider-private error.
Apr 12, 2019 2:35:37 PM - Critical bpbrm (pid=34483) from client ex-onprem01: FTL - snapshot processing failed, status 4201
Apr 12, 2019 2:35:37 PM - Critical bpbrm (pid=34483) from client ex-onprem01: FTL - snapshot creation failed, status 4201
Apr 12, 2019 2:35:37 PM - Warning bpbrm (pid=34483) from client ex-onprem01: WRN - ALL_LOCAL_DRIVES is not frozen
Apr 12, 2019 2:35:37 PM - Info bpfis (pid=14428) done. status: 4201
Apr 12, 2019 2:35:37 PM - end Hyper-V: Create Snapshot; elapsed time 0:00:58
Apr 12, 2019 2:35:37 PM - Info bpfis (pid=14428) done. status: 4201: Incorrect snapshot method configuration or snapshot method not compatible for protecting backup selection entries.
Apr 12, 2019 2:35:37 PM - end writing
Operation Status: 4201
Apr 12, 2019 2:35:37 PM - end Parent Job; elapsed time 0:00:58
Apr 12, 2019 2:35:37 PM - begin Hyper-V: Stop On Error
Operation Status: 0
Apr 12, 2019 2:35:37 PM - end Hyper-V: Stop On Error; elapsed time 0:00:00
Apr 12, 2019 2:35:37 PM - begin Hyper-V: Delete Snapshot
Apr 12, 2019 2:35:37 PM - started process bpbrm (pid=34750)
Apr 12, 2019 2:35:44 PM - Info bpbrm (pid=34750) Starting delete snapshot processing
Apr 12, 2019 2:35:47 PM - Info bpfis (pid=19704) Backup started
Apr 12, 2019 2:35:47 PM - Warning bpbrm (pid=34750) from client ex-onprem01: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ex-onprem01_1555094079.1.0
Apr 12, 2019 2:35:47 PM - Info bpfis (pid=19704) done. status: 4207
Apr 12, 2019 2:35:47 PM - end Hyper-V: Delete Snapshot; elapsed time 0:00:10
Apr 12, 2019 2:35:47 PM - Info bpfis (pid=19704) done. status: 4207: Could not fetch snapshot metadata or state files
Apr 12, 2019 2:35:47 PM - end writing
Operation Status: 4207
Apr 12, 2019 2:35:47 PM - begin Hyper-V: End Notify Script
Apr 12, 2019 2:35:47 PM - Info RUNCMD (pid=34773) started
Apr 12, 2019 2:35:47 PM - Info RUNCMD (pid=34773) exiting with status: 0
Operation Status: 0
Apr 12, 2019 2:35:47 PM - end Hyper-V: End Notify Script; elapsed time 0:00:00
Operation Status: 4201
Incorrect snapshot method configuration or snapshot method not compatible for protecting backup selection entries  (4201)

[Thiago_Ribeiro]

Hi @noneatnoone ,

Have you opportunnity to check these articles? Maybe it can help you

https://www.veritas.com/content/support/en_US/article.100014536.html

https://vox.veritas.com/t5/NetBackup/Backup-to-HyperV/td-p/731604

Thiago

[noneatnoone]

many dead links in there,I've looked at those exact same pages all day and tried suggestions and no where closer.

[Thiago_Ribeiro]

Hi @noneatnoone ,

Once that you already check those techs, would be good to check the nbu logs, can you attached some of these logs? 

Verbose 3

install_path\NetBackup\logs\

bpfis

bpbrm
bptm
bpcd
bpVMutil

[Marianne]

Just sharing job details and logs without any background information does not help.

Please share all relevant info such as NBU version, Hyper-V version, VM OS and steps that you have followed to config Hyper-V backups.
This error says that there is something wrong with the config or that pre-reqs may have been overlooked:

"Incorrect snapshot method configuration"

[noneatnoone · Accepted solution]

it was the VSS storage for Snapshots, I ran the powershell to create vss storage snapshot space and it started working,