Forum Discussion

rblaas's avatar
rblaas
Level 3
10 years ago

Random failure with status code 23

Hi all,

Could someone point me in the right direction? 

I have this problem which randomly occurs . 

I am backing up a physical client (mac OS X 10.6.8) and this client has 2 volumes. 

Most of the times the backup runs successfully. but now and then the backup fails with status 23. 

I can connect to the client via telnet on port 13782

DNS resolving works to. 

Here is some logging:

01/27/2015 11:10:14 - Info nbjm (pid=26156) starting backup job (jobid=4178) for client delage.xxxx.nl, policy PHYSICAL_LINUX_SPECIAL, schedule Daily_Dinc
01/27/2015 11:10:15 - Info bpbrm (pid=183283) delage.xxxx.nl is the host to backup data from
01/27/2015 11:10:15 - Info bpbrm (pid=183283) reading file list for client
01/27/2015 11:10:15 - estimated 1915622 kbytes needed
01/27/2015 11:10:15 - Info nbjm (pid=26156) started backup (backupid=delage.xxxx.nl_1422353415) job for client delage.xxxx.nl, policy PHYSICAL_LINUX_SPECIAL, schedule Daily_Dinc on storage unit STU_MSDP_NETBACKUP
01/27/2015 11:10:15 - started process bpbrm (pid=183283)
01/27/2015 11:10:16 - Info bpbrm (pid=183283) accelerator enabled
01/27/2015 11:10:16 - Error bpbrm (pid=183283) bpcd on delage.xxxx.nl exited with status 23: socket read failed
01/27/2015 11:10:16 - Info bpbkar (pid=0) done. status: 23: socket read failed
01/27/2015 11:10:16 - end writing
socket read failed  (23)

 

Client and Appliance running NetBackup v7.6.1

 

Backup and Recovery
MAC Agent
NetBackup Appliance

11 Replies

