guidance needed for vmware snapshot errors with netbackup

[kabacsk]

Dear All,

Enviroment
Netbackup 7.5.04. master server
policy type vmware,nbd transport,data deduplicated to vnxstorages at two diff location.(far location also has nbms)
policy setup all optimization checkbox is set. Quiesced is on.

problem
Backup is two windows file server 2008 standard. They have one boot disk which is small 30-60GB sized other is bigger 1-1,5Terra with independent disk setup in vmware.Both windows servers are virtual on

vmware 4.1.
I vmware snapshot backup them but while it snapshots after 5-10 minutes I have 156 error code on master server acmonitor.

What I found:

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

https://kb.vmware.com/selfservice/microsites/searc...

In the second link I found a line possible reason for 156 error.

This is an expected behavior, virtual machines with Independent disks cannot use memory or quiesced snapshots.

Backup setup uses quiesced snapshot but looks that independent disk do not support that? I do not off quiesced because that cause integrity issues for restores. What I wanted to reach to make a snapshot

backup of boot drive exclude data drive. Besides with ms-windows policy backup all data on data drives. If I have to restore I restore vmdk file of boot and then restore all data on drive D with ms-windows

policy. I also checked vmware tools version what could possilbe other reason. But I have other virtal server with same vmware tools versions. I am bit cluless.Other vmware backup works like charms only these

two independent disk backups has this issue.

Any help would be good.

[kabacsk]

log information

00:34:15.108 [3020.6320] <32> get_bpfis_msg: from client HERCULES.domaina.int.net: FTL - cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.HERCULES.domaina.int.net_1464388032.1.0
00:34:15.264 [3020.6320] <2> bpbrm Exit: client backup EXIT STATUS 1542: An existing snapshot is no longer valid and cannot be mounted for subsequent operations
00:42:08.084 [7080.7216] <32> get_bpfis_msg: from client dorus.domaina.int.net: FTL - VMware snapshot failed: SYM_VMC_TASK_REACHED_ERROR_STATE
00:42:08.099 [7080.7216] <32> get_bpfis_msg: from client dorus.domaina.int.net: FTL - VMware error received: Cannot create a quiesced snapshot because the create snapshot operation exceeded the time limit

for holding off I/O in the frozen virtual machine.
00:42:08.333 [7080.7216] <32> get_bpfis_msg: from client dorus.domaina.int.net: FTL - snapshot creation failed, status 156
------------------------------------------------------------

00:10:02.904 [6556.1564] <2> bpfis main: received FIM as [182]

VMware_v2:Virtual_machine_backup=2,nameuse=3,snapact=2,file_system_optimization=1,trantype=nbd,exclude_swap=1
,disable_quiesce=0,drive_selection=2,skipnodisk=0,post_events=1,nameuse=3
00:10:02.951 [6556.1564] <4> bpfis: Starting keep alive thread.
00:10:02.951 [6556.1564] <4> bpfis: INF - BACKUP START 6556
00:10:02.951 [6556.1564] <2> bpfis main: receive filelist:<NEW_STREAM>
00:10:02.951 [6556.1564] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
00:10:02.951 [6556.1564] <2> bpfis main: receive filelist:<CONTINUE>
00:10:03.154 [6556.1564] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59747 TO 172.30.224.84.13720 fd = 584
00:10:03.154 [6556.1564] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:03.294 [6556.1564] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59752 TO 172.30.224.84.13720 fd = 600
00:10:03.294 [6556.1564] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:03.372 [6148.6684] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe deletedb -noserverstate -policy VMBCK_FILE_SERVER -clnt
chronos.domaina.int.net -vm_client dorus.domaina.int.net -copy

1 -vm_bli_cleanup
00:10:03.372 [6148.6684] <4> bpfis: set vm client dorus.domaina.int.net as ol_client_name
00:10:03.372 [6148.6684] <4> bpfis: Starting keep alive thread.
00:10:03.403 [6148.6684] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59761 TO 172.30.224.84.13720 fd = 568
00:10:03.403 [6148.6684] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:03.466 [6148.6684] <4> bpfis: INF - BACKUP START 6148
00:10:03.466 [6148.6684] <4> bpfis: Starting keep alive thread.
00:10:03.466 [6148.6684] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed
00:10:03.637 [6556.1564] <8> bpfis: WRN - VfMS error 10; see following messages:
00:10:03.637 [6556.1564] <8> bpfis: WRN - Non-fatal method error was reported
00:10:03.637 [6556.1564] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init
00:10:03.637 [6556.1564] <8> bpfis: WRN - VfMS method error 3; see following message:
00:10:03.637 [6556.1564] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.
00:10:03.653 [6556.1564] <8> bpfis: WRN - VfMS error 10; see following messages:
00:10:03.653 [6556.1564] <8> bpfis: WRN - Non-fatal method error was reported
00:10:03.653 [6556.1564] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init
00:10:03.653 [6556.1564] <8> bpfis: WRN - VfMS method error 3; see following message:
00:10:03.653 [6556.1564] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.
00:10:03.965 [6508.6560] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id dorus.domaina.int.net_1464387002 -bpstart_to 300
-bpend_to 300 -backup_copy 0 -ru root -pt

