network connection timed out (41) - on Novell client 6.5
This is for Netbackup 7.1 Enterprise Server running on Windows Server 2008 R2 Enterprise SP1
Client: Novell server with a 6.5 BU Client
We have been assured Open File Manager is indeed "disabled" on the client, we had the client rebooted last evening prior to the scheduled incremental to see if there was something possibly stuck on the client that was preventing Netbackup from connecting. Standard bpclntcmd -hn and -ip tests verify that the connectivity is there:
“D:\Program Files\Veritas\NetBackup\bin>bpclntcmd -hn servername
host servername: servername at 10.204.253.1
aliases: servername 10.204.253.1
D:\Program Files\Veritas\NetBackup\bin>bpclntcmd -ip 10.204.253.1
host 10.204.253.1: servername at 10.204.253.1
aliases: servername 10.204.253.1”
I also ran the bptestbpcd cmd with the –verbose and –debug switches:
“D:\Program Files\Veritas\NetBackup\bin\admincmd>bptestbpcd -client Client_servername -verbose -debug
09:17:15.569 [6276.8680] <2> bptestbpcd: VERBOSE = 0
09:17:16.630 [6276.8680] <2> vnet_async_connect: ../../libvlibs/vnet_connect.c.1376: 0: getsockopt SO_ERROR returned: 10061 0x0000274d
09:17:17.051 [6276.8680] <2> vnet_version_connect: ../../libvlibs/vnet_vnetd.c.1663: 0: Function failed: 24 0x00000018
09:17:17.051 [6276.8680] <2> do_vnetd_service: ../../libvlibs/vnet_connect.c.1610: 0: vnet_version_connect failed: 24 0x00000018
09:17:17.051 [6276.8680] <2> vnet_async_connect: ../../libvlibs/vnet_connect.c.1353: 0: do_service failed: 24 0x00000018
09:17:17.066 [6276.8680] <2> logconnections: BPCD CONNECT FROM 10.249.32.77.1021 TO 10.204.253.1.13782 fd = 616
09:17:17.066 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 10 0x0000000a
09:17:17.066 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 249 0x000000f9
09:17:17.066 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 32 0x00000020
09:17:17.066 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 77 0x0000004d0 1 2
10.249.32.77:1021 -> 10.204.253.1:13782
10.249.32.77:13724 <- 10.204.253.1:966
09:17:19.032 [6276.8680] <2> bpcr_get_peername_rqst: Server peername length = 23
09:17:19.251 [6276.8680] <2> bpcr_get_hostname_rqst: Server hostname length = 22
09:17:19.469 [6276.8680] <2> bpcr_get_clientname_rqst: Server client name length = 6
09:17:19.687 [6276.8680] <2> bpcr_get_version_rqst: bpcd version: 06520000
09:17:19.906 [6276.8680] <2> bpcr_get_platform_rqst: Server client platform length = 7
09:17:20.124 [6276.8680] <2> bpcr_get_version_rqst: bpcd version: 06520000
09:17:20.140 [6276.8680] <2> get_short: (2) premature end of file (byte 1)
09:17:20.140 [6276.8680] <2> bpcr_patch_version_rqst: get_short failed: 5
09:17:20.140 [6276.8680] <2> bpcr_patch_version_rqst: bpcd returned failure: 23
09:17:20.140 [6276.8680] <16> bpcr_patch_version_rqst() failed, status = 23, errno = 0: get_patch_version
<16>bptestbpcd main: Function get_client_patch_version(Client_servername) failed: 23
09:17:20.140 [6276.8680] <16> bptestbpcd main: Function get_client_patch_version(Client_servername) failed: 23
09:17:20.140 [6276.8680] <2> get_long: (2) premature end of file (byte 1)
09:17:20.140 [6276.8680] <2> bpcr_patch_version_rqst: bpcr_get_version_rqst() failed: 0
09:17:20.140 [6276.8680] <2> bpcr_patch_version_rqst: bpcd returned failure: 23
09:17:20.140 [6276.8680] <16> bpcr_patch_version_rqst() failed, status = 23, errno = 0: get_patch_version
<16>bptestbpcd main: Function get_server_patch_version(Client_servername) failed: 23
09:17:20.140 [6276.8680] <16> bptestbpcd main: Function get_server_patch_version(Client_servername) failed: 23
09:17:20.140 [6276.8680] <2> get_long: (2) premature end of file (byte 1)
09:17:20.140 [6276.8680] <2> get_master_and_emm_servers: bpcr_read_host_config_rqst() failed: 16
<16>bptestbpcd main: Function get_master_and_emm_servers(Client_servername)failed: 16
09:17:20.140 [6276.8680] <16> bptestbpcd main: Function get_master_and_emm_servers(Client_servername) failed: 16
PEER_NAME = Main_Backup_servername
HOST_NAME = Client_servername
CLIENT_NAME = servername
VERSION = 0x06520000
PLATFORM = NetWare
PATCH_VERSION =
SERVER_PATCH_VERSION =
MASTER_SERVER = _UNKNOWN_
EMM_SERVER = _UNKNOWN_
09:17:20.140 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 10 0x0000000a
09:17:20.140 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 249 0x000000f9
09:17:20.140 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 32 0x00000020
09:17:20.140 [6276.8680] <2> vnet_vnetd_push_ipaddr: ../../libvlibs/vnet_vnetd.c.1783: 0: bptr[i]: 77 0x0000004d
09:17:20.140 [6276.8680] <2> vnet_pop_byte: ../../libvlibs/vnet.c.1159: 0: errno: 0 0x00000000
09:17:20.140 [6276.8680] <2> vnet_pop_byte: ../../libvlibs/vnet.c.1161: 0: Function failed: 9 0x00000009
09:17:20.140 [6276.8680] <2> vnet_pop_string: ../../libvlibs/vnet.c.1241: 0: Function failed: 9 0x00000009
09:17:20.140 [6276.8680] <2> vnet_pop_signed: ../../libvlibs/vnet.c.1285: 0: Function failed: 9 0x00000009
09:17:20.140 [6276.8680] <2> vnet_pop_status: ../../libvlibs/vnet.c.1363: 0: Function failed: 9 0x00000009
09:17:20.140 [6276.8680] <2> vnet_begin_connect_back: ../../libvlibs/vnet_vnetd.c.613: 0: status: 9 0x00000009
09:17:20.140 [6276.8680] <2> bpcr_get_vnetd_socket_rqst: vnet_begin_connect_back failed: 9
09:17:20.140 [6276.8680] <2> bpcr_new_standard_socket_rqst: bpcr_get_vnetd_socket_rqst failed: 23
<16>bptestbpcd main: Function bpcr_new_standard_socket_rqst(Client_servername) failed: 23
09:17:20.140 [6276.8680] <16> bptestbpcd main: Function bpcr_new_standard_socket_rqst(Client_servername) failed: 23
09:17:20.140 [6276.8680] <2> put_short: (10) network write() error: An operation was attempted on something that is not a socket. ; socket = 616
09:17:20.140 [6276.8680] <2> bpcr_disconnect_rqst: bpcr protocol error - couldn't send request type
<16>bptestbpcd main: Function bpcr_new_standard_socket_rqst(Client_servername) failed: 23
09:17:20.140 [6276.8680] <16> bptestbpcd main: Function bpcr_new_standard_socket_rqst(Client_servername) failed: 23
<2>bptestbpcd: socket close failed
09:17:20.140 [6276.8680] <2> bptestbpcd: socket close failed<2>bptestbpcd: EXIT status = 22
09:17:20.140 [6276.8680] <2> bptestbpcd: EXIT status = 22socket close failed”
The details on the error in the Netbackup Admin Console are also listed below.
"Detailed Status:
5/10/2012 11:29:54 PM - Info bpbrm(pid=152) servername is the host to backup data from
5/10/2012 11:29:54 PM - Info bpbrm(pid=152) reading file list from client
5/10/2012 11:29:58 PM - Info bpbrm(pid=152) starting bpbkar32 on client
5/10/2012 11:29:58 PM - Info bpbkar32(pid=0) Backup started
5/10/2012 11:29:59 PM - Info bptm(pid=2628) start
5/10/2012 11:29:59 PM - Info bptm(pid=2628) using 65536 data buffer size
5/10/2012 11:29:59 PM - Info bptm(pid=2628) setting receive network buffer to 263168 bytes
5/10/2012 11:29:59 PM - Info bptm(pid=2628) using 30 data buffers
5/10/2012 11:30:00 PM - Info nbjm(pid=8168) starting backup job (jobid=14997) for client servername, policy Server_Policy_Novell, schedule Incremental
5/10/2012 11:30:00 PM - Info nbjm(pid=8168) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=14997, request id:{48851B37-501D-40B4-BD5E-73D70B037AC2})
5/10/2012 11:30:00 PM - requesting resource osprscbackup-hcart-robot-tld-1
5/10/2012 11:30:00 PM - requesting resource main_servername.NBU_CLIENT.MAXJOBS.servername
5/10/2012 11:30:00 PM - requesting resource main_servername.NBU_POLICY.MAXJOBS.Server_Policy_Novell
5/10/2012 11:30:00 PM - granted resource main_servername.NBU_CLIENT.MAXJOBS.servername
5/10/2012 11:30:00 PM - granted resource main_servername.NBU_POLICY.MAXJOBS.Server_Policy_Novell
5/10/2012 11:30:00 PM - granted resource BD1740
5/10/2012 11:30:00 PM - granted resource HP.ULTRIUM4-SCSI.000
5/10/2012 11:30:00 PM - granted resource osprscbackup-hcart-robot-tld-1
5/10/2012 11:30:00 PM - estimated 51800200 Kbytes needed
5/10/2012 11:30:00 PM - Info nbjm(pid=8168) started backup job for client servername, policy Server_Policy_Novell, schedule Incremental on storage unit osprscbackup-hcart-robot-tld-1
5/10/2012 11:30:00 PM - Info bptm(pid=2628) start backup
5/10/2012 11:30:00 PM - Info bptm(pid=2628) backup child process is pid 944.3068
5/10/2012 11:30:00 PM - Info bptm(pid=2628) Waiting for mount of media id BD1740 (copy 1) on server osprscbackup.
5/10/2012 11:30:00 PM - Info bptm(pid=944) start
5/10/2012 11:30:01 PM - started process bpbrm (152)
5/10/2012 11:30:05 PM - connecting
5/10/2012 11:30:10 PM - connected; connect time: 00:00:05
5/10/2012 11:30:11 PM - mounting BD1740
5/10/2012 11:30:57 PM - Info bptm(pid=2628) media id BD1740 mounted on drive index 0, drivepath {4,0,0,0}, drivename HP.ULTRIUM4-SCSI.000, copy 1
5/10/2012 11:31:08 PM - mounted; mount time: 00:00:57
5/10/2012 11:31:12 PM - positioning BD1740 to file 472
5/10/2012 11:31:54 PM - positioned BD1740; position time: 00:00:42
5/10/2012 11:31:54 PM - begin writing
5/11/2012 12:35:52 AM - Error bpbrm(pid=152) cannot send mail to
5/11/2012 12:36:03 AM - end writing; write time: 01:04:09
network connection timed out(41)"
Any help would be much appreciated, we are at kind of a roadblock at this point on this one Novell server. This has been going on over a week that this server has not been backed up.
Thanks!
I wanted to post a solution to this thread I started back a couple weeks previous. In the end we had the Novell NBU client restarted which reset the NBU service on the client. This resolved our issues after ensuring we had the master server and media server defined in the host record. In the end there were other mitigating factors including network contention and outages that were not reported and taken into account when trying to figure out why this client was not responding to the requests made on the master server for backup's/restores ect.