Sort By
  • SymTerry's avatar
    SymTerry
    Level 6
    10 years ago

    DNS may be working wone way but coming back another. Please follow the solution in TECH54563
     to check long name, short name and reverse DNS via the bpclntcmd command.

  • rblaas's avatar
    rblaas
    Level 3
    10 years ago

    @SymTerry: Why should I check the shortname? Everything is setup with FQDN. 

     

    I have run the command using FQDN and it works fine. 

     

    Also good to know that since yesterday 14.00 the job ran without problems (did not change a thing) Now I have to wait untill it fails again.... 

    (this policy runs every hour)

     

     

  • rblaas's avatar
    rblaas
    Level 3
    10 years ago

    Spoke to soon.. the 9.00 run failed for one partition... (how is that possible anyway...) 

    Other partition runs fine..

     

  • RiaanBadenhorst's avatar
    RiaanBadenhorst
    Level 6
    10 years ago

    If you're running multiple datastreams it kicks of independent process (bpbkar) for each partition. So one can fail and the rest can survive.

  • rblaas's avatar
    rblaas
    Level 3
    10 years ago

    @Riaan: where can I find the bpbkar log file? 

    I have looked in /usr/open/netbackup/logs/  and /var/log/ 

    Or maybe I should turn on this logging first ?

    EDIT: Nevermind.. I found the option.. I have now created the directory, so the next time it fails I should have some more detailed logging

  • RiaanBadenhorst's avatar
    RiaanBadenhorst
    Level 6
    10 years ago

    Cool :)

     

    Is there maybe AV software on that MAC? Something that can be killing / stopping the backup processes?

  • rblaas's avatar
    rblaas
    Level 3
    10 years ago

    @Riaan: No there is no AV on the mac. Will have to wait untill the next failure for more troubleshooting.. 

    The job/partition which failed at 9.00 has restarted (as it should) and ran fine. Job at 10.00 ran fine too... 

     

     

  • rblaas's avatar
    rblaas
    Level 3
    10 years ago

    Ok,

     

    This is annoying...

    Backup has failed. Doesn't even do a retry.. 

    Have NO log on client! 

    What now ?

     

     

  • rblaas's avatar
    rblaas
    Level 3
    10 years ago

    I found some logging on the NetBackup Appliance (bpbrm)

    16:10:33.854 [66498] <2> logparams: -backup -S netbackup -c xxxx.tros.nl -ct 0 -ru root -cl PHYSICAL_LINUX_SPECIAL -sched Daily_Dinc -bt 1422457833 -dt 3902 -st 1 -b xxxx.tros.nl_1422457833 -mediasvr netbackup -jobid 4581 -jobgrpid 4580 -masterversion 760000 -maxfrag 51200 -bpstart_time 1422458133 -reqid -1421688207 -mt 0 -to 0 -stunit STU_MSDP_NETBACKUP -rl 1 -rp 1209600 -eari 0 -p PureDiskVolume -mst 6 -flags 2 -storagesvr netbackup -sts_type PureDisk -use_ofb -use_otm -jm -secure 1 -kl 13 -rg root -fso -fscp -stream_count 2 -stream_number 2 -connect_options 16974338 
    16:10:33.854 [66498] <4> bpbrm main: ensured stderr cannot be used
    16:10:33.855 [66498] <2> bpbrm main: max_entries_per_add = 5000
    16:10:33.856 [66498] <2> read_client: dname=., offline=0, online_at=0 offline_at=0
    16:10:33.856 [66498] <2> read_client: dname=.., offline=0, online_at=0 offline_at=0
    16:10:33.856 [66498] <2> read_client: dname=CO_0, offline=0, online_at=0 offline_at=0
    16:10:33.856 [66498] <2> read_client: dname=OA_0, offline=0, online_at=0 offline_at=0
    16:10:33.856 [66498] <2> read_client: dname=host_info, offline=0, online_at=0 offline_at=0
    16:10:33.856 [66498] <2> read_host_info: CONNECT_NON_RES_PORT 2
    16:10:33.856 [66498] <2> read_host_info: DYNAMIC_ADDRESS 0
    16:10:33.856 [66498] <2> read_host_info: FREE_BROWSE 0
    16:10:33.856 [66498] <2> read_host_info: LIST_RESTORE 0
    16:10:33.856 [66498] <2> read_host_info: MAX_JOBS_THIS_CLIENT 3
    16:10:33.856 [66498] <2> read_host_info: NO_CALLBACK 2
    16:10:33.856 [66498] <2> read_host_info: WOFB_ENABLED 1
    16:10:33.856 [66498] <2> read_host_info: WOFB_FIM 1
    16:10:33.856 [66498] <2> read_host_info: WOFB_USAGE 0
    16:10:33.856 [66498] <2> read_host_info: WOFB_ERROR 0
    16:10:33.856 [66498] <2> read_host_info: DAEMON_PORT_TYPE 3
    16:10:33.856 [66498] <2> read_host_info: OST_CLIENT_DIRECT 0
    16:10:33.856 [66498] <2> read_host_info: OST_PROXY 0
    16:10:33.856 [66498] <2> read_host_info: OST_PROXY_SERVER *NULL*
    16:10:33.856 [66498] <2> read_host_info: OST_CLIENT_DIRECT_RESTORE 0
    16:10:33.856 [66498] <2> db_freeEXDB_INFO: ?
    16:10:33.868 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.869 [66498] <2> logconnections: BPCD CONNECT FROM xx.xx.xx.150.40234 TO xx.xx.yy.8.1556 fd = 4
    16:10:33.873 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.874 [66498] <8> do_pbx_service: [vnet_connect.c:2156] via PBX VNETD CONNECT FROM xx.xx.xx.150.39411 TO xx.xx.yy.8.1556 fd = 5
    16:10:33.874 [66498] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:440] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
    16:10:33.875 [66498] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:457] ipc_string /usr/openv/var/tmp/vnet-66559422457833871812000000341-5ihqJV
    16:10:33.957 [66498] <2> bpcr_get_version_rqst: bpcd version: 07610000
    16:10:33.958 [66498] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 4
    16:10:33.958 [66498] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 5
    16:10:33.958 [66498] <2> bpcr_get_version_rqst: bpcd version: 07610000
    16:10:33.964 [66498] <2> read_legacy_touch_file: Found /usr/openv/netbackup/db/config/SIZE_DATA_BUFFERS_DISK; requested from (miscsvr.c.521).
    16:10:33.964 [66498] <2> read_legacy_touch_file: 2097152 read ; requested from (miscsvr.c.521).
    16:10:33.965 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.965 [66498] <2> job_connect: SO_KEEPALIVE set on socket 4 for client netbackup
    16:10:33.965 [66498] <2> logconnections: BPJOBD CONNECT FROM xx.xx.xx.150.58981 TO xx.xx.xx.150.1556 fd = 4
    16:10:33.965 [66498] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
    16:10:33.966 [66498] <2> job_connect: Connected to the host netbackup contype 53 jobid <4581> socket <4>
    16:10:33.966 [66498] <2> job_connect: Connected on port 58981
    16:10:33.966 [66498] <2> bpbrm main: send_3_0_client_params = 1
    16:10:33.969 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.969 [66498] <2> logconnections: BPCD CONNECT FROM xx.xx.xx.150.44266 TO xx.xx.yy.8.1556 fd = 5
    16:10:33.971 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.971 [66498] <8> do_pbx_service: [vnet_connect.c:2156] via PBX VNETD CONNECT FROM xx.xx.xx.150.54381 TO xx.xx.yy.8.1556 fd = 6
    16:10:33.972 [66498] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:440] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
    16:10:33.972 [66498] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
    16:10:33.972 [66498] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
    16:10:33.972 [66498] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
    16:10:33.972 [66498] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:454] status 9 0x9
    16:10:33.972 [66498] <2> bpcr_vnetd_connect_forward_socket_begin: vnet_vnetd_connect_forward_socket_begin() failed: 9
    16:10:33.972 [66498] <2> local_bpcr_connect: bpcr_vnetd_connect_forward_socket_begin failed: 23
    16:10:33.972 [66498] <2> ConnectToBPCD: bpcd_connect_and_verify(xxxx.tros.nl, xxxx.tros.nl) failed: 23
    16:10:33.972 [66498] <16> bpbrm start_bpcd_stat: bpcd on xxxx.tros.nl exited with status 23: socket read failed
    16:10:33.972 [66498] <4> db_error_add_to_file: bpcd on xxxx.tros.nl exited with status 23: socket read failed
    16:10:33.972 [66498] <2> bpbrm start_bpcd: ../bpbrm.c.23102: start_bpcd_stat failed: 23 23 0x00000017
    16:10:33.973 [66498] <2> bpbrm kill_child_process: start
    16:10:33.973 [66498] <2> bpbrm Exit: attempting to send mail to root on xxxx.tros.nl
    16:10:33.974 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.975 [66498] <2> logconnections: BPCD CONNECT FROM xx.xx.xx.150.55643 TO xx.xx.yy.8.1556 fd = 5
    16:10:33.976 [66498] <2> vnet_pbxConnect: pbxConnectEx Succeeded
    16:10:33.977 [66498] <8> do_pbx_service: [vnet_connect.c:2156] via PBX VNETD CONNECT FROM xx.xx.xx.150.33774 TO xx.xx.yy.8.1556 fd = 6
    16:10:33.977 [66498] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:440] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
    16:10:33.978 [66498] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:457] ipc_string /usr/openv/var/tmp/vnet-66563422457833974589000000341-5ihqJV
    16:10:34.062 [66498] <2> bpcr_get_version_rqst: bpcd version: 07610000
    16:10:34.062 [66498] <2> bpbrm Exit: OUT_SOCK from bpcr = 5
    16:10:34.062 [66498] <2> bpbrm Exit: IN_SOCK from bpcr = 6
    16:10:34.062 [66498] <2> bpcr_get_version_rqst: bpcd version: 07610000
    16:10:34.063 [66498] <2> bpcr_get_version_rqst: bpcd version: 07610000
    16:10:34.092 [66498] <2> bpcr_get_version_rqst: bpcd version: 07610000
    16:10:34.107 [66498] <2> bpbrm Exit: client backup EXIT STATUS 23: socket read failed
    16:10:34.111 [66498] <2> job_monitoring_exex: ACK disconnect
    16:10:34.111 [66498] <2> job_disconnect: Disconnected

     

    What is going on here (Bold text)?