40 -vm_type 2 -vm_client dorus.domaina.int.net -clnt chronos.domaina.int.net -st FULL -block_incr -prev_bli_incr 0 -last_bli_full 0 -dt 0 -rg root -fim

VMware_v2:Virtual_machine_backup=2,nameuse=3,snapact=2,file_system_optimization=1,trantype=nbd,exclude_swap=1,disable_quiesce=0,drive_selection=2,
skipnodisk=0,post_events=1,nameuse=3 -class VMBCK_FILE_SERVER

-sched Weekly_Full -fso -S chronos.domaina.int.net -jobid 439454
00:10:03.965 [6508.6560] <2> bpfis main: received FIM as [182]

VMware_v2:Virtual_machine_backup=2,nameuse=3,snapact=2,file_system_optimization=1,trantype=nbd,exclude_swap=1,disable_quiesce=0,
drive_selection=2,skipnodisk=0,post_events=1,nameuse=3
00:10:03.965 [6508.6560] <4> bpfis: Starting keep alive thread.
00:10:03.965 [6508.6560] <4> bpfis: INF - BACKUP START 6508
00:10:03.965 [6508.6560] <2> bpfis main: receive filelist:<NEW_STREAM>
00:10:03.965 [6508.6560] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
00:10:03.965 [6508.6560] <2> bpfis main: receive filelist:<CONTINUE>
00:10:03.965 [6556.1564] <4> bpfis: INF - FIS_ID=ISAURA.domaina.int.net_1464387000
00:10:03.965 [6556.1564] <4> bpfis: Failed to open flush NetBackup Change Journal databases mutex
00:10:03.965 [6556.1564] <4> bpfis: INF - Freezing ALL_LOCAL_DRIVES using snapshot method VMware_v2.
00:10:03.965 [6556.1564] <4> bpfis: INF - ACT=ISAURA.domaina.int.net
00:10:03.965 [6556.1564] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_6556_1
00:10:03.965 [6556.1564] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59773 TO 172.30.224.84.13720 fd = 620
00:10:03.965 [6556.1564] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:04.012 [6556.1564] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59774 TO 172.30.224.84.13720 fd = 616
00:10:04.012 [6556.1564] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:04.136 [6556.1564] <2> get_VM_names_VMware: get_VM_names_VMware: read for scarabeus.domaina.int.net
00:10:04.246 [1212.4828] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe deletedb -noserverstate -policy
VMBCK_FILE_SERVER -clnt chronos.domaina.int.net -vm_client HERCULES.domaina.int.net -

copy 1 -vm_bli_cleanup
00:10:04.246 [1212.4828] <4> bpfis: set vm client HERCULES.domaina.int.net as ol_client_name
00:10:04.246 [1212.4828] <4> bpfis: Starting keep alive thread.
00:10:04.261 [1212.4828] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59779 TO 172.30.224.84.13720 fd = 568
00:10:04.261 [1212.4828] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:04.292 [1212.4828] <4> bpfis: INF - BACKUP START 1212
00:10:04.292 [1212.4828] <4> bpfis: Starting keep alive thread.
00:10:04.292 [1212.4828] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed
00:10:04.838 [588.6344] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id HERCULES.domaina.int.net_1464387003 -bpstart_to 300 -bpend_to 300 -backup_copy 0 -ru root -

pt 40 -vm_type 2 -vm_client HERCULES.domaina.int.net -clnt chronos.domaina.int.net -st FULL -block_incr -prev_bli_incr 0 -last_bli_full 0 -dt 0 -rg root -fim

VMware_v2:Virtual_machine_backup=2,nameuse=3,snapact=2,file_system_optimization=1,trantype=nbd,exclude_swap=1,
disable_quiesce=0,drive_selection=2,skipnodisk=0,post_events=1,nameuse=3 -class VMBCK_FILE_SERVER

-sched Weekly_Full -fso -S chronos.domaina.int.net -jobid 439455
00:10:04.838 [588.6344] <2> bpfis main: received FIM as [182]

