few streams failed with status code 49 client did not start 12/02/2014 09:58:23 - end writing

[symsonu]

Below is the logs from the detailed status of job

12/02/2014 08:34:51 - Info nbjm (pid=5922) starting backup job (jobid=20968) for client ossbkupIP, policy OSS_i386_DATA_ossbkupIP_syb1bkupIP, schedule Daily_Incr
12/02/2014 08:34:51 - Info nbjm (pid=5922) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=20968, request id:{68FF7CD4-79C3-11E4-97E9-0017A477FC20})
12/02/2014 08:34:51 - requesting resource bksrst1-hcart-robot-tld-0
12/02/2014 08:34:51 - requesting resource bksrst1.NBU_CLIENT.MAXJOBS.ossbkupIP
12/02/2014 08:34:51 - requesting resource bksrst1.NBU_POLICY.MAXJOBS.OSS_i386_DATA_ossbkupIP_syb1bkupIP
12/02/2014 08:34:51 - awaiting resource bksrst1-hcart-robot-tld-0. No drives are available.
12/02/2014 09:12:32 - Info nbrb (pid=5900) Limit has been reached for the logical resource bksrst1.NBU_CLIENT.MAXJOBS.ossbkupIP
12/02/2014 09:58:08 - granted resource  bksrst1.NBU_CLIENT.MAXJOBS.ossbkupIP
12/02/2014 09:58:08 - granted resource  bksrst1.NBU_POLICY.MAXJOBS.OSS_i386_DATA_ossbkupIP_syb1bkupIP
12/02/2014 09:58:08 - granted resource  1128L4
12/02/2014 09:58:08 - granted resource  HP.ULTRIUM4-SCSI.003
12/02/2014 09:58:08 - granted resource  bksrst1-hcart-robot-tld-0
12/02/2014 09:58:08 - estimated 0 kbytes needed
12/02/2014 09:58:08 - Info nbjm (pid=5922) started backup (backupid=ossbkupIP_1417489088) job for client ossbkupIP, policy OSS_i386_DATA_ossbkupIP_syb1bkupIP, schedule Daily_Incr on storage unit bksrst1-hcart-robot-tld-0
12/02/2014 09:58:08 - started process bpbrm (pid=24154)
12/02/2014 09:58:09 - Info bpbrm (pid=24154) ossbkupIP is the host to backup data from
12/02/2014 09:58:09 - Info bpbrm (pid=24154) reading file list from client
12/02/2014 09:58:09 - Info bpbrm (pid=24154) starting bpbkar on client
12/02/2014 09:58:09 - Info bpbkar (pid=0) Starting bpstart_notify script
12/02/2014 09:58:09 - connecting
12/02/2014 09:58:09 - connected; connect time: 0:00:00
12/02/2014 09:58:23 - Error bpbrm (pid=24154) client ossbkupIP aborted
12/02/2014 09:58:23 - Info bpbkar (pid=0) done. status: 49: client did not start
12/02/2014 09:58:23 - end writing
client did not start  (49)

I figured out that below two commands reporting different host names

admrst1{root} # ./bpclntcmd -pn
expecting response from server bksrst1
admrst1-bk *NULL* 10.224.16.101 25614
admrst1{root} # ./bpclntcmd -self
current domain = rstom.net
NIS does not seem to be running: (10) can't communicate with ypbind
gethostname() returned: ossbkupIP
host ossbkupIP: ossbkupIP at 10.224.16.102
aliases:     ossbkupIP     10.224.16.102
 getfqdn: Error 0
admrst1{root} #

admrst1-bk and ossbkupIP are two IPs in  backup network but we  have created policy using ossbkupIP

I am thinking that bpclntcmd  is showing admrst1-bck  is wrong

How to correct  this ?

Please find logs from bprd while running the above command

