This issue has been solved.

Netbackup 6.5.4 to 7.0 VMware backups fail

Created: 05 May 2010 • Updated: 10 Jun 2010
Login to vote
0 0 Votes

Hello all,

I recently upgraded from Netbackup 6.5.4 to 7.0,I have a seperate Master and Media server.Media server is my offhost backup running vcb 1.5,everything worked sweet in 6.5.4.Now when the exact same policy tried to run under 7.0 it fails with the 156 snapshot error.nothing else has changed besides netbackup version.If I change the options inside the policy to file level backup using vcb that works however the fullvm backup is the one I want to work but fails with the above error.Logs provided
bpfis:
Sorry Long!
16:43:59.937 [3312.2648] <2> logparams: D:\Program Files\Veritas\NetBackup\bin\bpfis.exe create -nbu -owner NBU -id vmcolour.uk.conde-nast.biz_1273074233 -bpstart_to 300 -bpend_to 300 -backup_copy 0 -ru root -pt 29 -vm_type 1 -vm_client vmcolour.uk.conde-nast.biz -clnt vh-dpm -st FULL -rg other -fim VMware:nameuse=0,Virtual_machine_backup=1,trantype=6,disable_quiesce=0,file_system_optimization=1,snapact=0,vmmono=1,mntpt=d:\vmmounts,nameuse=0 -class ESXBackups -sched Weekly -fso -S vbackup
16:43:59.937 [3312.2648] <2> bpfis main: received FIM as [144] VMware:nameuse=0,Virtual_machine_backup=1,trantype=6,disable_quiesce=0,file_system_optimization=1,snapact=0,vmmono=1,mntpt=d:\vmmounts,nameuse=0
16:43:59.937 [3312.2648] <4> bpfis: INF - BACKUP START 3312
16:43:59.937 [3312.2648] <2> bpfis main: receive filelist:<NEW_STREAM>
16:43:59.937 [3312.2648] <2> bpfis main: receive filelist:<ALL_LOCAL_DRIVES>
16:44:00.156 [3312.2648] <2> bpfis main: receive filelist:<CONTINUE>
16:44:00.203 [3312.2648] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
16:44:00.203 [3312.2648] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
16:44:00.422 [3312.2648] <2> logconnections: BPRD CONNECT FROM 172.16.10.223.1746 TO 172.16.10.64.13724
16:44:02.547 [3312.2648] <2> get_long: (2) premature end of file (byte 1)
16:44:02.547 [3312.2648] <2> bprd_read_text_file: get_string() failed, Access is denied.  (5), premature end of file encountered
16:44:02.547 [3312.2648] <8> bpfis: WRN - VfMS error 10; see following messages:
16:44:02.547 [3312.2648] <8> bpfis: WRN - Non-fatal method error was reported
16:44:02.547 [3312.2648] <8> bpfis: WRN - vfm_configure_fi_one: method: FlashSnap, type: FIM, function: FlashSnap_init
16:44:02.547 [3312.2648] <8> bpfis: WRN - VfMS method error 3; see following message:
16:44:02.547 [3312.2648] <8> bpfis: WRN - FlashSnap_init: Veritas Volume Manager not installed.
16:44:02.547 [3312.2648] <8> bpfis: WRN - VfMS error 10; see following messages:
16:44:02.547 [3312.2648] <8> bpfis: WRN - Non-fatal method error was reported
16:44:02.547 [3312.2648] <8> bpfis: WRN - vfm_configure_fi_one: method: vxvm, type: FIM, function: vxvm_init
16:44:02.547 [3312.2648] <8> bpfis: WRN - VfMS method error 3; see following message:
16:44:02.547 [3312.2648] <8> bpfis: WRN - vxvm_init: Veritas Volume Manager not installed.
16:44:02.562 [3312.2648] <4> bpfis: INF - FIS_ID=vmcolour.uk.conde-nast.biz_1273074233
16:44:02.562 [3312.2648] <4> bpfis: INF - Freezing ALL_LOCAL_DRIVES using snapshot method VMware.
16:44:02.562 [3312.2648] <4> bpfis: INF - ACT=vmcolour.uk.conde-nast.biz
16:44:02.562 [3312.2648] <4> bpfis: INF - Created mount point D:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_3312
16:44:02.593 [3312.2648] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
16:44:02.593 [3312.2648] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
16:44:02.718 [3312.2648] <2> logconnections: BPRD CONNECT FROM 172.16.10.223.1747 TO 172.16.10.64.13724
16:44:05.453 [3312.2648] <4> bpfis: INF - Deleted mount point D:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_ALL_LOCAL_DRIVES_3312
16:44:05.453 [3312.2648] <32> bpfis: FTL - VfMS error 11; see following messages:
16:44:05.453 [3312.2648] <32> bpfis: FTL - Fatal method error was reported
16:44:05.453 [3312.2648] <32> bpfis: FTL - vfm_freeze: method: VMware, type: FIM, function: VMware_freeze
16:44:05.453 [3312.2648] <32> bpfis: FTL - VfMS method error 7; see following message:
16:44:05.453 [3312.2648] <32> bpfis: FTL - VMware_freeze: VIXAPI freeze failed unknown client vmcolour.uk.conde-nast.biz
16:44:05.453 [3312.2648] <32> bpfis: FTL - VfMS error 11; see following messages:
16:44:05.453 [3312.2648] <32> bpfis: FTL - Fatal method error was reported
16:44:05.453 [3312.2648] <32> bpfis: FTL - vfm_freeze: method: VMware, type: FIM, function: VMware_freeze
16:44:05.453 [3312.2648] <32> bpfis: FTL - VfMS method error 7; see following message:
16:44:05.453 [3312.2648] <32> bpfis: FTL - VMware_freeze: VIXAPI freeze failed unknown client vmcolour.uk.conde-nast.biz
16:44:05.453 [3312.2648] <16> bpfis: FTL - snapshot creation failed, status 156
16:44:05.453 [3312.2648] <4> bpfis: INF - Thawing ALL_LOCAL_DRIVES using snapshot method VMware.
16:44:05.453 [3312.2648] <8> bpfis: WRN - ALL_LOCAL_DRIVES is not frozen
16:44:05.453 [3312.2648] <8> bpfis: WRN - snapshot delete returned status 20
16:44:05.484 [3312.2648] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
16:44:05.484 [3312.2648] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
16:44:05.672 [3312.2648] <2> logconnections: BPRD CONNECT FROM 172.16.10.223.1750 TO 172.16.10.64.13724
16:44:06.984 [3312.2648] <4> bpfis: INF - EXIT STATUS 156: snapshot error encountered
16:44:16.469 [1936.2652] <2> logparams: D:\Program Files\Veritas\NetBackup\bin\bpfis.exe delete -nbu -id vmcolour.uk.conde-nast.biz_1273074233 -bpstart_to 300 -bpend_to 300 -clnt vh-dpm -S vbackup
16:44:16.516 [1936.2652] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
16:44:16.516 [1936.2652] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
16:44:16.719 [1936.2652] <2> logconnections: BPRD CONNECT FROM 172.16.10.223.1760 TO 172.16.10.64.13724
16:44:17.703 [1936.2652] <4> bpfis: INF - BACKUP START 1936
16:44:17.703 [1936.2652] <32> bpfis: FTL - cannot open D:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.vmcolour.uk.conde-nast.biz_1273074233.0
16:44:17.750 [1936.2652] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
16:44:17.750 [1936.2652] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bprd
16:44:17.922 [1936.2652] <2> logconnections: BPRD CONNECT FROM 172.16.10.223.1763 TO 172.16.10.64.13724
16:44:18.906 [1936.2652] <4> bpfis: INF - EXIT STATUS 0: the requested operation was successfully completed
Then in job error :

