Video Screencast Help

Backup Vmware Fail wint error 11

Created: 09 Oct 2013 | 4 comments
Arturo López's picture

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?

 

 

 

Operating Systems:

Comments 4 CommentsJump to latest comment

Yasuhisa Ishikawa's picture

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

Authorized Symantec Consultant(ASC) Data Protection in Tokyo, Japan

Arturo López's picture

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 López's picture

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's picture

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

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