7:06:45.405 [10601] <2> process_request: EXIT STATUS 0
17:06:45.444 [10476] <2> listen_loop: do_schild = 1
17:06:45.444 [10476] <2> childterm: pid=10601 exit=0, signo=0 core=no
17:06:45.444 [10476] <2> schild: wait2() ECHILD
17:06:58.475 [10476] <2> listen_loop: initial schedule event
17:06:58.516 [10476] <2> launch: /usr/openv/netbackup/bin/admincmd/bpstsinfo, pid=10848
17:06:58.517 [10476] <2> listen_loop: do_schild = 1
17:06:58.517 [10476] <2> childterm: pid=10848 exit=0, signo=0 core=no
17:06:58.517 [10476] <2> schild: wait2() ECHILD
17:07:17.647 [10476] <2> vnet_pbxAcceptSocket: Accepted sock[10] from 10.224.16.104:45137
17:07:17.648 [10476] <2> bprd: socket fd from accept() is 10
17:07:17.649 [10476] <2> listen_loop: request complete
17:07:17.654 [11077] <2> logconnections: BPRD ACCEPT FROM 10.224.16.104.45137 TO 10.224.16.105.1556 fd = 10
17:07:17.654 [11077] <2> process_request: setsockopt SO_LINGER on 10 succeeded.
17:07:17.654 [11077] <2> vnet_pcache_init_table: [vnet_private.c:235] starting cache size 200 0xc8
17:07:17.657 [11077] <2> vnet_cached_getnameinfo: [vnet_addrinfo.c:1895] found via getnameinfo OUR_HOST=admrst2-bk IPSTR=10.224.16.104
17:07:17.657 [11077] <2> connected_peer: Connection from host admrst2-bk, 10.224.16.104, on non-reserved port 45137
17:07:17.657 [11077] <2> db_valid_master_server: admrst2-bk is not a valid server
17:07:17.658 [11077] <8> vnet_check_vxss_server_magic: [vnet_vxss_helper.c:495] VxSS magic 329199 0x505ef
17:07:17.658 [11077] <8> vnet_check_vxss_server_magic: [vnet_vxss_helper.c:496] remote_vxss 45 0x2d
17:07:17.658 [11077] <8> vnet_check_vxss_server_magic: [vnet_vxss_helper.c:538] Ignoring VxSS authentication 2 0x2
17:07:17.658 [11077] <2> process_request: command C_CLIENT_ID (45) received
17:07:17.658 [11077] <2> process_request: admrst2-bk is 7.5
17:07:17.658 [11077] <2> get_ccname: determine configured name for admrst2-bk
17:07:17.658 [11077] <2> ConnectionCache::connectAndCache: Acquiring new connection for host bksrst1, query type 84
17:07:17.658 [11077] <2> vnet_same_host_and_update: [vnet_addrinfo.c:2876] matched as locals NAME1=bksrst1 NAME2=localhost
17:07:17.658 [11077] <2> vnet_in_resilient_network: [vnet_addrinfo.c:8752] ignoring local host 0 0x0
17:07:17.658 [11077] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
17:07:17.658 [11077] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4776] Local [strong] check, using interface  ANY
17:07:17.659 [11077] <2> async_connect: [vnet_connect.c:1433] connect immediate CONNECT FROM 10.224.16.105.58202 TO 10.224.16.105.13721 fd = 6
17:07:17.659 [11077] <2> connect_to_service: connect succeeded STATUS (0) SUCCESS FROM 0.0.0.0 TO bksrst1 10.224.16.105 bpdbm
17:07:17.659 [11077] <2> logconnections: BPDBM CONNECT FROM 10.224.16.105.58202 TO 10.224.16.105.13721 fd = 6
17:07:17.659 [11077] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
17:07:17.681 [11077] <2> get_ccname: unable to get configured name: no entity was found (227)
17:07:17.712 [10476] <2> listen_loop: do_schild = 1
17:07:17.712 [10476] <2> childterm: pid=11077 exit=0, signo=0 core=no
17:07:17.712 [10476] <2> schild: wait2() ECHILD
17:07:44.715 [10476] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link local 0 0x0
17:08:45.721 [10476] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link local 0 0x0
17:09:46.737 [10476] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link local 0 0x0
17:10:47.744 [10476] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link local 0 0x0
17:11:43.749 [10476] <2> ConnectionCache::connectAndCache: Acquiring new connection for host bksrst1, query type 98
17:11:43.749 [10476] <2> vnet_same_host_and_update: [vnet_addrinfo.c:2876] matched as locals NAME1=bksrst1 NAME2=localhost
17:11:43.749 [10476] <2> vnet_in_resilient_network: [vnet_addrinfo.c:8752] ignoring local host 0 0x0
17:11:43.749 [10476] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
17:11:43.749 [10476] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4776] Local [strong] check, using interface  ANY
17:11:43.750 [10476] <2> async_connect: [vnet_connect.c:1433] connect immediate CONNECT FROM 10.224.16.105.58293 TO 10.224.16.105.13721 fd = 10
17:11:43.750 [10476] <2> connect_to_service: connect succeeded STATUS (0) SUCCESS FROM 0.0.0.0 TO bksrst1 10.224.16.105 bpdbm
17:11:43.750 [10476] <2> logconnections: BPDBM CONNECT FROM 10.224.16.105.58293 TO 10.224.16.105.13721 fd = 10
17:11:43.750 [10476] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
17:11:43.750 [10476] <2> db_end: Need to collect reply
17:11:43.801 [10476] <2> launch: /usr/openv/netbackup/bin/admincmd/bpstsinfo, pid=11749
17:11:43.805 [10476] <2> listen_loop: do_schild = 1
17:11:43.805 [10476] <2> childterm: pid=11749 exit=0, signo=0 core=no
17:11:43.805 [10476] <2> schild: wait2() ECHILD
17:11:48.806 [10476] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link local 0 0x0
17:12:49.813 [10476] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link loca

[revarooo]

status 49 means that bpbkar never starts. Enable logging on the client for bpcd and bpbkar and see if the logs are updated when the backup runs.

Master thinks client is ossbkupIP

You ran the bpclntcmd command from host admrst1 - what is this?

Login to the media server that is responsible for running the backup and run:

bptestbpcd -client ossbkupIP -verbose

What is the output?

[symsonu]

This admrst1 is the client on which backup interface is ossbkupIP.

# ./bptestbpcd -client ossbkupIP -verbose
1 1 1
10.224.16.105:60275 -> 10.224.16.102:1556
10.224.16.105:60276 -> 10.224.16.102:1556
PEER_NAME = bksrst1
HOST_NAME = ossbkupIP
CLIENT_NAME = ossbkupIP
VERSION = 0x07500004
PLATFORM = solaris_x86_10_64
PATCH_VERSION = 7.5.0.4
SERVER_PATCH_VERSION = -1.-1.-1.-1
MASTER_SERVER = bksrst1
EMM_SERVER = bksrst1
NB_MACHINE_TYPE = CLIENT
10.224.16.105:60277 -> 10.224.16.102:1556
#

admrst1{root} # ./bpclntcmd -pn
expecting response from server bksrst1
admrst1-bk *NULL* 10.224.16.101 25614----> should not this command gives ossbkupIP rather than admrst1-bk?

doesnot this output means that master thinks  the client is admrst-bk?

[revarooo]

Yes. The client communicates to the master and the master identifies the IP and resolves it to the hostname you have configured in hosts or DNS.

did you run the bptestbpcd -client command from the media server? If you did it thinks the IP is 10.224.16.102 - is that correct?

Login to the media server that will run the backup and run:

bpclntcmd -hn ossbkupIP

bpclntcmd -ip <ip_address>    (use the IP address that is returned from the -hn command)

[symsonu]

