Forum Discussion

fazhar's avatar
fazhar
Level 3
7 years ago

Extremely bad performance after upgrade from Netbackup 8.0 to 8.1.1

After Upgradign our IWndows master from 773 to 8.1.1, numerous backups and replication have started to fail with socket erros but completing successfully mostly on rerun. while running bptestbpcd on multiple clients , its gettign failed intermittently  for many clients.

we opened case with support but so far nothing concrete has been achieved. Checked with n/w OS team and did all possible nic/ network related settings but issue is still there. anyone else is faving such issue

  • Have you logged a Support call with Veritas about issues experienced after upgrade? 

    My guess is that the performance problem and socket errors are 2 separate issues.

    Are you using MSDP on media servers? 
    This is a known issue for NBU 8.1: https://www.veritas.com/support/en_US/article.100041390

    Plus the rolling MSDP conversion:
    https://vox.veritas.com/t5/NetBackup/Extremely-bad-performance-after-upgrade-from-Netbackup-8-0-to-8/td-p/856844
    MSDP EEB : https://www.veritas.com/support/en_US/article.100043461

    About the socket errors and bptestbpcd failure - 
    can you show us an example of bptestbpcd failure (with -verbose -debug)?
    There are no 'known issues' w.r.t to comms in 8.1 and later. 
    See LBN: https://www.veritas.com/support/en_US/article.000127571

    • fazhar's avatar
      fazhar
      Level 3

      we are not using MSDP but DD boost and all DDRs are running at 6.0

      we tested bptestbpcd multiple times for different clients in a loop and we cann see socket error in between. below is one such output:

       

      <2> put_string: cannot write data to network:  An existing connection was forcibly closed by
      the remote host.

       

      PS C:\temp> .\test1.bat

      C:\temp>bptestbpcd -host qtc-db068p -debug
      04:17:41.489 [27760.27376] <2> bptestbpcd: VERBOSE = 0
      04:17:41.489 [27760.27376] <8> cache_item_to_file: [vnet_addrinfo.c:6857] rename() failed 13 0xd
      04:17:41.489 [27760.27376] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1858] cache_item_to_file() failed 0
      0x0
      04:17:41.505 [27760.27376] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:41.505 [27760.27376] <2> logconnections: BPCD CONNECT FROM 10.44.72.40.57563 TO 10.44.71.45.1556 fd = 604
      04:17:41.505 [27760.27376] <2> vnet_connect_to_vnetd_bpcd: js_bpcd_info: 0000000002A8BB40
      04:17:41.521 [27760.27376] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:41.552 [27760.27376] <8> do_pbx_service: [vnet_connect.c:2581] via PBX VNETD CONNECT FROM 10.44.72.40.57565 TO 10.
      44.71.45.1556 fd = 608
      04:17:41.552 [27760.27376] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SO
      CKET 10 0xa
      04:17:41.568 [27760.27376] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 52694
      04:17:41.630 [27760.27376] <2> bpcr_get_version_rqst: bpcd version: 07730000
      1 1 1
      10.44.72.40:57563 -> 10.44.71.45:1556
      10.44.72.40:57565 -> 10.44.71.45:1556
      <2>bptestbpcd: EXIT status = 0
      04:17:41.646 [27760.27376] <2> bptestbpcd: EXIT status = 0

      C:\temp>bptestbpcd -host qtc-db068p -debug
      04:17:41.677 [29320.15416] <2> bptestbpcd: VERBOSE = 0
      04:17:41.693 [29320.15416] <8> cache_item_to_file: [vnet_addrinfo.c:6857] rename() failed 13 0xd
      04:17:41.693 [29320.15416] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1858] cache_item_to_file() failed 0
      0x0
      04:17:41.693 [29320.15416] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:41.708 [29320.15416] <2> logconnections: BPCD CONNECT FROM 10.44.72.40.57570 TO 10.44.71.45.1556 fd = 604
      04:17:41.708 [29320.15416] <2> vnet_connect_to_vnetd_bpcd: js_bpcd_info: 000000000203B540
      04:17:41.708 [29320.15416] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:41.739 [29320.15416] <8> do_pbx_service: [vnet_connect.c:2581] via PBX VNETD CONNECT FROM 10.44.72.40.57572 TO 10.
      44.71.45.1556 fd = 608
      04:17:41.755 [29320.15416] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SO
      CKET 10 0xa
      04:17:41.755 [29320.15416] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 52696
      04:17:41.818 [29320.15416] <2> bpcr_get_version_rqst: bpcd version: 07730000
      1 1 1
      10.44.72.40:57570 -> 10.44.71.45:1556
      10.44.72.40:57572 -> 10.44.71.45:1556
      <2>bptestbpcd: EXIT status = 0
      04:17:41.833 [29320.15416] <2> bptestbpcd: EXIT status = 0

      C:\temp>bptestbpcd -host qtc-db068p -debug
      04:17:42.052 [27232.29796] <2> bptestbpcd: VERBOSE = 0
      04:17:42.068 [27232.29796] <8> cache_item_to_file: [vnet_addrinfo.c:6857] rename() failed 13 0xd
      04:17:42.068 [27232.29796] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1858] cache_item_to_file() failed 0
      0x0
      04:17:42.068 [27232.29796] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:42.083 [27232.29796] <16> vnet_connect_with_opts: connect() failed: 10048
      04:17:42.083 [27232.29796] <16> vnet_proxy_helper_connect_try: vnet_connect_with_opts() failed: 10
      04:17:42.083 [27232.29796] <16> vnet_proxy_helper_connect_try: js_helper = {"service": "outbound_proxy", "sockaddr": {"f
      amily": {"number": 2, "symbol": "AF_INET", "description": "IPv4"}, "length": 16, "ipstr": "127.0.0.1", "port": 62130, "i
      p_port": "127.0.0.1:62130"}, "pid": 4316}
      04:17:42.083 [27232.29796] <16> vnet_proxy_helper_connect_try: ../../libvlibs/vnet_proxy.c.1551: status = 10, JSON strin
      g = {"service": "outbound_proxy", "sockaddr": {"family": {"number": 2, "symbol": "AF_INET", "description": "IPv4"}, "len
      gth": 16, "ipstr": "127.0.0.1", "port": 62130, "ip_port": "127.0.0.1:62130"}, "pid": 4316}
      04:17:42.146 [27232.29796] <2> logconnections: BPCD CONNECT FROM 10.44.72.40.57583 TO 10.44.71.45.1556 fd = 564
      04:17:42.146 [27232.29796] <2> vnet_connect_to_vnetd_bpcd: js_bpcd_info: 0000000002E5BAE0
      04:17:42.177 [27232.29796] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:42.208 [27232.29796] <8> do_pbx_service: [vnet_connect.c:2581] via PBX VNETD CONNECT FROM 10.44.72.40.57586 TO 10.
      44.71.45.1556 fd = 600
      04:17:42.208 [27232.29796] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SO
      CKET 10 0xa
      04:17:42.208 [27232.29796] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 52701
      04:17:42.239 [27232.29796] <2> put_string: cannot write data to network:  An existing connection was forcibly closed by
      the remote host.
      04:17:42.239 [27232.29796] <2> bpcr_put_vnetd_forward_socket: put_string 52701 failed: 10054
      04:17:42.239 [27232.29796] <2> local_bpcr_connect: bpcr_put_vnetd_forward_socket failed: 24
      04:17:42.239 [27232.29796] <2> ConnectToBPCD: bpcd_connect_and_verify(qtc-db068p, qtc-db068p) failed: 24
      04:17:42.239 [27232.29796] <16> bptestbpcd main: JSON proxy message = {"allow_large_status": {"timestamp": 1538738262, "
      who": "vnet_tss_init", "line_number": 32, "comment": "allow vnet status > 255", "data": true}, "direct_connect": {"times
      tamp": 1538738262, "who": "connect_to_service", "line_number": 834, "comment": "connect parameters", "data": {"who": "vn
      et_connect_to_vnetd_bpcd", "host": "qtc-db068p", "service": "vnetd", "override_required_interface": null, "extra_tries_o
      n_connect": 0, "getsock_disable_to": 0, "overide_connect_timeout": 0, "connect_options": null}}, "proxy_request": {"time
      stamp": 1538738262, "who": "vnet_proxy_build_request", "line_number": 3300, "comment": "request to local proxy", "data":
       {"bpcd_info": {"remote_client": "qtc-db068p", "remote_host": "qtc-db068p", "remote_probably_dhcp": false, "proxy_flag":
       32, "proxy_flag_hex": "0x00000020", "cmd_sock": 564}, "i_am_daemon": false, "domain_constraints": {}, "service": "vnetd
      ", "auth_only": false, "pid": 27232, "ssa": false, "local_user": "p-fazhar1@PROD", "host": "qtc-db068p", "peer_host": "q
      tc-db068p", "isTestConnection": true, "peer_client": "qtc-db068p", "local_client": "qtc-bku001.prod.ds.russell.com", "lo
      cal_dhcp_interval": 0, "peer_dhcp_info": null, "local_hostname": "qtc-bku001.prod.ds.russell.com", "secure_peer": false,
       "resilient": false, "nbrntd_peer_addr": null, "nbrntd_sock_addr": null, "hand_back": false, "request_timeout": 14410}},
       "proxy_response": {"timestamp": 1538738262, "who": "vnet_proxy_parse_response", "line_number": 3472, "comment": "respon
      se from local proxy", "data": {"status": 0, "local_proxy_info": {}, "domain_constraints_set": {"process_hint": "78130727
      -87db-4f53-907c-6b4b501bdb85", "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": "qtc-bku001.prod.ds.russell.com"}, "statusmsgxml":
      "<?xml version=\"1.0\" encoding=\"utf-8\"?><StatusMsgDoc><StatusMsg NBUStatus=\"0\" Severity=\"0\"></StatusMsg></StatusM
      sgDoc>"}}, "status": {"timestamp": 1538738262, "who": "connect_to_service", "line_number": 981, "comment": "vnet status"
      , "data": 0}}
      <16>bptestbpcd main: Function ConnectToBPCD(qtc-db068p) failed: 24
      04:17:42.239 [27232.29796] <16> bptestbpcd main: Function ConnectToBPCD(qtc-db068p) failed: 24
      <16>bptestbpcd main: socket write failed
      04:17:42.255 [27232.29796] <16> bptestbpcd main: socket write failed
      <2>bptestbpcd: socket write failed
      04:17:42.255 [27232.29796] <2> bptestbpcd: socket write failed
      <2>bptestbpcd: EXIT status = 24
      04:17:42.271 [27232.29796] <2> bptestbpcd: EXIT status = 24
      socket write failed

      C:\temp>bptestbpcd -host qtc-db068p -debug
      04:17:42.302 [29656.31356] <2> bptestbpcd: VERBOSE = 0
      04:17:42.318 [29656.31356] <8> cache_item_to_file: [vnet_addrinfo.c:6857] rename() failed 13 0xd
      04:17:42.318 [29656.31356] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1858] cache_item_to_file() failed 0
      0x0
      04:17:42.318 [29656.31356] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:42.333 [29656.31356] <2> logconnections: BPCD CONNECT FROM 10.44.72.40.57588 TO 10.44.71.45.1556 fd = 604
      04:17:42.333 [29656.31356] <2> vnet_connect_to_vnetd_bpcd: js_bpcd_info: 0000000002C5AF40
      04:17:42.333 [29656.31356] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:42.380 [29656.31356] <8> do_pbx_service: [vnet_connect.c:2581] via PBX VNETD CONNECT FROM 10.44.72.40.57590 TO 10.
      44.71.45.1556 fd = 608
      04:17:42.380 [29656.31356] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SO
      CKET 10 0xa
      04:17:42.380 [29656.31356] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 52702
      04:17:42.458 [29656.31356] <2> bpcr_get_version_rqst: bpcd version: 07730000
      1 1 1
      10.44.72.40:57588 -> 10.44.71.45:1556
      10.44.72.40:57590 -> 10.44.71.45:1556
      <2>bptestbpcd: EXIT status = 0
      04:17:42.474 [29656.31356] <2> bptestbpcd: EXIT status = 0

      C:\temp>bptestbpcd -host qtc-db068p -debug
      04:17:42.505 [25828.31492] <2> bptestbpcd: VERBOSE = 0
      04:17:42.521 [25828.31492] <8> cache_item_to_file: [vnet_addrinfo.c:6857] rename() failed 13 0xd
      04:17:42.521 [25828.31492] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1858] cache_item_to_file() failed 0
      0x0
      04:17:42.521 [25828.31492] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:42.536 [25828.31492] <2> logconnections: BPCD CONNECT FROM 10.44.72.40.57596 TO 10.44.71.45.1556 fd = 604
      04:17:42.536 [25828.31492] <2> vnet_connect_to_vnetd_bpcd: js_bpcd_info: 00000000027CAF40
      04:17:42.536 [25828.31492] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:42.583 [25828.31492] <8> do_pbx_service: [vnet_connect.c:2581] via PBX VNETD CONNECT FROM 10.44.72.40.57598 TO 10.
      44.71.45.1556 fd = 616
      04:17:42.583 [25828.31492] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SO
      CKET 10 0xa
      04:17:42.583 [25828.31492] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 52704
      04:17:42.646 [25828.31492] <2> bpcr_get_version_rqst: bpcd version: 07730000
      1 1 1
      10.44.72.40:57596 -> 10.44.71.45:1556
      10.44.72.40:57598 -> 10.44.71.45:1556
      <2>bptestbpcd: EXIT status = 0
      04:17:42.661 [25828.31492] <2> bptestbpcd: EXIT status = 0

      C:\temp>bptestbpcd -host qtc-db068p -debug
      04:17:43.396 [28580.27880] <2> bptestbpcd: VERBOSE = 0
      04:17:43.411 [28580.27880] <8> cache_item_to_file: [vnet_addrinfo.c:6857] rename() failed 13 0xd
      04:17:43.411 [28580.27880] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1858] cache_item_to_file() failed 0
      0x0
      04:17:43.411 [28580.27880] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:43.427 [28580.27880] <2> logconnections: BPCD CONNECT FROM 10.44.72.40.57637 TO 10.44.71.45.1556 fd = 564
      04:17:43.427 [28580.27880] <2> vnet_connect_to_vnetd_bpcd: js_bpcd_info: 000000000270B840
      04:17:43.427 [28580.27880] <2> vnet_pbxConnect_ex: pbxConnectExEx Succeeded
      04:17:43.474 [28580.27880] <8> do_pbx_service: [vnet_connect.c:2581] via PBX VNETD CONNECT FROM 10.44.72.40.57640 TO 10.
      44.71.45.1556 fd = 584
      04:17:43.474 [28580.27880] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:458] VN_REQUEST_CONNECT_FORWARD_SO
      CKET 10 0xa
      04:17:43.474 [28580.27880] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:483] ipc_string 52713
      04:17:43.536 [28580.27880] <2> bpcr_get_version_rqst: bpcd version: 07730000
      1 1 1
      10.44.72.40:57637 -> 10.44.71.45:1556
      10.44.72.40:57640 -> 10.44.71.45:1556
      <2>bptestbpcd: EXIT status = 0
      04:17:43.552 [28580.27880] <2> bptestbpcd: EXIT status = 0

       

      support case is also opened and its not escalated to engineering team with windows and n/w expert from veritas side.its been more than week now.

      • Marianne's avatar
        Marianne
        Level 6

        You may want to add -verbose and also check client's bpcd log.

        We see winsock errors in  bptestbpcd output : 10048 and 10054:

        04:17:42.083 [27232.29796] <16> vnet_connect_with_opts: connect() failed: 10048

        04:17:42.239 [27232.29796] <2> bpcr_put_vnetd_forward_socket: put_string 52701 failed: 10054

        http://www.destructor.de/firebird/winsockerrors.htm    

        10048 WSAEADDRINUSE Address already in use

         

        10054 WSAECONNRESET Connection reset by peer