cancel
Showing results forΒ 
Search instead forΒ 
Did you mean:Β 

Backup failing with 156 error

lalajee
Level 4

Hi,

We are having problem with one of server where it keep failing.

We are running

  • Master Server: Windows 2012 R2 STd (Netbackup  Version 8.0)
  • Media Server: Linux latest version (Its a netbackup appliance )
  • Host: Windows 2012 R2 std           (Netbackup V: 7.7)
  • Guest: Windows 2008 R2 STD       (Netbackup  V 7.7)

Policy setting

  • Policy Type: Hyper-V (Running windows: Windows 2012 R2 std )
  • It gets backup on to netbackup appliance
  • Backup Methed: Hyper-v host sp2 or later vss
  • Online backup because it has sql server


02-May-2017 14:31:08 - Info nbjm (pid=5280) starting backup job (jobid=29222) for client SERVER.DOMAIN.com, policy POLICY_NAME, schedule Mon
02-May-2017 14:31:08 - Info nbjm (pid=5280) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=29222, request id:{379F1EF7-8B70-4E15-AA62-E20B3F5898B2})
02-May-2017 14:31:08 - requesting resource dedupe_MEDIASERVER.DOMAIN.com
02-May-2017 14:31:08 - requesting resource MASTER-SERVER.DOMAIN.com.NBU_CLIENT.MAXJOBS.SERVER.DOMAIN.com
02-May-2017 14:31:08 - requesting resource MASTER-SERVER.DOMAIN.com.Hyper-V.Active
02-May-2017 14:31:08 - requesting resource MASTER-SERVER.DOMAIN.com.Hyper-V.Active
02-May-2017 14:31:08 - requesting resource MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot
02-May-2017 14:31:08 - requesting resource MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot
02-May-2017 14:31:08 - granted resource  MASTER-SERVER.DOMAIN.com.NBU_CLIENT.MAXJOBS.SERVER.DOMAIN.com
02-May-2017 14:31:08 - granted resource  MASTER-SERVER.DOMAIN.com.Hyper-V.Active Snapshots Per Cluster.NAME
02-May-2017 14:31:08 - granted resource  MASTER-SERVER.DOMAIN.com.Hyper-V.Active Snapshots Per Server.HOST-NAME
02-May-2017 14:31:08 - granted resource  MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot Operations Per Cluster.NAME
02-May-2017 14:31:08 - granted resource  MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot Operations Per Server.HOST-NAME
02-May-2017 14:31:08 - granted resource  MediaID=@aaabK;DiskVolume=PureDiskVolume;DiskPool=dedupe_MEDIASERVER.DOMAIN.com;Path=PureDiskVolume;StorageServer=MEDIASERVER.DOMAIN.com;MediaServer=MEDIASERVER.DOMAIN.com
02-May-2017 14:31:08 - granted resource  dedupe_MEDIASERVER.DOMAIN.com
02-May-2017 14:31:10 - estimated 823501982 kbytes needed
02-May-2017 14:31:10 - begin Parent Job
02-May-2017 14:31:10 - begin Application Snapshot: Step By Condition
Operation Status: 0
02-May-2017 14:31:10 - end Application Snapshot: Step By Condition; elapsed time 0:00:00
02-May-2017 14:31:10 - begin Application Snapshot: Read File List
Operation Status: 0
02-May-2017 14:31:10 - end Application Snapshot: Read File List; elapsed time 0:00:00
02-May-2017 14:31:10 - begin Application Snapshot: Create Snapshot
02-May-2017 14:31:13 - started process bpbrm (pid=43337)
02-May-2017 14:31:14 - Info bpbrm (pid=43337) SERVER.DOMAIN.com is the host to backup data from
02-May-2017 14:31:14 - Info bpbrm (pid=43337) reading file list for client
02-May-2017 14:31:14 - Info bpbrm (pid=43337) start bpfis on client
02-May-2017 14:31:15 - Info bpbrm (pid=43337) Starting create snapshot processing
02-May-2017 14:31:15 - Info bpfis (pid=10988) Backup started
02-May-2017 14:32:30 - Critical bpbrm (pid=43337) from client SERVER.DOMAIN.com: FTL - vfm_freeze_commit: method: Hyper-V_v2, type: FIM, function: Hyper-V_v2_make
02-May-2017 14:32:30 - Critical bpbrm (pid=43337) from client SERVER.DOMAIN.com: FTL - snapshot services: snapshot creation failed: unknown error.
02-May-2017 14:32:30 - Critical bpbrm (pid=43337) from client SERVER.DOMAIN.com: FTL - vfm_freeze_commit: method: Hyper-V_v2, type: FIM, function: Hyper-V_v2_make
02-May-2017 14:32:30 - Critical bpbrm (pid=43337) from client SERVER.DOMAIN.com: FTL - snapshot services: snapshot creation failed: unknown error.
02-May-2017 14:32:31 - Critical bpbrm (pid=43337) from client SERVER.DOMAIN.com: FTL - snapshot processing failed, status 156
02-May-2017 14:32:31 - Critical bpbrm (pid=43337) from client SERVER.DOMAIN.com: FTL - snapshot creation failed, status 156
02-May-2017 14:32:31 - Warning bpbrm (pid=43337) from client SERVER.DOMAIN.com: WRN - ALL_LOCAL_DRIVES is not frozen
02-May-2017 14:32:31 - Info bpfis (pid=10988) done. status: 156
02-May-2017 14:32:31 - end Application Snapshot: Create Snapshot; elapsed time 0:01:21
02-May-2017 14:32:31 - Info bpfis (pid=10988) done. status: 156: snapshot error encountered
02-May-2017 14:32:31 - end writing
Operation Status: 156
02-May-2017 14:32:31 - end Parent Job; elapsed time 0:01:21
02-May-2017 14:32:31 - begin Application Snapshot: Stop On Error
Operation Status: 0
02-May-2017 14:32:31 - end Application Snapshot: Stop On Error; elapsed time 0:00:00
02-May-2017 14:32:31 - begin Application Snapshot: Cleanup Resources
02-May-2017 14:32:31 - requesting resource MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot
02-May-2017 14:32:31 - requesting resource MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot
02-May-2017 14:32:31 - granted resource  MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot Operations Per Cluster.NAME
02-May-2017 14:32:31 - granted resource  MASTER-SERVER.DOMAIN.com.Hyper-V.Snapshot Operations Per Server.HOST-NAME
Operation Status: 0
02-May-2017 14:32:31 - end Application Snapshot: Cleanup Resources; elapsed time 0:00:00
02-May-2017 14:32:31 - begin Application Snapshot: Delete Snapshot
02-May-2017 14:32:33 - started process bpbrm (pid=43820)
02-May-2017 14:32:35 - Info bpbrm (pid=43820) Starting delete snapshot processing
02-May-2017 14:32:36 - Info bpfis (pid=5040) Backup started
02-May-2017 14:32:36 - Warning bpbrm (pid=43820) from client SERVER.DOMAIN.com: cannot open C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\bpfis.fim.SERVER.DOMAIN.com_1493731870.1.0
02-May-2017 14:32:37 - Info bpfis (pid=5040) done. status: 4207
02-May-2017 14:32:37 - end Application Snapshot: Delete Snapshot; elapsed time 0:00:06
02-May-2017 14:32:37 - Info bpfis (pid=5040) done. status: 4207: Could not fetch snapshot metadata or state files
02-May-2017 14:32:37 - end writing
Operation Status: 4207
Operation Status: 156
snapshot error encountered  (156)