# bpclntcmd -hn ossbkupIP
host ossbkupIP: ossbkupIP at 10.224.16.102
aliases:     ossbkupIP     10.224.16.102
# bpclntcmd -ip 10.224.16.102
host 10.224.16.102: ossbkupIP at 10.224.16.102
aliases:     ossbkupIP     10.224.16.102
#

[symsonu]

Actually the concern I had which I think you didnt answer

aadmrst1{root} # ./bpclntcmd -pn
expecting response from server bksrst1
admrst1-bk *NULL* 10.224.16.101 25614

How does the master identifies the IP in above command , because it it determining the wrong IP

as mentioned by me above

[Marianne]

Double-check /etc/hosts file on the master and media server and also double-check client's IP address.

Show us output of 'bpclntcmd -self' and 'ifconfig' on the client.

bpclntcmd -pn shows this IP: 10.224.16.101 

[revarooo]

symsonu,

Your client is communicating to the master via 10.224.16.101 - the master is then resolving this to admrst1-bk

That is down to your routing.

You can force ALL traffic from the client to use 10.224.16.101 by adding

REQUIRED_INTERFACE = 10.224.16.101

Or you can use the PREFERRED_NETWORK option:

http://www.symantec.com/business/support/index?page=content&id=HOWTO60779

[symsonu]

On Client :-->

admrst1{root} # ./bpclntcmd -self
current domain = rstom.net
NIS does not seem to be running: (10) can't communicate with ypbind
gethostname() returned: ossbkupIP
host ossbkupIP: ossbkupIP at 10.224.16.102
aliases:     ossbkupIP     10.224.16.102
 getfqdn: Error 0

admrst1{root} # ifconfig -a
lo0: flags=2001000849<UP,LOOPBACK,RUNNING,MULTICAST,IPv4,VIRTUAL> mtu 8232 index 1
        inet 127.0.0.1 netmask ff000000
bnxe1: flags=9040843<UP,BROADCAST,RUNNING,MULTICAST,DEPRECATED,IPv4,NOFAILOVER> mtu 1500 index 2
        inet 10.224.16.13 netmask ffffffc0 broadcast 10.224.16.63
        groupname pub_mnic
        ether 0:17:a4:77:fc:6
bnxe2: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 5
        inet 200.200.200.15 netmask ffffff00 broadcast 200.200.200.255
        ether 0:17:a4:77:fc:c
bnxe3: flags=9040843<UP,BROADCAST,RUNNING,MULTICAST,DEPRECATED,IPv4,NOFAILOVER> mtu 1500 index 6
        inet 10.224.17.34 netmask ffffff80 broadcast 10.224.17.127
        groupname stor_mnic
        ether 0:17:a4:77:fc:e
bnxe8: flags=9040843<UP,BROADCAST,RUNNING,MULTICAST,DEPRECATED,IPv4,NOFAILOVER> mtu 1500 index 7
        inet 10.224.16.12 netmask ffffffc0 broadcast 10.224.16.63
        groupname pub_mnic
        ether 0:17:a4:77:fc:0
bnxe8:1: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 7
        inet 10.224.16.5 netmask ffffffc0 broadcast 10.224.16.63
bnxe8:2: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 7
        inet 10.224.16.9 netmask ffffffc0 broadcast 10.224.16.63
bnxe8:3: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 7
        inet 10.224.16.8 netmask ffffffc0 broadcast 10.224.16.63
bnxe8:4: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 7
        inet 10.224.16.11 netmask ffffffc0 broadcast 10.224.16.63
bnxe8:5: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 7
        inet 10.224.16.4 netmask ffffffc0 broadcast 10.224.16.63
bnxe10: flags=9040843<UP,BROADCAST,RUNNING,MULTICAST,DEPRECATED,IPv4,NOFAILOVER> mtu 1500 index 3
        inet 10.224.17.33 netmask ffffff80 broadcast 10.224.17.127
        groupname stor_mnic
        ether 0:17:a4:77:fc:8
bnxe10:1: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 3
        inet 10.224.17.32 netmask ffffff80 broadcast 10.224.17.127
bnxe11: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 4
        inet 10.224.16.101 netmask ffffffe0 broadcast 10.224.16.127
        ether 0:17:a4:77:fc:a
bnxe11:1: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 4
        inet 10.224.16.102 netmask ffffffe0 broadcast 10.224.16.127

[revarooo]

Add the required interface with the ip ending in 102

What is the result then?

[symsonu]

the communication and  entries of hosts file are all okay.

thing is that only few streams  i.e 4 or 5 out of 25 are failing .

if there is communicaton issue then all must be failing.

can you guys point me what could be the issue here ?

[Marianne]

As per revaroo's post on 2 Dec: "status 49 means that bpbkar never starts. Enable logging on the client for bpcd and bpbkar and see if the logs are updated when the backup runs."

[revarooo]

Again, please post up the bpbkar and bpcd logs from the client.

[symsonu]

I  enabled bpcd , bpbkar on client  and bpbrm logs  on media server

and can see below ebtries in bpbrm on media server  as below

19:30:11.050 [6639] <2> bpbrm main: received bpcd success message
19:30:11.148 [6639] <2> get_readline_type: Returning BPBRM_READ_INFORM_WHEN_DONE
19:30:11.148 [6639] <2> bpbrm main: from client ossbkupIP: INF - START bpstart_notify
19:30:11.148 [6639] <2> set_job_details: Tfile (21921): LOG 1418041811 4 bpbkar 0 Starting bpstart_notify script

19:30:11.148 [6639] <2> send_job_file: job ID 21921, ftype = 3 msg len = 57, msg = LOG 1418041811 4 bpbkar 0 Starting bpstart_notify script

