cancel
Showing results for 
Search instead for 
Did you mean: 

Agent Backup failing|bptestbpcd hung

fazhar
Level 3

hello Guys,

2 of my clients started failing recently with error in job details as below

 

Feb 19, 2021 8:57:58 PM - started process bpbrm (pid=72139)
Feb 19, 2021 9:58:09 PM - Error bpbrm (pid=72139) [PROXY] Connecting host: frontier123
Feb 19, 2021 9:58:09 PM - Error bpbrm (pid=72139) [PROXY] ConnectionId: {0E8CEB40-731F-11EB-B0C8-19FDBA47E32D}:OUTBOUND
Feb 19, 2021 9:58:09 PM - Error bpbrm (pid=72139) [PROXY] pid: 19555
Feb 19, 2021 9:58:09 PM - Error bpbrm (pid=72139) [PROXY] Received status: 41 with message The requested I/O operation has timed out.
Feb 19, 2021 9:58:09 PM - Error bpbrm (pid=72139) [PROXY] Encountered error (CERT_PROTOCOL_READING_JSON_LENGTH) while processing(CertProtocol).
Feb 19, 2021 9:58:09 PM - Error bpbrm (pid=72139) bpcd on Frontier123 exited with status 41: network connection timed out

 

nbU version s 8.1.2 on all

Client is Windows 2016

Master/media NBU 5240

 

12 REPLIES 12

quebek
Moderator
Moderator
   VIP    Certified

Hey

can you ping from master these two clients and vice - versa? How about telnet from master to bpcd port on clients? 

yea it does

 

backup1:/home/maintenance # telnet dmc-frontierhtz bpcd
Trying 155.139.194.179...
Connected to dmc-frontierhtz.
Escape character is '^]'.
^CConnection closed by foreign host.
backup1:/home/maintenance # telnet dmc-frontier123.dmc.org bpcd
Trying 155.139.194.141...
Connected to dmc-frontier123.dmc.org.
Escape character is '^]'.
^CConnection closed by foreign host.
backup1:/home/maintenance #


backup1:/usr/openv/netbackup/bin/support/output/nbsu # ping dmc-frontierhtz
PING frontierhtz.dmc.org (155.139.194.179) 56(84) bytes of data.
64 bytes from frontierhtz.dmc.org (155.139.194.179): icmp_seq=1 ttl=127 time=0.602 ms
64 bytes from frontierhtz.dmc.org (155.139.194.179): icmp_seq=2 ttl=127 time=0.400 ms
^C
--- frontierhtz.dmc.org ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 0.400/0.501/0.602/0.101 ms
backup1:/usr/openv/netbackup/bin/support/output/nbsu # ping dmc-frontier123
PING dmc-frontier123.dmc.org (155.139.194.141) 56(84) bytes of data.
64 bytes from dmc-frontier123.dmc.org (155.139.194.141): icmp_seq=1 ttl=127 time=0.673 ms
64 bytes from dmc-frontier123.dmc.org (155.139.194.141): icmp_seq=2 ttl=127 time=0.581 ms
64 bytes from dmc-frontier123.dmc.org (155.139.194.141): icmp_seq=3 ttl=127 time=0.743 ms

 

 

quebek
Moderator
Moderator
   VIP    Certified

OK so these are reachable...

What is bpbrm log telling for this job:

grep 72139 /usr/openv/netbackup/logs/bpbrm/log_from_job_date

increase verbosity to 3 and retry if above is clueless.

quebek
Moderator
Moderator
   VIP    Certified

I would also have enabled logging for bpcd on client end and possible bpbkar... 

i got for another pid from latest one

 