14 REPLIES 14

Thank you for reply.

I have check the document and it all seem to be right. it was working fine last week but now it stop working. we havent change any settings

Thiago_Ribeiro
Moderator
Moderator
Partner    VIP    Accredited

Hi lalajee,

In addition to Marianne's article there are these, maybe can it can help you.

https://www.veritas.com/support/en_US/article.000011616 - Status 156 on Hyper-V backups
https://www.veritas.com/support/en_US/article.000011553 - Hyper-v Backups fail with status 156:snapshot creation failed.

 

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Have you checked logs as suggested in the TN?

There is no quick fix for snapshot errors.

You need to carefully examine each of the possibilities.

bp logs

13:42:56.169 [19004.11768] <2> logparams: C:\Program Files\VERITAS\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id CLIENT-SERVER.domain.com_1234567890 -bpstart_to 300 -bpend_to 300 -backup_copy 0 -ru root -pt 41 -vm_type 2 -vm_client CLIENT-SERVER.domain.com -clnt HOST- sevrer -st FULL -rg other -fim Hyper-V_v2:allow_offline_backup=0,prov_type=2,csv_timeout=0,nameuse=0,Virtual_machine_backup=2,snap_attr=0,cluster_name=CLUSTER-name,nameuse=0 -class PolicyName -sched Tues -fso -S master-name.domain.com -jobid 31747 -nbu_version 124846080 -application_consistent 1
13:42:56.169 [19004.11768] <2> bpfis main: received FIM as [137] Hyper-V_v2:allow_offline_backup=0,prov_type=2,csv_timeout=0,nameuse=0,Virtual_machine_backup=2,snap_attr=0,cluster_name=CLUSTER-NAME,nameuse=0
13:42:56.169 [19004.11768] <4> bpfis: Starting keep alive thread.
13:42:56.169 [19004.11768] <4> bpfis: INF - BACKUP START 19004
13:42:56.169 [19004.11768] <2> bpfis main: receive filelist:<NEW_STREAM>
13:42:56.169 [19004.11768] <2> check_special_names: got path entry as :<NEW_STREAM>
13:42:56.169 [19004.11768] <2> check_special_names: after conversion returning :<NEW_STREAM>
13:42:56.169 [19004.11768] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
13:42:56.169 [19004.11768] <2> check_special_names: got path entry as :<ALL_LOCAL_DRIVES>
13:42:56.169 [19004.11768] <2> check_special_names: after conversion returning :<ALL_LOCAL_DRIVES>
13:42:56.169 [19004.11768] <2> bpfis main: receive filelist:<CONTINUE>
13:42:56.169 [19004.11768] <2> check_special_names: got path entry as :<CONTINUE>
13:42:56.169 [19004.11768] <2> check_special_names: after conversion returning :<CONTINUE>
13:42:56.200 [19004.11768] <2> vnet_pbxConnect: pbxConnectEx Succeeded
13:42:56.200 [19004.11768] <2> logconnections: BPRD CONNECT FROM 172.16.11.128.58924 TO 172.16.5.11.1556 fd = 696
13:42:59.638 [19004.11768] <8> bpfis: WRN - VfMS error 10; see following messages:
13:42:59.638 [19004.11768] <8> bpfis: WRN - Non-fatal method error was reported
13:42:59.638 [19004.11768] <8> bpfis: WRN -
13:42:59.638 [19004.11768] <8> bpfis: WRN - VfMS method error 0; see following message:
13:42:59.638 [19004.11768] <8> bpfis: WRN -
13:42:59.638 [19004.11768] <8> bpfis: WRN - VfMS error 10; see following messages:
13:42:59.638 [19004.11768] <8> bpfis: WRN - Non-fatal method error was reported
13:42:59.638 [19004.11768] <8> bpfis: WRN -
13:42:59.638 [19004.11768] <8> bpfis: WRN - VfMS method error 0; see following message:
13:42:59.638 [19004.11768] <8> bpfis: WRN -
13:42:59.653 [19004.11768] <4> bpfis: INF - FIS_ID=CLIENT-SERVER.domain.com_1234567890
13:42:59.653 [19004.11768] <4> bpfis: parameter client_type 41, fis_accl 0, fis_accl_cksv -1, SNAPSHOT_IS_HERE 1
13:42:59.653 [19004.11768] <4> bpfis: Volume guid list is empty, will not pause and flush NetBackup Change Journal databases
13:42:59.653 [19004.11768] <4> bpfis main: read_registry_dw_value for VSS_CONCURRENT_OPERATIONS: return status 2, return value 0
13:42:59.653 [19004.11768] <4> bpfis main: VSS Snapshot create Mutex lock acquired
13:42:59.653 [19004.11768] <4> bpfis: INF - Preparing freeze of ALL_LOCAL_DRIVES using snapshot method Hyper-V_v2.
13:42:59.653 [19004.11768] <4> bpfis: INF - Created mount point C:\Program Files\VERITAS\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_19004_1
13:44:13.265 [19004.11768] <32> bpfis: FTL - VfMS error 11; see following messages:
13:44:13.265 [19004.11768] <32> bpfis: FTL - Fatal method error was reported
13:44:13.265 [19004.11768] <32> bpfis: FTL - vfm_freeze_commit: method: Hyper-V_v2, type: FIM, function: Hyper-V_v2_make
13:44:13.265 [19004.11768] <32> bpfis: FTL - VfMS method error 38; see following message:
13:44:13.265 [19004.11768] <32> bpfis: FTL - snapshot services: snapshot creation failed: unknown error.
13:44:13.265 [19004.11768] <32> bpfis: FTL - VfMS error 11; see following messages:
13:44:13.265 [19004.11768] <32> bpfis: FTL - Fatal method error was reported
13:44:13.265 [19004.11768] <32> bpfis: FTL - vfm_freeze_commit: method: Hyper-V_v2, type: FIM, function: Hyper-V_v2_make
13:44:13.265 [19004.11768] <32> bpfis: FTL - VfMS method error 38; see following message:
13:44:13.265 [19004.11768] <32> bpfis: FTL - snapshot services: snapshot creation failed: unknown error.
13:44:13.265 [19004.11768] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method Hyper-V_v2.
13:44:13.265 [19004.11768] <4> bpfis: INF - do_thaw return value: 0
13:44:13.265 [19004.11768] <4> bpfis: INF - Deleted mount point C:\Program Files\VERITAS\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_19004_1
13:44:13.265 [19004.11768] <4> try_vss_unlockmutex: VSS Snapshot Mutex Unlock
13:44:13.265 [19004.11768] <16> bpfis: FTL - snapshot creation failed, status 156
13:44:13.265 [19004.11768] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method Hyper-V_v2.
13:44:13.265 [19004.11768] <8> bpfis: WRN - ALL_LOCAL_DRIVES is not frozen
13:44:13.265 [19004.11768] <8> bpfis: WRN - snapshot delete returned status 20
13:44:13.265 [19004.11768] <4> bpfis: INF - EXIT STATUS 156: snapshot error encountered
13:44:17.030 [19004.11768] <8> bpfis: WRN - set backup status returned status 156
13:44:17.030 [19004.11768] <4> bpfis: Starting keep alive thread.
13:44:17.046 [19004.11768] <32> bpfis: FTL - VfMS error 11; see following messages:
13:44:17.046 [19004.11768] <32> bpfis: FTL - Fatal method error was reported
13:44:17.046 [19004.11768] <32> bpfis: FTL - vfm_fi_terminate: method: VxFI, type: FIM, function: VxFI_detach
13:44:17.046 [19004.11768] <16> bpfis: Error -1 sending <vfm_fi_terminate: method: VxFI, type: FIM, function: VxFI_detach> to server
13:44:17.046 [19004.11768] <32> bpfis: FTL - VfMS method error 0; see following message:
13:44:17.046 [19004.11768] <32> bpfis: FTL - snapshot services: snapshot detach failed 1 times: invalid argument(s).
13:44:17.046 [19004.11768] <16> bpfis: Error -1 sending <snapshot services: snapshot detach failed 1 times: invalid argument(s).> to server
13:44:18.983 [8364.20448] <2> logparams: C:\Program Files\VERITAS\NetBackup\bin\bpfis.exe delete -nbu -id CLIENT-SERVER.domain.com_1234567890 -bpstart_to 300 -bpend_to 300 -clnt HOST- sevrer -jobgrpid 31747 -jobid 31747 -copy 1 -pt 41 -st FULL -status 156 -S master-name.domain.com -fim Hyper-V_v2:allow_offline_backup=0,prov_type=2,csv_timeout=0,nameuse=0,Virtual_machine_backup=2,snap_attr=0
13:44:18.983 [8364.20448] <2> bpfis main: received FIM as [106] Hyper-V_v2:allow_offline_backup=0,prov_type=2,csv_timeout=0,nameuse=0,Virtual_machine_backup=2,snap_attr=0
13:44:18.983 [8364.20448] <4> bpfis: Starting keep alive thread.
13:44:18.983 [8364.20448] <4> bpfis: Acquiring snapshot lock:retry count [0]
13:44:18.983 [8364.20448] <2> getFileName: FileName is [C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\CLIENT-SERVER.domain.com_1234567890_copy1.lock]
13:44:18.983 [8364.20448] <2> rw_lock: LockFileEx WRITELOCK
13:44:18.983 [8364.20448] <2> rw_lock: Lock acquired
13:44:18.999 [8364.20448] <2> vnet_pbxConnect: pbxConnectEx Succeeded
13:44:18.999 [8364.20448] <2> logconnections: BPRD CONNECT FROM 172.16.11.128.59077 TO 172.16.5.11.1556 fd = 716
13:44:19.609 [8364.20448] <4> bpfis: INF - BACKUP START 8364
13:44:19.609 [8364.20448] <4> bpfis main: read_registry_dw_value for VSS_CONCURRENT_OPERATIONS: return status 2, return value 0
13:44:19.609 [8364.20448] <4> bpfis main: VSS Snapshot Mutex lock acquired
13:44:19.609 [8364.20448] <8> bpfis: WRN - cannot open C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\bpfis.fim.CLIENT-SERVER.domain.com_1234567890.1.0
13:44:19.609 [8364.20448] <4> bpfis: INF - Attempt to send status to the bpfis create process
13:44:19.609 [8364.20448] <4> bpfis: Starting keep alive thread.
13:44:19.609 [8364.20448] <2> deleteReference: reference not found in the list
13:44:19.609 [8364.20448] <4> bpfis: Delete reference: status [-4]
13:44:19.609 [8364.20448] <2> writeSnapshotLockFile: Writing type[2] refcount[0]
13:44:19.609 [8364.20448] <2> writeSnapshotLockFile: Writing Flags [0] [0]
13:44:19.609 [8364.20448] <2> writeSnapshotLockFile: Writing Last addReffernt Time [Thu Jan 01 00:00:00 1970 ]
13:44:19.609 [8364.20448] <2> writeSnapshotLockFile: Writing Last Hostname []
13:44:19.609 [8364.20448] <2> getFileName: FileName is [C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\CLIENT-SERVER.domain.com_1234567890_copy1.lock]
13:44:19.609 [8364.20448] <2> unlockSnapshot: file[C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\CLIENT-SERVER.domain.com_1234567890_copy1.lock] : zero reference count
13:44:19.609 [8364.20448] <4> bpfis: Released snapshot lock: status [0]
13:44:20.624 [8364.20448] <4> bpfis: Starting keep alive thread.
13:44:20.624 [8364.20448] <2> deleteReference: Snapshot lock info NULL
13:44:20.624 [8364.20448] <4> bpfis: Delete reference: status [-4]
13:44:20.624 [8364.20448] <2> unlockSnapshot: Snapshot lock info NULL
13:44:20.624 [8364.20448] <4> bpfis: Released snapshot lock: status [0]
13:44:20.624 [8364.20448] <4> do_post_processing: Deleting snapshot lock files from client for id [CLIENT-SERVER.domain.com_1234567890] and copy_number [1]
13:44:20.624 [8364.20448] <2> getFileName: FileName is [C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\CLIENT-SERVER.domain.com_1234567890_copy1.lock]
13:44:20.624 [8364.20448] <2> deleteSnapshotLockFile: Renamed lock file from [C:\Program Files\VERITAS\NetBackup\online_util\fi_cntl\CLIENT-SERVER.domain.com_1234567890_copy1.lock] to [\s85c.] for deletion
13:44:20.624 [8364.20448] <2> deleteSnapshotLockFile: File[\s85c.] deleted: status[0]
13:44:20.624 [8364.20448] <4> bpfis: INF - EXIT STATUS 4207: Could not fetch snapshot metadata or state files
13:44:20.624 [8364.20448] <4> try_vss_unlockmutex: VSS Snapshot Mutex Unlock