19:30:16.048 [28128] <2> bpbrm main: ADDED FILES TO DB FOR ossbkupIP_1418038945 1000 /Backup/ombsnap/segment1/UETR/SubNetwork=RNSNK02/MeContext=RNSNK02/A20141205.1700+0700-1715+0700_SubNetwork=RNSNK02,MeContext=RNSNK02_10005_520189104556260_uetrfile.bin.gz
19:30:25.403 [28128] <2> bpbrm readline: EOF detected on NAME socket
19:30:25.403 [28128] <32> bpbrm main: unexpected termination of client ossbkupIP
19:30:25.403 [6639] <2> bpbrm readline: EOF detected on NAME socket
19:30:25.403 [6639] <16> bpbrm main: client ossbkupIP aborted
19:30:25.403 [28128] <2> set_job_details: Tfile (21920): LOG 1418041825 32 bpbrm 28128 unexpected termination of client ossbkupIP

19:30:25.403 [28128] <2> send_job_file: job ID 21920, ftype = 3 msg len = 73, msg = LOG 1418041825 32 bpbrm 28128 unexpected termination of client ossbkupIP

19:30:25.403 [6639] <2> set_job_details: Tfile (21921): LOG 1418041825 16 bpbrm 6639 client ossbkupIP aborted

19:30:25.403 [6639] <2> send_job_file: job ID 21921, ftype = 3 msg len = 54, msg = LOG 1418041825 16 bpbrm 6639 client ossbkupIP aborted

19:30:25.403 [28128] <4> db_error_add_to_file: unexpected termination of client ossbkupIP
19:30:25.404 [6639] <4> db_error_add_to_file: client ossbkupIP aborted
19:30:25.404 [28128] <2> bpbrm kill_child_process: start
19:30:25.404 [28128] <2> bpbrm wait_for_child: start
19:30:25.405 [6639] <2> bpbrm kill_child_process: start
19:30:25.405 [6639] <2> inform_client_of_status: INF - Server status = 49
19:30:25.405 [6639] <2> set_job_details: Tfile (21921): LOG 1418041825 4 bpbkar 0 done. status: 49: client did not start

19:30:25.405 [6639] <2> send_job_file: job ID 21921, ftype = 3 msg len = 65, msg = LOG 1418041825 4 bpbkar 0 done. status: 49: client did not start