08:00:18.361 [182015.182015] <4> bpbrm main: logging will continue into new log at midnight
08:00:18.362 [182015.182015] <2> bpbrm main: INITIATING (VERBOSE = 0): version NetBackup 8.1.2 2018082717
08:00:18.362 [182015.182015] <2> logparams: -backup -S backup1.dmc.org -c DMC-FRONTIERHTZ -ct 13 -ru root -cl Windows-Clients-HTZ -sched Diff-Daily -b DMC-FRONTIERHTZ_1613998818 -bt 1613998818 -dt 1001046 -st 1 -mediasvr backup1 -jobid 2203849 -jobgrpid 2203849 -masterversion 812000 -maxfrag 51200 -bpstart_time 1613999118 -reqid -1611810251 -mt 0 -to 0 -stunit stu_disk_backup1 -rl 3 -rp 2678400 -eari 0 -p PureDiskVolume -mst 6 -flags 2 -storagesvr backup1.dmc.org -sts_type PureDisk -use_ofb -use_otm -WOFB_enabled 1 -WOFB_fim 1 -nbu -jm -secure 1 -kl 15 -rg root -fso -connect_options 16974338
08:00:18.362 [182015.182015] <2> ParseConfigExA: Option (CRYPT_KIND) redefined on line 35, discarding definition on line 18.
08:00:18.363 [182015.182015] <2> read_client: dname=., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.363 [182015.182015] <2> read_client: dname=.., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.363 [182015.182015] <2> read_client: dname=CO_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.363 [182015.182015] <2> read_client: dname=OA_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.363 [182015.182015] <2> read_client: dname=host_info, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.395 [182015.182015] <2> check_dynamic_client_and_set_tss: Client entry for client DMC-FRONTIERHTZ found in client DB but dynamic address is not set
08:00:18.395 [182015.182015] <2> bpbrm main: Cleaning cs_cache for client:[DMC-FRONTIERHTZ] older than:[30] sec
08:00:18.396 [182015.182015] <2> read_legacy_touch_file: Found /usr/openv/netbackup/MAX_ENTRIES_PER_ADD; requested from (../bpbrm.c.3112).
08:00:18.396 [182015.182015] <2> read_legacy_touch_file: 100000 read ; requested from (../bpbrm.c.3112).
08:00:18.396 [182015.182015] <2> bpbrm main: max_entries_per_add = 100000
08:00:18.396 [182015.182015] <2> bpbrm main: max_files_per_cache = 50000
08:00:18.396 [182015.182015] <2> read_client: dname=., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.396 [182015.182015] <2> read_client: dname=.., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.396 [182015.182015] <2> read_client: dname=CO_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.396 [182015.182015] <2> read_client: dname=OA_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.396 [182015.182015] <2> read_client: dname=host_info, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
08:00:18.406 [182015.182015] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
09:00:28.412 [182015.182015] <16> dump_proxy_info: statusmsg: The requested I/O operation has timed out., nbu status = 41, severity = 1, Additional Message: [PROXY] Encountered error (CERT_PROTOCOL_READING_JSON_LENGTH) while processing(CertProtocol)., nbu status = 2, severity = 1
09:00:28.412 [182015.182015] <16> dump_proxy_info: local_proxy_info:
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----pid: 19555
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----connection_id: {E9E55548-750D-11EB-9FA7-F7B463715608}:OUTBOUND
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----ca_roots: 5d13ef34-3100-4c16-94df-1ab0c5737bee
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----ca_roots_excluded: UNCONSTRAINED
09:00:28.412 [182015.182015] <16> dump_proxy_info: domain_constraints_set:
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----process_hint_server_name: backup1.dmc.org
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----process_hint: 5d13ef34-3100-4c16-94df-1ab0c5737bee
09:00:28.412 [182015.182015] <16> dump_proxy_info: ----process_hint_reason: there was no inherited hint, the connected peer was not a master server, so defaulted to primary master
09:00:28.412 [182015.182015] <16> vnet_proxy_protocol_from_legacy: proxy returned status: 41 msg: {"status": 41, "local_proxy_info": {"ca_roots": ["5d13ef34-3100-4c16-94df-1ab0c5737bee"], "ca_roots_excluded": ["UNCONSTRAINED"], "connection_id": "{E9E55548-750D-11EB-9FA7-F7B463715608}:OUTBOUND", "pid": 19555}, "domain_constraints_set": {"process_hint": "5d13ef34-3100-4c16-94df-1ab0c5737bee", "process_hint_reason": "there was no inherited hint, the connected peer was not a master server, so defaulted to primary master", "process_hint_server_name": "backup1.dmc.org"}, "statusmsgxml": "<?xml version=\"1.0\" encoding=\"utf-8\"?><StatusMsgDoc><StatusMsg NBUStatus=\"41\" Severity=\"1\" VXULoid=\"486\" VXULtid=\"26\"><MsgString>The&#32;requested&#32;I/O&#32;operation&#32;has&#32;timed&#32;out.</MsgString><StatusMsg NBUStatus=\"2\" Severity=\"1\" VXULoid=\"486\" VXULtid=\"88\"><P pos=\"0\">CERT_PROTOCOL_READING_JSON_LENGTH</P><P pos=\"1\">CertProtocol</P><MsgString>[PROXY]&#32;Encountered&#32;error&#32;(CERT_PROTOCOL_READING_JSON_LENGTH)&#32;while&#32;processing(CertProtocol).</MsgString></StatusMsg></StatusMsg></StatusMsgDoc>", "statusmsg": "The requested I/O operation has timed out., nbu status = 41, severity = 1, Additional Message: [PROXY] Encountered error (CERT_PROTOCOL_READING_JSON_LENGTH) while processing(CertProtocol)., nbu status = 2, severity = 1"} vnet status: 11
09:00:28.412 [182015.182015] <16> vnet_proxy_socket_swap: vnet_proxy_protocol_from_legacy() failed: 11
09:00:28.412 [182015.182015] <16> connect_to_service: vnet_proxy_socket_swap(NULL, -1, 3610, 0, DMC-FRONTIERHTZ, bpcd, 1) failed: 11
09:00:28.412 [182015.182015] <16> connect_to_service: JSON data = {"allow_large_status": {"timestamp": 1613998818, "who": "vnet_tss_init", "line_number": 32, "comment": "allow vnet status > 255", "data": true}, "direct_connect": {"timestamp": 1613998818, "who": "connect_to_service", "line_number": 838, "comment": "connect parameters", "data": {"who": "vnet_connect_to_bpcd", "host": "DMC-FRONTIERHTZ", "service": "bpcd", "override_required_interface": null, "extra_tries_on_connect": 0, "getsock_disable_to": 0, "overide_connect_timeout": 0, "connect_options": {"server": null, "callback_kind": {"number": 1, "symbol": "NBCONF_CALLBACK_KIND_VNETD", "description": "Vnetd"}, "daemon_port_type": {"number": 0, "symbol": "NBCONF_DAEMON_PORT_TYPE_AUTOMATIC", "description": "Automatic"}, "reserved_port_kind": {"number": 0, "symbol": "NBCONF_RESERVED_PORT_KIND_LEGACY", "description": "Legacy"}}}}, "proxy_request": {"timestamp": 1613998818, "who": "vnet_proxy_build_request", "line_number": 3477, "comment": "request to local proxy", "data": {"bpcd_info": {"remote_client": "DMC-FRONTIERHTZ", "remote_host": "DMC-FRONTIERHTZ", "remote_probably_dhcp": false, "proxy_flag": 16, "proxy_flag_hex": "0x00000010"}, "i_am_daemon": false, "domain_constraints": {}, "service": "bpcd", "auth_only": false, "pid": 182015, "exe_name": "bpbrm", "ssa": false, "local_user": "root", "NB_ORG_USER": null, "local_group": "root", "host": "DMC-FRONTIERHTZ", "peer_host": "DMC-FRONTIERHTZ", "peer_client": "DMC-FRONTIERHTZ", "local_client": "backup1.dmc.org", "local_dhcp_interval": 0, "peer_dhcp_info": {"dhcp_client_name": "DMC-FRONTIERHTZ", "is_dhcp_client": 0}, "local_hostname": "backup1.dmc.org", "user_info_uid": 0, "user_info_gid": 0, "light_proxy": false, "secure_peer": true, "resilient": false, "nbrntd_peer_addr": null, "nbrntd_sock_addr": null, "hand_back": false, "request_timeout": 3610}}, "proxy_response": {"timestamp": 1614002428, "who": "vnet_proxy_parse_response", "line_number": 3721, "comment": "response from local proxy", "data": {"status": 41, "local_proxy_info": {"ca_roots": ["5d13ef34-3100-4c16-94df-1ab0c5737bee"], "ca_roots_excluded": ["UNCONSTRAINED"], "connection_id": "{E9E55548-750D-11EB-9FA7-F7B463715608}:OUTBOUND", "pid": 19555}, "domain_constraints_set": {"process_hint": "5d13ef34-3100-4c16-94df-1ab0c5737bee", "process_hint_reason": "there was no inherited hint, the connected peer was not a master server, so defaulted to primary master", "process_hint_server_name": "backup1.dmc.org"}, "statusmsgxml": "<?xml version=\"1.0\" encoding=\"utf-8\"?><StatusMsgDoc><StatusMsg NBUStatus=\"41\" Severity=\"1\" VXULoid=\"486\" VXULtid=\"26\"><MsgString>The&#32;requested&#32;I/O&#32;operation&#32;has&#32;timed&#32;out.</MsgString><StatusMsg NBUStatus=\"2\" Severity=\"1\" VXULoid=\"486\" VXULtid=\"88\"><P pos=\"0\">CERT_PROTOCOL_READING_JSON_LENGTH</P><P pos=\"1\">CertProtocol</P><MsgString>[PROXY]&#32;Encountered&#32;error&#32;(CERT_PROTOCOL_READING_JSON_LENGTH)&#32;while&#32;processing(CertProtocol).</MsgString></StatusMsg></StatusMsg></StatusMsgDoc>", "statusmsg": "The requested I/O operation has timed out., nbu status = 41, severity = 1, Additional Message: [PROXY] Encountered error (CERT_PROTOCOL_READING_JSON_LENGTH) while processing(CertProtocol)., nbu status = 2, severity = 1"}}, "status": {"timestamp": 1614002428, "who": "connect_to_service", "line_number": 985, "comment": "vnet status", "data": 11}}
09:00:28.412 [182015.182015] <8> vnet_connect_to_bpcd: [vnet_connect.c:569] connect_to_service() failed 11 0xb
09:00:28.412 [182015.182015] <16> local_bpcr_connect: vnet_connect_to_bpcd(DMC-FRONTIERHTZ) failed: 11
09:00:28.413 [182015.182015] <2> local_bpcr_connect: Can't connect to client DMC-FRONTIERHTZ
09:00:28.413 [182015.182015] <2> ConnectToBPCD: bpcd_connect_and_verify(DMC-FRONTIERHTZ, DMC-FRONTIERHTZ) failed: 41
09:00:28.445 [182015.182015] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
09:00:28.446 [182015.182015] <2> job_connect: SO_KEEPALIVE set on socket 5 for client backup1.dmc.org
09:00:28.446 [182015.182015] <2> logconnections: BPJOBD CONNECT FROM 155.139.61.10.38267 TO 155.139.61.10.1556 fd = 5
09:00:28.446 [182015.182015] <2> job_authenticate_connection: VxSS authentication check for now...
09:00:28.446 [182015.182015] <8> vnet_get_user_credential_path: [vnet_vxss.c:1620] status 35 0x23
09:00:28.446 [182015.182015] <8> vnet_check_user_certificate: [vnet_vxss_helper.c:4122] vnet_get_user_credential_path failed 35 0x23
09:00:28.446 [182015.182015] <2> job_connect: Connected to the host backup1.dmc.org contype 53 jobid <2203849> socket <5>
09:00:28.446 [182015.182015] <2> job_connect: Connected on port 38267
09:00:28.446 [182015.182015] <4> JobdSockList::RegisterSocket: Register socket (5).
09:00:28.447 [182015.182015] <16> bpbrm start_bpcd_stat: bpcd on DMC-FRONTIERHTZ exited with status 41: network connection timed out
09:00:28.447 [182015.182015] <2> verify_client: ../bpbrm.c.37688: start_bpcd_stat failed: 41 41 0x00000029
09:00:28.447 [182015.182015] <2> bpbrm main: ../bpbrm.c.3451: verify_client failed: 41 41 0x00000029
09:00:28.447 [182015.182015] <2> bpbrm kill_child_process: start
09:00:28.447 [182015.182015] <2> inform_client_of_status: COMM_SOCK == INVALID_SOCKET, 0
09:00:28.447 [182015.182015] <2> OpenSendmailPipe: /usr/lib/sendmail -t >/dev/null 2>/dev/null
09:00:28.590 [182015.182015] <2> bpbrm Exit: client snapshot EXIT STATUS 41: network connection timed out
09:00:28.591 [182015.182015] <4> JobdSockList::UnregisterSocket: Unregister socket (5).
09:00:29.856 [182015.182015] <2> job_monitoring_exex: ACK disconnect
09:00:29.856 [182015.182015] <2> job_disconnect: Disconnected