Client Event log:

A VSS writer has rejected an event with error 0x800423f4, The writer experienced a non-transient error.  If the backup process is retried,
the error is likely to reoccur.
. Changes that the writer made to the writer components while handling the event will not be available to the requester. Check the event log for related events from the application hosting the VSS writer.

Operation:
   PostSnapshot Event

Context:
   Execution Context: Writer
   Writer Class Id: {dd846aaa-a1b6-42a8-aaf8-03dcb6114bfd}
   Writer Name: ADAM (domainADAMForApplications) Writer
   Writer Instance ID: {fda4f753-93a8-4ff0-8be2-27cc85c657e8}
   Command Line: C:\Windows\System32\dsamain.exe -sn:DomainADAMForApplications
   Process ID: 9816

The VSS writer ADAM (DomainADAMForApplications) Writer failed with status 11 and writer specific failure code 0x800423F4.

Host event logs.

A VSS writer has rejected an event with error 0x800423f4, The writer experienced a non-transient error.  If the backup process is retried,
the error is likely to reoccur.
. Changes that the writer made to the writer components while handling the event will not be available to the requester. Check the event log for related events from the application hosting the VSS writer.

Operation:
   PrepareForSnapshot Event

Context:
   Execution Context: Writer
   Writer Class Id: {66841cd4-6ded-4f4b-8f17-fd23f8ddc3de}
   Writer Name: Microsoft Hyper-V VSS Writer
   Writer Instance ID: {ebc77ed4-b777-46dd-b628-420ccefb9f06}
   Command Line: C:\WINDOWS\system32\vmms.exe
   Process ID: 3748