19:30:25.405 [6639] <2> bpbrm Exit: client backup EXIT STATUS 49: client did not start
19:30:25.407 [6639] <2> vnet_close_socket_safely: [vnet.c:2029] safe close 0 0x0
19:30:26.032 [6703] <2> bpbrm main: INITIATING (VERBOSE = 5): version NetBackup 7.5 2012091610
19:30:26.032 [6703] <2> logparams: -backup -S bksrst1 -c ossbkupIP -ct 0 -ru root -cl OSS_i386_DATA_ossbkupIP_syb1bkupIP -sched Daily_Incr -bt 1418041825 -dt 140691 -st 1 -b ossbkupIP_1418041825 -mediasvr bksrst1 -jobid 21922 -jobgrpid 21903 -masterversion 750000 -maxfrag 1048576 -bpstart_time 1418042125 -reqid -1417516796 -mt 2 -to 0 -stunit bksrst1-hcart-robot-tld-0 -rl 3 -rp 2678400 -eari 0 -cj 2 -D 6 -rt 8 -rn 0 -pool OSSRC_Pool -use_ofb -use_otm -jm -secure 1 -kl 7 -rg root -fso -tir -tir_plus -nfsok -stream_count 22 -stream_number 18 -connect_options 16974338
19:30:26.032 [6703] <2> init_resilient_cache: [vnet_nbrntd.c:869] Initialize resilient cache. 0 0x0
19:30:26.032 [6703] <2> vnet_check_resilient_socket: [vnet_nbrntd.c:808] the socket is  0 0x0
19:30:26.032 [6703] <2> vnet_check_resilient_socket: [vnet_nbrntd.c:808] the socket is  2 0x2
19:30:26.033 [6703] <2> verify_client: bpbrm.c.37847: *connect_opts: 16974338 16974338 0x01030202
19:30:26.034 [6703] <2> read_client: ?
19:30:26.034 [6703] <2> read_client: dname=., offline=0, online_at=0 offline_at=0
19:30:26.034 [6703] <2> read_client: dname=.., offline=0, online_at=0 offline_at=0
19:30:26.034 [6703] <2> read_client: dname=CO_0, offline=0, online_at=0 offline_at=0
19:30:26.034 [6703] <2> read_client: dname=OA_0, offline=0, online_at=0 offline_at=0
19:30:26.034 [6703] <2> read_client: dname=host_info, offline=0, online_at=0 offline_at=0
19:30:26.034 [6703] <2> read_host_info: ?
19:30:26.034 [6703] <2> read_host_info: CONNECT_NON_RES_PORT 2
19:30:26.034 [6703] <2> read_host_info: DYNAMIC_ADDRESS 0
19:30:26.034 [6703] <2> read_host_info: FREE_BROWSE 0
19:30:26.034 [6703] <2> read_host_info: LIST_RESTORE 0
19:30:26.034 [6703] <2> read_host_info: MAX_JOBS_THIS_CLIENT 2
19:30:26.034 [6703] <2> read_host_info: NO_CALLBACK 2
19:30:26.034 [6703] <2> read_host_info: WOFB_ENABLED 0
19:30:26.034 [6703] <2> read_host_info: WOFB_FIM 1
19:30:26.034 [6703] <2> read_host_info: WOFB_USAGE 0
19:30:26.034 [6703] <2> read_host_info: WOFB_ERROR 0
19:30:26.034 [6703] <2> read_host_info: DAEMON_PORT_TYPE 3
19:30:26.034 [6703] <2> read_host_info: OST_CLIENT_DIRECT 0
19:30:26.034 [6703] <2> read_host_info: OST_PROXY 0
19:30:26.034 [6703] <2> read_host_info: OST_PROXY_SERVER *NULL*
19:30:26.034 [6703] <2> read_host_info: OST_CLIENT_DIRECT_RESTORE 0
19:30:26.034 [6703] <2> read_sec_info: ?
19:30:26.034 [6703] <2> read_sec_info: no sec_info: /usr/openv/netbackup/db/client/ossbkupIP/sec_info does not exist
19:30:26.034 [6703] <2> get_exdb_info1: ?
19:30:26.034 [6703] <2> read_exdb_info: ?
19:30:26.034 [6703] <2> read_exdb_info: no exdb_info files processed
19:30:26.034 [6703] <2> db_freeSEC_INFO: pinfo is NULL
19:30:26.034 [6703] <2> db_freeEXDB_INFO: ?
19:30:26.034 [6703] <2> db_freeEXDB_INFO: plist is NULL
19:30:26.035 [6703] <2> bpbrm start_bpcd_stat: bpbrm.c.22001: bpcd_client: ossbkupIP
19:30:26.035 [6703] <2> bpbrm start_bpcd_stat: bpbrm.c.22004: bpcd_client_hostname: ossbkupIP
19:30:26.035 [6703] <2> local_bpcr_connect: bpcr.c.278: connect_opts = 0x01000100 connect_opts2 = 0x01000100
19:30:26.035 [6703] <2> local_bpcr_connect: bpcr.c.285: connect_opts = 0x01000100
19:30:26.035 [6703] <2> local_bpcr_connect: bpcr.c.324: daemon_port_type = 0
19:30:26.036 [6703] <2> insert_if_not_dup: [vnet_addrinfo.c:5705] ignoring IPv6 link local 0 0x0
19:30:26.036 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.036 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.036 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.036 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.036 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.036 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.036 [6703] <2> async_connect: [vnet_connect.c:1477] connect in progress 1 0x1
19:30:26.038 [6703] <2> vnet_pbxConnect: pbxConnectEx Succeeded
19:30:26.038 [6703] <2> do_pbx_service: [vnet_connect.c:2116] via PBX bpcd CONNECT FROM 10.224.16.105.35607 TO 10.224.16.102.1556 fd = 5
19:30:26.038 [6703] <2> async_connect: [vnet_connect.c:1644] connect async CONNECT FROM 10.224.16.105.35607 TO 10.224.16.102.1556 fd = 5
19:30:26.038 [6703] <2> connect_to_service: connect succeeded STATUS (0) SUCCESS FROM 0.0.0.0 TO ossbkupIP 10.224.16.102 bpcd VIA pbx
19:30:26.038 [6703] <2> logconnections: BPCD CONNECT FROM 10.224.16.105.35607 TO 10.224.16.102.1556 fd = 5
19:30:26.038 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.038 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.039 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.039 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.039 [6703] <2> async_connect: [vnet_connect.c:1477] connect in progress 1 0x1
19:30:26.039 [6703] <2> vnet_pbxConnect: pbxConnectEx Succeeded
19:30:26.048 [6703] <8> do_pbx_service: [vnet_connect.c:2108] via PBX VNETD CONNECT FROM 10.224.16.105.35608 TO 10.224.16.102.1556 fd = 8
19:30:26.048 [6703] <2> async_connect: [vnet_connect.c:1644] connect async CONNECT FROM 10.224.16.105.35608 TO 10.224.16.102.1556 fd = 8
19:30:26.048 [6703] <2> connect_to_service: connect succeeded STATUS (0) SUCCESS FROM 0.0.0.0 TO 10.224.16.102 10.224.16.102 vnetd VIA pbx
19:30:26.048 [6703] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:443] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
19:30:26.109 [6703] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:460] ipc_string /tmp/vnet-18313418041826105264000000014-5SaiXJ
19:30:26.178 [6703] <2> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:471] hash_str1 3aab54b6e02902cb638fd99ef1d574b1
19:30:26.315 [6703] <2> bpcr_get_hostname_rqst: Server hostname length = 9
19:30:26.315 [6703] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 5
19:30:26.315 [6703] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 8
19:30:26.315 [6703] <2> verify_client: bpbrm.c.38170: hostname: bksrst1
19:30:26.315 [6703] <2> verify_client: bpbrm.c.38171: is_on: 0 0 0x00000000
19:30:26.378 [6703] <2> bpcr_get_version_rqst: bpcd version: 07500004
19:30:26.448 [6703] <2> verify_client: bpbrm.c.38174: bpcr_update_resiliency : 0 0 0x00000000
19:30:26.453 [6703] <2> verify_client: bpbrm.c.38197: *connect_opts: 16843008 16843008 0x01010100
19:30:26.454 [6703] <2> read_config_file: using 65536 value from /usr/openv/netbackup/db/config/SIZE_DATA_BUFFERS
19:30:26.454 [6703] <2> vnet_same_host_and_update: [vnet_addrinfo.c:2876] matched as locals NAME1=bksrst1 NAME2=localhost
19:30:26.454 [6703] <2> vnet_in_resilient_network: [vnet_addrinfo.c:8752] ignoring local host 0 0x0
19:30:26.454 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.454 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4776] Local [strong] check, using interface  ANY
19:30:26.455 [6703] <2> async_connect: [vnet_connect.c:1433] connect immediate CONNECT FROM 10.224.16.105.35609 TO 10.224.16.105.13723 fd = 5
19:30:26.455 [6703] <2> connect_to_service: connect succeeded STATUS (0) SUCCESS FROM 0.0.0.0 TO bksrst1 10.224.16.105 bpjobd
19:30:26.455 [6703] <2> job_connect: SO_KEEPALIVE set on socket 5 for client bksrst1
19:30:26.455 [6703] <2> logconnections: BPJOBD CONNECT FROM 10.224.16.105.35609 TO 10.224.16.105.13723 fd = 5
19:30:26.455 [6703] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
19:30:26.455 [6703] <2> job_connect: Connected to the host bksrst1 contype 53 jobid <21922> socket <5>
19:30:26.455 [6703] <2> job_connect: Connected on port 35609
19:30:26.455 [6703] <2> set_job_details: Tfile (21922): LOG 1418041826 4 bpbrm 6703 ossbkupIP is the host to backup data from