quebek
Moderator
Moderator
   VIP    Certified

Hmm

Are all certificates in place and good? Can you see anything in client's bpcd?

Any recent changes in this env?

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@fazhar 

You are using lowercase for ping and telnet : dmc-frontierhtz
but it seems that the backup policy has uppercase for client name? DMC-FRONTIERHTZ

NBU is case sensitive, as is Linux/Unix.

Please check Client Connect timeout on master and media server. Change it to the default of 300 (5 min) while you are troubleshooting.
NBU (bptestbpcd and bpbrm) will firstly try to connect to PBX until Client Connect Timeout, then try vnetd if PBX is not possible, and then bpcd.
So, too long Timeouts will make bptestbpcd appear to hang.

The client seems to be in a DMZ.
Which ports have been opened?
All you really need is port 1556 (PBX) in both directions.

Please ensure bpcd log folder exists on the client, Timeout is reduced, then retry bptestbpcd with uppercase client name, adding -verbose -debug.

Please post bptestbpcd output and client bpcd log (as .txt file).

bptestbpcd output is below

 

10:23:29.729 [110729] <2> bptestbpcd: VERBOSE = 0
10:23:29.729 [110729] <2> read_client: dname=., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
10:23:29.729 [110729] <2> read_client: dname=.., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
10:23:29.729 [110729] <2> read_client: dname=CO_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
10:23:29.729 [110729] <2> read_client: dname=OA_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
10:23:29.729 [110729] <2> read_client: dname=host_info, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
10:23:29.836 [110729] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
10:28:39.169 [110729] <2> get_exactly_n_bytes_or_eof_abs: socket read timed out: Connection timed out (110)
10:28:39.169 [110729] <2> ts_get_long_abs: error reading long from socket: Connection timed out (110)
10:28:39.169 [110729] <2> ts_get_string: error reading long from socket: Connection timed out (110)
10:28:39.169 [110729] <16> nb_recv_str: ts_get_string() failed: -2 110
10:28:39.169 [110729] <16> vnet_proxy_protocol_from_legacy: nb_recv_str() failed: 9
10:28:39.169 [110729] <16> vnet_proxy_socket_swap: vnet_proxy_protocol_from_legacy() failed: 9
10:28:39.169 [110729] <16> connect_to_service: vnet_proxy_socket_swap(NULL, -1, 310, 0, DMC-Frontier123, bpcd, 1) failed: 9
10:28:39.169 [110729] <16> connect_to_service: JSON data = {"allow_large_status": {"timestamp": 1614093809, "who": "vnet_tss_init", "line_number": 32, "comment": "allow vnet status > 255", "data": true}, "direct_connect": {"timestamp": 1614093809, "who": "connect_to_service", "line_number": 838, "comment": "connect parameters", "data": {"who": "vnet_connect_to_bpcd", "host": "DMC-Frontier123", "service": "bpcd", "override_required_interface": null, "extra_tries_on_connect": 0, "getsock_disable_to": 0, "overide_connect_timeout": 0, "connect_options": {"server": null, "callback_kind": {"number": 1, "symbol": "NBCONF_CALLBACK_KIND_VNETD", "description": "Vnetd"}, "daemon_port_type": {"number": 0, "symbol": "NBCONF_DAEMON_PORT_TYPE_AUTOMATIC", "description": "Automatic"}, "reserved_port_kind": {"number": 0, "symbol": "NBCONF_RESERVED_PORT_KIND_LEGACY", "description": "Legacy"}}}}, "proxy_request": {"timestamp": 1614093809, "who": "vnet_proxy_build_request", "line_number": 3477, "comment": "request to local proxy", "data": {"bpcd_info": {"remote_client": "DMC-Frontier123", "remote_host": "DMC-Frontier123", "remote_probably_dhcp": false, "proxy_flag": 16, "proxy_flag_hex": "0x00000010"}, "i_am_daemon": false, "domain_constraints": {}, "service": "bpcd", "auth_only": false, "pid": 110729, "exe_name": "bptestbpcd", "ssa": false, "local_user": "root", "NB_ORG_USER": null, "local_group": "root", "host": "DMC-Frontier123", "peer_host": "DMC-Frontier123", "isTestConnection": true, "peer_client": "DMC-Frontier123", "local_client": "backup1.dmc.org", "local_dhcp_interval": 0, "peer_dhcp_info": null, "local_hostname": "backup1.dmc.org", "user_info_uid": 0, "user_info_gid": 0, "light_proxy": false, "secure_peer": true, "resilient": false, "nbrntd_peer_addr": null, "nbrntd_sock_addr": null, "hand_back": false, "request_timeout": 310}}, "status": {"timestamp": 1614094119, "who": "connect_to_service", "line_number": 985, "comment": "vnet status", "data": 9}}
10:28:39.169 [110729] <8> vnet_connect_to_bpcd: [vnet_connect.c:569] connect_to_service() failed 9 0x9
10:28:39.169 [110729] <16> local_bpcr_connect: vnet_connect_to_bpcd(DMC-Frontier123) failed: 9
10:28:39.169 [110729] <2> local_bpcr_connect: Can't connect to client DMC-Frontier123
10:28:39.169 [110729] <2> ConnectToBPCD: bpcd_connect_and_verify(DMC-Frontier123, DMC-Frontier123) failed: 23
10:28:39.169 [110729] <16> bptestbpcd main: JSON proxy message = {"allow_large_status": {"timestamp": 1614093809, "who": "vnet_tss_init", "line_number": 32, "comment": "allow vnet status > 255", "data": true}, "direct_connect": {"timestamp": 1614093809, "who": "connect_to_service", "line_number": 838, "comment": "connect parameters", "data": {"who": "vnet_connect_to_bpcd", "host": "DMC-Frontier123", "service": "bpcd", "override_required_interface": null, "extra_tries_on_connect": 0, "getsock_disable_to": 0, "overide_connect_timeout": 0, "connect_options": {"server": null, "callback_kind": {"number": 1, "symbol": "NBCONF_CALLBACK_KIND_VNETD", "description": "Vnetd"}, "daemon_port_type": {"number": 0, "symbol": "NBCONF_DAEMON_PORT_TYPE_AUTOMATIC", "description": "Automatic"}, "reserved_port_kind": {"number": 0, "symbol": "NBCONF_RESERVED_PORT_KIND_LEGACY", "description": "Legacy"}}}}, "proxy_request": {"timestamp": 1614093809, "who": "vnet_proxy_build_request", "line_number": 3477, "comment": "request to local proxy", "data": {"bpcd_info": {"remote_client": "DMC-Frontier123", "remote_host": "DMC-Frontier123", "remote_probably_dhcp": false, "proxy_flag": 16, "proxy_flag_hex": "0x00000010"}, "i_am_daemon": false, "domain_constraints": {}, "service": "bpcd", "auth_only": false, "pid": 110729, "exe_name": "bptestbpcd", "ssa": false, "local_user": "root", "NB_ORG_USER": null, "local_group": "root", "host": "DMC-Frontier123", "peer_host": "DMC-Frontier123", "isTestConnection": true, "peer_client": "DMC-Frontier123", "local_client": "backup1.dmc.org", "local_dhcp_interval": 0, "peer_dhcp_info": null, "local_hostname": "backup1.dmc.org", "user_info_uid": 0, "user_info_gid": 0, "light_proxy": false, "secure_peer": true, "resilient": false, "nbrntd_peer_addr": null, "nbrntd_sock_addr": null, "hand_back": false, "request_timeout": 310}}, "status": {"timestamp": 1614094119, "who": "connect_to_service", "line_number": 985, "comment": "vnet status", "data": 9}}
PEER_NAME = backup1.dmc.org
<16>bptestbpcd main: Function ConnectToBPCD(DMC-Frontier123) failed: 23
10:28:39.169 [110729] <16> bptestbpcd main: Function ConnectToBPCD(DMC-Frontier123) failed: 23
<16>bptestbpcd main: socket read failed
10:28:39.203 [110729] <16> bptestbpcd main: socket read failed
<2>bptestbpcd: socket read failed
10:28:39.203 [110729] <2> bptestbpcd: socket read failed
<2>bptestbpcd: EXIT status = 23
10:28:39.203 [110729] <2> bptestbpcd: EXIT status = 23
socket read failed