05/05/2010 16:43:03 - requesting resource LTO4
05/05/2010 16:43:03 - requesting resource vbackup.NBU_CLIENT.MAXJOBS.vmcolour.uk.conde-nast.biz
05/05/2010 16:43:03 - requesting resource vbackup.NBU_POLICY.MAXJOBS.ESXBackups
05/05/2010 16:43:03 - granted resource vbackup.NBU_CLIENT.MAXJOBS.vmcolour.uk.conde-nast.biz
05/05/2010 16:43:03 - granted resource vbackup.NBU_POLICY.MAXJOBS.ESXBackups
05/05/2010 16:43:03 - granted resource 0012L4
05/05/2010 16:43:03 - granted resource IBM.ULTRIUM-TD4.001
05/05/2010 16:43:03 - granted resource LTO4
05/05/2010 16:43:03 - estimated 28477881 Kbytes needed
05/05/2010 16:43:03 - begin Parent Job
05/05/2010 16:43:03 - begin Flash Backup Windows, Start Notify Script
05/05/2010 16:43:03 - started process RUNCMD (7156)
05/05/2010 16:43:03 - ended process 0 (7156)
Status 0
05/05/2010 16:43:03 - end Flash Backup Windows, Start Notify Script; elapsed time: 00:00:00
05/05/2010 16:43:03 - begin Flash Backup Windows, Step By Condition
Status 0
05/05/2010 16:43:03 - end Flash Backup Windows, Step By Condition; elapsed time: 00:00:00
05/05/2010 16:43:03 - begin Flash Backup Windows, Read File List
Status 0
05/05/2010 16:43:03 - end Flash Backup Windows, Read File List; elapsed time: 00:00:00
05/05/2010 16:43:03 - begin Flash Backup Windows, Create Snapshot
05/05/2010 16:43:03 - started process bpbrm (7004)
05/05/2010 16:43:03 - started
05/05/2010 16:43:08 - begin Create Snapshot
05/05/2010 16:43:12 - snapshot backup of client vmcolour.uk.conde-nast.biz using method VMware
05/05/2010 16:43:15 - Critical bpbrm(pid=7004) from client vmcolour.uk.conde-nast.biz: FTL - snapshot creation failed, status 156  
05/05/2010 16:43:15 - Warning bpbrm(pid=7004) from client vmcolour.uk.conde-nast.biz: WRN - ALL_LOCAL_DRIVES is not frozen   
05/05/2010 16:43:17 - end Create Snapshot; elapsed time: 00:00:09
05/05/2010 16:43:21 - end writing
Status 156
05/05/2010 16:43:21 - end Flash Backup Windows, Create Snapshot; elapsed time: 00:00:18
05/05/2010 16:43:21 - begin Flash Backup Windows, Stop On Error
Status 0
05/05/2010 16:43:21 - end Flash Backup Windows, Stop On Error; elapsed time: 00:00:00
05/05/2010 16:43:21 - begin Flash Backup Windows, Delete Snapshot On Exit
05/05/2010 16:43:21 - begin Flash Backup Windows, Delete Snapshot On Exit
05/05/2010 16:43:21 - started process bpbrm (4672)
05/05/2010 16:43:30 - end writing
Status 0
05/05/2010 16:43:30 - end Flash Backup Windows, Delete Snapshot On Exit; elapsed time: 00:00:09
05/05/2010 16:43:30 - begin Flash Backup Windows, End Notify Script
05/05/2010 16:43:31 - started process RUNCMD (7160)
05/05/2010 16:43:31 - ended process 0 (7160)
Status 0
05/05/2010 16:43:31 - end Flash Backup Windows, End Notify Script; elapsed time: 00:00:01
Status 156
05/05/2010 16:43:31 - end Flash Backup Windows, Delete Snapshot On Exit; elapsed time: 00:00:10
snapshot error encountered(156)