19:30:26.455 [6703] <2> send_job_file: job ID 21922, ftype = 3 msg len = 70, msg = LOG 1418041826 4 bpbrm 6703 ossbkupIP is the host to backup data from

19:30:26.455 [6703] <2> set_job_details: Tfile (21922): LOG 1418041826 4 bpbrm 6703 reading file list from client

19:30:26.455 [6703] <2> send_job_file: job ID 21922, ftype = 3 msg len = 58, msg = LOG 1418041826 4 bpbrm 6703 reading file list from client

19:30:26.456 [6703] <2> bpbrm main: File read = "/Backup/ossdg/ossrc/3pp"
19:30:26.456 [6703] <2> bpbrm main: File read = "CONTINUE"
19:30:26.456 [6703] <2> bpbrm main: send_3_0_client_params = 1
19:30:26.456 [6703] <2> local_bpcr_connect: bpcr.c.278: connect_opts = 0x01000100 connect_opts2 = 0x01000100
19:30:26.456 [6703] <2> local_bpcr_connect: bpcr.c.285: connect_opts = 0x01000100
19:30:26.456 [6703] <2> local_bpcr_connect: bpcr.c.324: daemon_port_type = 0
19:30:26.456 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.456 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.456 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.456 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.456 [6703] <2> vnet_sortaddrs: [vnet_addrinfo.c:3945] sorted addrs: 1 0x1
19:30:26.456 [6703] <2> vnet_get_pref_netconnection: [vnet_addrinfo.c:4809] using interface  ANY
19:30:26.456 [6703] <2> async_connect: [vnet_connect.c:1477] connect in progress 1 0x1
19:30:26.457 [6703] <2> vnet_pbxConnect: pbxConnectEx Succeeded
19:30:26.457 [6703] <2> do_pbx_service: [vnet_connect.c:2116] via PBX bpcd CONNECT FROM 10.224.16.105.35610 TO 10.224.16.102.1556 fd = 8
19:30:26.458 [6703] <2> async_connect: [vnet_connect.c:1644] connect async CONNECT FROM 10.224.16.105.35610 TO 1

From activity log :-->