bpcd logs attached.

i reduced the timeout to 300 sec now but no luck.

client is not in DMZ.why do think otherwise?

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Apologies - seems I was a bit dyslexic - I misread DMC as DMZ.

You ran bptestbpcd at 10:28.
Client bpcd log has entries for 10:12 where it only runs comparisons against it own hostname.
There is no evidence of any connection request in the log.

So, the assumption is that the connection request never got to this client.

I see that config on the client is all in lower case, but you are still using a mix of cases and shortname/FQDN in policies and cmd ?
You really need to standardize.

All I can suggest is that you go back to basics by validating hostname & IP addresses in all directions.

Do this on the master and ALL media servers that will backup this client:

bpclntcmd -hn <client-name>
bpclntcmd ip <client-IP>

On problematic clients:
bpclntcmd -self
bpclntcmd -pn
Repeat these commands for master and all media server:
bpclntcmd -hn <server-name>
bpclntcmd ip <server-IP>

Please add all of above output to a text file and upload here.

here are the output form bpclntcmd 

I tried reinstalling the client today but it didnt help

 

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

In all honesty - the vast amount of hostnames for the one client is confusing me... may NBU as well...

It also seems as if the client has 2 IP addresses with the same hostname?
host DMC-FRONTIERHTZ: DMC-FrontierHTZ.dmcnt1.local at 155.139.194.179
host DMC-FRONTIERHTZ: DMC-FrontierHTZ.dmcnt1.local at 192.168.10.104

At least the uppercase hostname is consistent on client and master - DMC-FRONTIERHTZ
With same IP address used for comms between the master and client: 155.139.194.179
If you use this hostname consistently everywhere, at least hostname lookup should be fine.

What you really need to troubleshoot is the fact that connection request never reached the client (as seen in yesterday's bpcd log).

Something that you did not post with bptestbpcd output is the 1st line that shows the connect options.

This will tell you/us how NBU is trying to connect. (See https://www.veritas.com/support/en_US/doc/15263389-127350397-0/v14667804-127350397
You can then try to involve network, server and/or security admin to find out if something in the environment or on the client changed that could block NBU connection attempts (e.g. Windows Firewall or AV software).