VMware_v2:Virtual_machine_backup=2,nameuse=3,snapact=2,file_system_optimization=1,trantype=nbd,exclude_swap=1
,disable_quiesce=0,drive_selection=2,skipnodisk=0,post_events=1,nameuse=3
00:10:04.838 [588.6344] <4> bpfis: Starting keep alive thread.
00:10:04.838 [588.6344] <4> bpfis: INF - BACKUP START 588
00:10:04.838 [588.6344] <2> bpfis main: receive filelist:<NEW_STREAM>
00:10:04.838 [588.6344] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
00:10:04.838 [588.6344] <2> bpfis main: receive filelist:<CONTINUE>
00:10:17.568 [588.6344] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59806 TO 172.30.224.84.13720 fd = 592
00:10:17.568 [6508.6560] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59807 TO 172.30.224.84.13720 fd = 596
00:10:17.568 [588.6344] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.568 [6508.6560] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.646 [6508.6560] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59816 TO 172.30.224.84.13720 fd = 596
00:10:17.646 [6508.6560] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.646 [588.6344] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59817 TO 172.30.224.84.13720 fd = 608
00:10:17.646 [588.6344] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.834 [6508.6560] <8> bpfis: WRN - VfMS error 10; see following messages:
00:10:17.834 [6508.6560] <8> bpfis: WRN - Non-fatal method error was reported
00:10:17.834 [6508.6560] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init
00:10:17.834 [6508.6560] <8> bpfis: WRN - VfMS method error 3; see following message:
00:10:17.834 [6508.6560] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.
00:10:17.834 [6508.6560] <8> bpfis: WRN - VfMS error 10; see following messages:
00:10:17.834 [6508.6560] <8> bpfis: WRN - Non-fatal method error was reported
00:10:17.834 [6508.6560] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init
00:10:17.834 [6508.6560] <8> bpfis: WRN - VfMS method error 3; see following message:
00:10:17.834 [6508.6560] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.
00:10:17.834 [6508.6560] <4> bpfis: INF - FIS_ID=dorus.domaina.int.net_1464387002
00:10:17.834 [6508.6560] <4> bpfis: Failed to open flush NetBackup Change Journal databases mutex
00:10:17.834 [6508.6560] <4> bpfis: INF - Freezing ALL_LOCAL_DRIVES using snapshot method VMware_v2.
00:10:17.834 [6508.6560] <4> bpfis: INF - ACT=dorus.domaina.int.net
00:10:17.834 [6508.6560] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_6508_1
00:10:17.834 [6508.6560] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59832 TO 172.30.224.84.13720 fd = 632
00:10:17.834 [6508.6560] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.849 [588.6344] <8> bpfis: WRN - VfMS error 10; see following messages:
00:10:17.849 [588.6344] <8> bpfis: WRN - Non-fatal method error was reported
00:10:17.849 [588.6344] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init
00:10:17.849 [588.6344] <8> bpfis: WRN - VfMS method error 3; see following message:
00:10:17.849 [588.6344] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.
00:10:17.849 [588.6344] <8> bpfis: WRN - VfMS error 10; see following messages:
00:10:17.849 [588.6344] <8> bpfis: WRN - Non-fatal method error was reported
00:10:17.849 [588.6344] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init
00:10:17.849 [588.6344] <8> bpfis: WRN - VfMS method error 3; see following message:
00:10:17.849 [588.6344] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.
00:10:17.849 [588.6344] <4> bpfis: INF - FIS_ID=HERCULES.domaina.int.net_1464387003
00:10:17.849 [588.6344] <4> bpfis: Failed to open flush NetBackup Change Journal databases mutex
00:10:17.849 [588.6344] <4> bpfis: INF - Freezing ALL_LOCAL_DRIVES using snapshot method VMware_v2.
00:10:17.849 [588.6344] <4> bpfis: INF - ACT=HERCULES.domaina.int.net
00:10:17.849 [588.6344] <4> bpfis: INF - Created mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_588_1
00:10:17.865 [588.6344] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59833 TO 172.30.224.84.13720 fd = 628
00:10:17.865 [588.6344] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.880 [6508.6560] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59834 TO 172.30.224.84.13720 fd = 632
00:10:17.880 [6508.6560] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.896 [588.6344] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59835 TO 172.30.224.84.13720 fd = 624
00:10:17.896 [588.6344] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:10:17.958 [6508.6560] <2> get_VM_names_VMware: get_VM_names_VMware: read for scarabeus.domaina.int.net
00:10:17.974 [588.6344] <2> get_VM_names_VMware: get_VM_names_VMware: read for scarabeus.domaina.int.net
00:11:03.371 [6556.1564] <4> bpfis: INF - Deleted mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_6556_1
00:11:03.371 [6556.1564] <4> bpfis: INF - REMAP FILE BACKUP NEW_STREAM
00:11:03.371 [6556.1564] <4> bpfis: INF - REMAP FILE BACKUP FIS_VM_BI_ATTRS_FILE=\online_util\fi_cntl\bpfis.fim.ISAURA.domaina.int.net_1464387000.1.0.NBU_DATA.xml
00:11:03.371 [6556.1564] <4> bpfis: INF - REMAP FILE BACKUP \\.\C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.ISAURA.domaina.int.net_1464387000.1.0.NBU_DATA.xml USING \\.\C:\