12/08/2014 18:00:22 - Info nbjm (pid=10483) starting backup job (jobid=21920) for client ossbkupIP, policy OSS_i386_DATA_ossbkupIP_syb1bkupIP, schedule Daily_Incr
12/08/2014 18:00:22 - Info nbjm (pid=10483) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=21920, request id:{67BBFB3A-7EC9-11E4-9235-0017A477FC20})
12/08/2014 18:00:22 - requesting resource bksrst1-hcart-robot-tld-0
12/08/2014 18:00:22 - requesting resource bksrst1.NBU_CLIENT.MAXJOBS.ossbkupIP
12/08/2014 18:00:22 - requesting resource bksrst1.NBU_POLICY.MAXJOBS.OSS_i386_DATA_ossbkupIP_syb1bkupIP
12/08/2014 18:00:22 - awaiting resource bksrst1-hcart-robot-tld-0. No drives are available.
12/08/2014 18:34:22 - Info nbrb (pid=10461) Limit has been reached for the logical resource bksrst1.NBU_CLIENT.MAXJOBS.ossbkupIP
12/08/2014 18:42:25 - granted resource  bksrst1.NBU_CLIENT.MAXJOBS.ossbkupIP
12/08/2014 18:42:25 - granted resource  bksrst1.NBU_POLICY.MAXJOBS.OSS_i386_DATA_ossbkupIP_syb1bkupIP
12/08/2014 18:42:25 - granted resource  1128L4
12/08/2014 18:42:25 - granted resource  HP.ULTRIUM4-SCSI.003
12/08/2014 18:42:25 - granted resource  bksrst1-hcart-robot-tld-0
12/08/2014 18:42:25 - estimated 0 kbytes needed
12/08/2014 18:42:25 - Info nbjm (pid=10483) started backup (backupid=ossbkupIP_1418038945) job for client ossbkupIP, policy OSS_i386_DATA_ossbkupIP_syb1bkupIP, schedule Daily_Incr on storage unit bksrst1-hcart-robot-tld-0
12/08/2014 18:42:26 - Info bpbrm (pid=28128) ossbkupIP is the host to backup data from
12/08/2014 18:42:26 - Info bpbrm (pid=28128) reading file list from client
12/08/2014 18:42:26 - started process bpbrm (pid=28128)
12/08/2014 18:42:26 - connecting
12/08/2014 18:42:27 - Info bpbrm (pid=28128) starting bpbkar on client
12/08/2014 18:42:27 - Info bpbkar (pid=0) Starting bpstart_notify script
12/08/2014 18:42:27 - connected; connect time: 0:00:00
12/08/2014 18:42:44 - Info bpbkar (pid=0) Finished bpstart_notify script
12/08/2014 18:42:44 - Info bpbkar (pid=10607) Backup started
12/08/2014 18:42:44 - Info bpbrm (pid=28128) bptm pid: 28153
12/08/2014 18:42:44 - Info bptm (pid=28153) start
12/08/2014 18:42:44 - Info bptm (pid=28153) using 65536 data buffer size
12/08/2014 18:42:44 - Info bptm (pid=28153) setting receive network buffer to 262144 bytes
12/08/2014 18:42:44 - Info bptm (pid=28153) using 30 data buffers
12/08/2014 18:42:44 - Info bptm (pid=28153) start backup
12/08/2014 18:42:44 - Info bptm (pid=28153) backup child process is pid 28160
12/08/2014 18:42:44 - Info bptm (pid=28153) media id 1128L4 mounted on drive index 3, drivepath /dev/rmt/5cbn, drivename HP.ULTRIUM4-SCSI.003, copy 1
12/08/2014 18:42:44 - mounted 1128L4
12/08/2014 18:42:44 - positioning 1128L4 to file 257
12/08/2014 18:42:46 - positioned 1128L4; position time: 0:00:02
12/08/2014 18:42:46 - begin writing
12/08/2014 18:58:47 - Info bpbkar (pid=10607) 4997 entries sent to bpdbm
12/08/2014 18:59:26 - Info bpbkar (pid=10607) 9997 entries sent to bpdbm
12/08/2014 19:00:38 - Info bpbkar (pid=10607) 14997 entries sent to bpdbm
12/08/2014 19:01:31 - Info bpbkar (pid=10607) 19997 entries sent to bpdbm
12/08/2014 19:02:43 - Info bpbkar (pid=10607) 24997 entries sent to bpdbm
12/08/2014 19:03:32 - Info bpbkar (pid=10607) 29997 entries sent to bpdbm
12/08/2014 19:04:35 - Info bpbkar (pid=10607) 34997 entries sent to bpdbm
12/08/2014 19:05:57 - Info bpbkar (pid=10607) 39997 entries sent to bpdbm
12/08/2014 19:07:07 - Info bpbkar (pid=10607) 44997 entries sent to bpdbm
12/08/2014 19:07:59 - Info bpbkar (pid=10607) 49997 entries sent to bpdbm
12/08/2014 19:08:49 - Info bpbkar (pid=10607) 54997 entries sent to bpdbm
12/08/2014 19:09:27 - Info bpbkar (pid=10607) 59997 entries sent to bpdbm
12/08/2014 19:10:14 - Info bpbkar (pid=10607) 64997 entries sent to bpdbm
12/08/2014 19:10:54 - Info bpbkar (pid=10607) 69997 entries sent to bpdbm
12/08/2014 19:11:41 - Info bpbkar (pid=10607) 74997 entries sent to bpdbm
12/08/2014 19:12:20 - Info bpbkar (pid=10607) 79997 entries sent to bpdbm
12/08/2014 19:13:05 - Info bpbkar (pid=10607) 84997 entries sent to bpdbm
12/08/2014 19:13:46 - Info bpbkar (pid=10607) 89997 entries sent to bpdbm
12/08/2014 19:14:39 - Info bpbkar (pid=10607) 94997 entries sent to bpdbm
12/08/2014 19:15:31 - Info bpbkar (pid=10607) 99997 entries sent to bpdbm
12/08/2014 19:16:31 - Info bpbkar (pid=10607) 104997 entries sent to bpdbm
12/08/2014 19:17:23 - Info bpbkar (pid=10607) 109997 entries sent to bpdbm
12/08/2014 19:18:21 - Info bpbkar (pid=10607) 114997 entries sent to bpdbm
12/08/2014 19:19:07 - Info bpbkar (pid=10607) 119997 entries sent to bpdbm
12/08/2014 19:20:15 - Info bpbkar (pid=10607) 124997 entries sent to bpdbm
12/08/2014 19:21:14 - Info bpbkar (pid=10607) 129997 entries sent to bpdbm
12/08/2014 19:22:25 - Info bpbkar (pid=10607) 134997 entries sent to bpdbm
12/08/2014 19:23:33 - Info bpbkar (pid=10607) 139997 entries sent to bpdbm
12/08/2014 19:24:27 - Info bpbkar (pid=10607) 144997 entries sent to bpdbm
12/08/2014 19:25:12 - Info bpbkar (pid=10607) 149997 entries sent to bpdbm
12/08/2014 19:26:10 - Info bpbkar (pid=10607) 154997 entries sent to bpdbm
12/08/2014 19:26:59 - Info bpbkar (pid=10607) 159997 entries sent to bpdbm
12/08/2014 19:27:49 - Info bpbkar (pid=10607) 164997 entries sent to bpdbm
12/08/2014 19:28:42 - Info bpbkar (pid=10607) 169997 entries sent to bpdbm
12/08/2014 19:29:23 - Info bpbkar (pid=10607) 174997 entries sent to bpdbm
12/08/2014 19:30:08 - Info bpbkar (pid=10607) 179997 entries sent to bpdbm
12/08/2014 19:30:25 - Critical bpbrm (pid=28128) unexpected termination of client ossbkupIP
12/08/2014 19:30:25 - Error bptm (pid=28153) media manager terminated by parent process
12/08/2014 19:31:52 - Info bpbkar (pid=10607) done. status: 50: client process aborted
12/08/2014 19:31:52 - end writing; write time: 0:49:06
client process aborted  (50)

kindly have a look at logs and suggest the way forward

Thanks

[symsonu]

Please find attached bpcd and bpbkar logs from client

[Marianne]

Have you seen this?

19:12:12.083 [4190] <16> bpbkar: ERR - Skipping too long path name [/Backup/ossdg/var/opt/ericsson/ccpdm/tmp/PCRBKK2/zone1_jambala/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/pre/A20140214.0330-0345_jambala_Diameter_traffic_counters]

There are lots of entries like these.
Get server owner to fix this.

Check bpstart_notify as well:

19:31:54.746 [25436] <4> bpbkar: INF - START bpstart_notify
19:31:54.746 [25436] <4> bpbkar: /usr/openv/netbackup/bin/bpstart_notify ossbkupIP OSS_i386_DATA_ossbkupIP_syb1bkupIP Daily_Incr INCR
19:31:56.102 [24266] <4> bpbkar: INF - END bpstart_notify
19:31:56.102 [24266] <16> bpbkar: ERR - bpstart_notify returned 127
19:31:56.102 [24266] <16> bpbkar: ERR - bpbkar FATAL exit status = 73: bpstart_notify failed