The luns are definately exposed,credentials correct,re-entered and double checked.Using the filelevel backup with vcb I can see virtual centre snapping the VM,however on the fullvm backup no activity is shown in VC.Am I missing a component that netbackup has taken over from vcb with the new API's?Hope someone canhelp and thanks for reading!.

Quick Look Solution

Resolved required the

Resolved required the netbackup 7.0 Hotfix from support .after it was applied it resolved the issue,its 35mb if anyone wants it.
gg>win

Filed Under

Comments

05
May
2010

I'm running into the same

I'm running into the same issue. :-(

If I find anything, I'll post it.

05
May
2010

I'm facing this error too.

I'm facing this error too. "snapshot creation failed, status 156  ALL_LOCAL_DRIVES is not frozen".  This error randomly occurs on several VMs [1-4] , I'm backing up 14VMs now.

https://www-secure.symantec.com/connect/forums/nbu...

rj_nbu
Symantec Employee
Certified
06
May
2010

try this

HI,

it appears that the API is not able to locate the VM

<32> bpfis: FTL - VMware_freeze: VIXAPI freeze failed unknown client vmcolour.uk.conde-nast.biz

Delete the client from the policy, browse and add it again

-Rajeev
"Unix IS user friendly... It's just selective about who its friends are"

06
May
2010

Hello all, Thanks for the

Hello all,

Thanks for the replies,I have just tried the remove the client and re-add it to the policy after using the refresh as well,unfortunately it has not solved the issue.I tried adding an entry into the hosts file as well with no luck.Any other ideas?

07
May
2010

anything>?

anything>?

07
May
2010
SOLUTION

Resolved required the

Resolved required the netbackup 7.0 Hotfix from support .after it was applied it resolved the issue,its 35mb if anyone wants it.
gg>win

Marianne
Trusted Advisor
Accredited
Certified
07
May
2010

Thanks for sharing this info!

Thanks for sharing this info! Hopefully Symantec will publish a TechNote?

Supporting Storage Foundation and VCS on Unix and Windows as well as NetBackup on Unix and Windows
Handy NBU Links

SgtPepper
Symantec Employee
10
May
2010

TechNote regarding this issue


DOCUMENTATION: Issues resolved in the bundle for VMware backups included in Etrack 1976029