OPTIONS:FITYPE=MIRROR,FSTYPE=NTFS
00:11:03.371 [6556.1564] <2> getFileName:  FileName is [C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\ISAURA.domaina.int.net_1464387000_copy1.lock]
00:11:03.371 [6556.1564] <2> getFileName:  FileName is [C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\ISAURA.domaina.int.net_1464387000_copy1.lock]
00:11:03.371 [6556.1564] <2> addSnapshotReference: SnapShot Locked <ISAURA.domaina.int.net_1464387000>
00:11:03.371 [6556.1564] <2> addReference:    Added  refferent jobid[439453] pid[6556]
00:11:03.371 [6556.1564] <2> writeSnapshotLockFile:    Writing type[0] refcount[1]
00:11:03.371 [6556.1564] <2> writeSnapshotLockFile:    Writing Flags [0] [0]
00:11:03.371 [6556.1564] <2> writeSnapshotLockFile:   Writing Last addReffernt Time [Thu Jan 01 01:00:00 1970
]
00:11:03.371 [6556.1564] <2> writeSnapshotLockFile:   Writing Last Hostname []
00:11:03.371 [6556.1564] <2> writeSnapshotLockFile:    Writing jobid[439453] pid [6556]
00:11:03.387 [6556.1564] <2> addSnapshotReference: SnapShot unlockLocked <ISAURA.domaina.int.net_1464387000>
00:11:03.481 [6556.1564] <4> bpfis: Starting keep alive thread.
00:11:03.481 [6556.1564] <2> logconnections: BPRD CONNECT FROM 172.30.224.84.59861 TO 172.30.224.84.13720 fd = 572
00:11:03.481 [6556.1564] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
00:11:04.152 [6556.1564] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed
00:17:10.124 [588.6344] <4> bpfis: INF - Deleted mount point C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_588_1
00:17:10.124 [588.6344] <32> bpfis: FTL - VfMS error 11; see following messages:
00:17:10.124 [588.6344] <32> bpfis: FTL - Fatal method error was reported
00:17:10.124 [588.6344] <32> bpfis: FTL - vfm_freeze: method: VMware_v2, type: FIM, function: VMware_v2_freeze
00:17:10.124 [588.6344] <32> bpfis: FTL - VfMS method error 7; see following message:
00:17:10.124 [588.6344] <32> bpfis: FTL - VMware_freeze: VIXAPI freeze failed with 36
00:17:10.124 [588.6344] <32> bpfis: FTL - VfMS error 11; see following messages:
00:17:10.124 [588.6344] <32> bpfis: FTL - Fatal method error was reported
00:17:10.124 [588.6344] <32> bpfis: FTL - vfm_freeze: method: VMware_v2, type: FIM, function: VMware_v2_freeze
00:17:10.124 [588.6344] <32> bpfis: FTL - VfMS method error 7; see following message:
00:17:10.124 [588.6344] <32> bpfis: FTL - VMware_freeze: VIXAPI freeze failed with 36
00:17:10.124 [588.6344] <16> bpfis: FTL - snapshot creation failed, status 156
00:17:10.170 [588.6344] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method VMware_v2.
00:17:10.170 [588.6344] <8> bpfis: WRN - ALL_LOCAL_DRIVES is not frozen
00:17:10.170 [588.6344] <8> bpfis: WRN - snapshot delete returned status 20
00:17:10.233 [588.6344] <4> bpfis: Starting keep alive thread.
00:17:10.233 [588.6344] <4> bpfis: INF - EXIT STATUS 156: snapshot error encountered
00:17:11.902 [472.568] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpfis.exe delete -nbu -id HERCULES.domaina.int.net_1464387003 -bpstart_to 300 -bpend_to 300 -clnt chronos.domaina.int.net -status

156 -S chronos.domaina.int.net -noserverstate -jobid 439455 -copy 1 -fim