Backup Vmware Fail wint error 11

[Arturo_Lopez]

Hi everybody,

I have a problem with a Vmware Backup. The Netbackup version is 7.5.0.1 and uses a Host Backup as media server. The host Backup it's connect with a Vcenter where are all Vmwware's.

Ok, the problem is next, I launch a backup with a Vmware Policy and the backup launched ok but the backup return the next error

10/09/2013 14:15:46 - Error bpbrm (pid=864) from client mvicapsvr030p11%20(PSSOBEIDP1): ERR - Read of VM file read 0 bytes, should have read 131072 bytes
10/09/2013 14:15:47 - Error bptm (pid=1234) system call failed - Connection reset by peer (at child.c.1298)
10/09/2013 14:15:47 - Error bptm (pid=1234) unable to perform read from client socket, connection may have been broken
10/09/2013 14:15:48 - Error bptm (pid=1176) media manager terminated by parent process
10/09/2013 14:15:52 - Error bpbrm (pid=864) could not send server status message
10/09/2013 14:15:53 - Critical bpbrm (pid=864) unexpected termination of client mvicapsvr030p11%20(PSSOBEIDP1)
10/09/2013 14:15:53 - Info bpbkar (pid=0) done. status: 11: system call failed

And I don't understand this error because the backup write 120,20 GB and suddenly fail. The rest of machines configured in the same datastore do the backups Ok.

The Vmware policy it's configure:

Transport mode -> nbd

Optimizations -> Enable file recovery from VM backup, Exclude deleted blocks, Exclude swap and paging files.

Any solution?

[Yasuhisa_Ishika]

For the first, check relevant logs like bpbkar, VxMS, Windows Event Logs if there are any clue of crashing processes.

[Arturo_Lopez]

I create a bpbkar directory and I wait to finish the backup. Where is the VxMS? and in the windows event Logs don't appear nothing,

Thanks, meanwhile other solutions?

[Arturo_Lopez]

Hi,

In the bpbkar appears:

:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog VIRTUAL_FILE.
16:12:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - Map completion time: 5
16:12:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - after close_vm_map_section
16:12:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - after fiml_get_fvv
16:12:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - before write_vm_files_extents
16:12:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - write_incr_data size = 39374225408, num_extents = 58
16:12:30.876: [1752.4000] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog VMFILE0.
17:31:46.828: [1752.4000] <2> tar_base::V_vTarMsgW: INF - before write_vm_files_extents
17:31:46.828: [1752.4000] <2> tar_base::V_vTarMsgW: INF - write_incr_data size = 1344610304, num_extents = 5
17:31:46.828: [1752.4000] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog VMFILE1.
17:34:23.597: [1752.4000] <2> tar_base::V_vTarMsgW: INF - before write_vm_files_extents
17:34:23.597: [1752.4000] <2> tar_base::V_vTarMsgW: INF - write_incr_data size = 88464392192, num_extents = 1395
17:34:23.597: [1752.4000] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog VMFILE2.
20:20:10.735: [1752.4000] <2> tar_base::V_vTarMsgW: INF - before write_vm_files_extents
20:20:10.735: [1752.4000] <2> tar_base::V_vTarMsgW: INF - write_incr_data size = 29957128192, num_extents = 5661
20:20:10.735: [1752.4000] <2> tar_base::V_vTarMsgW: INF - File System Name to catalog VMFILE3.
20:20:10.751: [1752.4000] <2> tar_base::V_vTarMsgW: INF - VxMS error - severity 99.
20:20:10.751: [1752.4000] <2> tar_base::V_vTarMsgW: INF - VxMS Error message 1 = fiml_read_file vfm_read
message 2 = stat 11 req.io_error 0
20:20:10.751: [1752.4000] <2> tar_base::V_vTarMsgW: ERR - Read of VM file read 0 bytes, should have read 131072 bytes
20:20:12.142: [1752.4000] <2> tar_base::V_vTarMsgW: INF - VxMS Performance stats:
20:20:12.142: [1752.4000] <2> tar_base::V_vTarMsgW: INF - Write Buffer Time: 0, Get Buffer Time: 0
20:20:12.142: [1752.4000] <2> tar_base::V_vTarMsgW: INF - Get Metadata Time: 311, Write Catalog Time: 0
20:20:12.142: [1752.4000] <2> tar_base::V_vTarMsgW: INF - Create Names Time: 1, Put Tape Time: 3
20:20:12.142: [1752.4000] <2> tar_base::V_vTarMsgW: INF - Build Map Time: 0, Extract Stat Time: 50
20:20:12.142: [1752.4000] <2> tar_base::V_vTarMsgW: INF - Build Image Time: 453, Next Index Time: 166
20:20:12.142: [1752.4000] <4> tar_backup::backup_done_state: INF - number of file directives not found: 0
20:20:12.142: [1752.4000] <4> tar_backup::backup_done_state: INF -     number of file directives found: 1
20:20:12.142: [1752.3108] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0)
20:20:12.142: [1752.4000] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0)
20:20:12.157: [1752.4000] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 11: system call failed
20:20:12.157: [1752.4000] <4> tar_backup::backup_done_state: INF - Not waiting for server status
20:20:12.157: [1752.4000] <4> dos_backup::tfs_reset: INF - Snapshot deletion start
20:20:12.157: [1752.4000] <4> ov_log::OVLoop: Timestamp
20:20:12.157: [1752.4000] <4> OVStopCmd: INF - EXIT - status = 0
20:20:12.157: [1752.4000] <2> tar_base::V_Close: closing...
20:20:12.157: [1752.4000] <4> dos_backup::tfs_reset: INF - Snapshot deletion start
20:20:12.329: [1752.4000] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): enter - InitFlags:0x00000101
20:20:12.329: [1752.4000] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): ubs specifics: 0x001d0000
20:20:12.735: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:13.735: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:14.735: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:15.736: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:16.736: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:17.736: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:18.736: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:19.736: [1752.4000] <16> dtcp_read: TCP - failure: recv socket (400) (TCP 10053: Software caused connection abort)
20:20:19.736: [1752.4000] <4> OVShutdown: INF - Finished process
20:20:19.736: [1752.4000] <4> WinMain: INF - Exiting C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe
20:20:21.751: [1752.4000] <4> ov_log::OVClose: INF - Closing log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\101013.LOG

22:55:14.925: [3856.3836] <4> ov_log::OVInit: INF - Starting log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\101013.LOG

It is the posible error?

[Marianne]

How to enable VxMS logs: http://www.symantec.com/docs/TECH72862

See this TN (it describes a similar error): http://www.symantec.com/docs/TECH167193