I move the VM to new host and runn following commands

vssadmin list writers (all writers had no errors) but when i run the backup and it failed and wont back to host and re-run the vssadmin list writers i can see the vss was in failed state.

Writer name: 'Microsoft Hyper-V VSS Writer'
   Writer Id: {66841cd4-6ded-4f4b-8f17-fd23f8ddc3de}
   Writer Instance Id: {ebc77ed4-b777-46dd-b628-420ccefb9f06}
   State: [8] Failed
   Last error: Non-retryable error

Thiago_Ribeiro
Moderator
Moderator
Partner    VIP    Accredited

Hi,

Please check this link:

https://vox.veritas.com/t5/NetBackup/Hyper-V-backup-fails-156-1542/m-p/568204#M139068

The problem that was reported is very similar to your.

 

Thiago

already try that. all of the patchs applied

Thiago_Ribeiro
Moderator
Moderator
Partner    VIP    Accredited

Hi,

Ok you already applied these MS KBs..So, I see this tech please check it

https://www.veritas.com/support/en_US/article.000024036

 

Already check that and server does have SCSI Controller

Thiago_Ribeiro
Moderator
Moderator
Partner    VIP    Accredited

Hi,

I foud two articles:


Veritas = https://www.veritas.com/support/en_US/article.000019515

Microsoft = https://social.technet.microsoft.com/Forums/windowsserver/en-US/a176574e-858a-4715-80f7-3609bb4d6d71...

Both are about Hyper-V problems, but the MS is about some errors from VSS, and I saw that you posted vss list writers and Microsoft Hyper-V VSS Writer was with status failed.

I hope that some of them help you.


Thiago

Hi Thiago,

When I check the VSS writers on the Hyper-v Host they all look OK but when i try to take the backup of the client it failes

  • Hyper-v Host is running windows 2012 R2
  • Client is running Winows 2008 R2

I have move the client on to different host but it still failing with backup. this is the only client which fails.