Only when these 2 issues have been fixed, increase logging level on client (I suggest level 3) so that we can see if we can get get more info about these status 0 showing as an error:

18:33:28.390 [18021] <16> bpbkar: ERR - read server exit status = 0: the requested operation was successfully completed

[inn_kam]

STATUS CODE 1: The error "ERR - Skipping long dir path." occurs because long directories exceed 1023 character limit.

Article:TECH43036

|

Created: 2005-01-08

|

Updated: 2013-10-24

|

Article URL http://www.symantec.com/docs/TECH43036

[symsonu]

can these long paths  can cause backup jobs to fail ?

Also, I got below information from  bptm logs

21:36:29.835 [26954] <2> ConnectionCache::connectAndCache: Acquiring new connection for host bksrst1, query type 77
21:36:29.836 [26954] <2> logconnections: BPDBM CONNECT FROM 10.224.16.105.60214 TO 10.224.16.105.13721 fd = 0
21:36:29.836 [26954] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
21:36:29.848 [26954] <2> db_end: Need to collect reply
21:36:29.913 [26954] <2> send_MDS_msg: MEDIADB 1 11750 1126L4 4000006 *NULL* 6 1415035505 1418220723 1420899123 0 1346587962 290 280 3 5 0 0 1024 0 21041205 021:36:29.920 [26954] <2> notify: executing - /usr/openv/netbackup/bin/backup_notify bptm ossbkupIP_1418220723
21:36:29.948 [26954] <2> updateEMM_freespace: updateEMM_freespace() (1 0)
21:36:29.948 [26954] <2> updateEMM_freespace: 0, bksrst1-hcart-robot-tld-0 (1 0 2 1)
21:36:29.948 [26954] <2> bptm: EXITING with status 0 <----------
21:36:29.948 [26954] <2> set_job_details: Tfile (22375): LOG 1418222189 4 bptm 26954 EXITING with status 0 <----------

21:36:29.948 [26954] <2> send_job_file: job ID 22375, ftype = 3 msg len = 62, msg = LOG 1418222189 4 bptm 26954 EXITING with status 0 <----------

21:36:29.950 [26954] <2> cleanup: Detached from BPBRM shared memory
21:36:46.630 [27724] <2> fill_buffer: [27720] socket is closed, waited for empty buffer 76 times, delayed 3920 times, read 70254592 Kbytes
21:36:46.632 [27720] <2> Media_dispatch_signal: calling catch_signal for 1 (bptm.c:23648) delay 0 seconds
21:36:46.632 [27720] <2> Media_siginfo_print: 0: delay 0 signo SIGHUP:1 code 0 pid 27643
21:36:46.675 [27720] <2> set_job_details: Tfile (22382): LOG 1418222206 16 bptm 27720 media manager terminated by parent process

21:36:46.675 [27720] <2> send_job_file: job ID 22382, ftype = 3 msg len = 72, msg = LOG 1418222206 16 bptm 27720 media manager terminated by parent process

21:36:46.675 [27720] <16> catch_signal: media manager terminated by parent process
21:36:46.675 [27720] <2> KILL_MM_CHILD: Sending SIGUSR2 (kill) to child 27724 (tmcommon.c:1524)
21:36:46.675 [27720] <2> wait_for_sigcld: waiting for child to exit, timeout is 3600
21:36:46.675 [27720] <2> Media_siginfo_print: 1: delay 0 signo SIGCHLD:18 code 1 pid 27724
21:36:46.675 [27720] <2> child_wait: SIGCHLD: exit=0, signo=0 core=no, pid=27724 (tmcommon.c:5931)
21:36:46.676 [27720] <2> io_terminate_tape: writing empty backup header, drive index 0, copy 1
21:36:46.676 [27720] <2> io_terminate_tape: reposition to previous tapemark and rewrite header
21:36:46.676 [27720] <2> io_ioctl: command (2)MTBSF 1 0x0 from (bptm.c.8757) on drive index 0
21:38:48.422 [2084] <2> SetMaxDataLimit: maximum data size: current=-3 max=-3
21:38:48.422 [2084] <2> initialize: fd values STDOUTSOCK=3 STDERRSOCK=4

and job is failing with logs in activity monitor

12/10/2014 21:33:19 - Info bpbkar (pid=24129) 4997 entries sent to bpdbm
12/10/2014 21:35:30 - Info bpbkar (pid=24129) 9997 entries sent to bpdbm
12/10/2014 21:36:46 - Critical bpbrm (pid=27643) unexpected termination of client ossbkupIP
12/10/2014 21:36:46 - Error bptm (pid=27720) media manager terminated by parent process
12/10/2014 21:40:48 - Info bpbkar (pid=24129) done. status: 50: client process aborted
12/10/2014 21:40:48 - end writing; write time: 0:25:08
client process aborted  (50)

What both of these logs suggests ? any idea

[Marianne · Accepted solution]

The bptm entries is quite normal. 
bpbrm (parent process) will stop the backup if error is received from client or if a timeout occurs.
bpbrm will then terminate the child process - bptm.

You need to deal with the long path names and the bpstart_notify errors.

Once these have been resolved and the status 49 in still seen, increase bpbkar logging level to see if anything additional is seen on the client.
Also check in client's syslog for other issues that may indicate a reboot when status 50 was seen.
Or ask server owners if bpbkar process was killed. Both of these scenarios will not have anything in bpbkar log.

You may also want to limit the amount of concurrent jobs on this client. Not sure what it is right now, but 4 is normally a good average.

[revarooo]

As Marianne mentioned, concentrate on the bpbkar errors first and resolve them.

They are likely to resolve the entire issue, if not you can then deal with any remaining issues.