Status 13 on Windows client

[WayneLackey]

I have a Windows client that is consistently failing to back up with a status 13 error after initially backing up successfully for several weeks. The particulars are as follows:

Master Server: NBU Server 7.5.0.4 running on UNIX SunOS 5.10; recently upgraded from NBU 7.1.0.3

Media Server: NBU Server 7.1.0.3 running on Windows 2008 Server

Client: Windows 2008 Server running NBU Client 7.1

---

Recent job details from Activity Monitor:

First attempt:

12/04/2012 18:00:20 - Info nbjm (pid=1695) starting backup job (jobid=3510520) for client bkusolgwwcis007, policy USCIS-WIN-CDI, schedule Diff
12/04/2012 18:00:20 - Info nbjm (pid=1695) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=3510520, request id:{6072B5C6-3E66-11E2-95B5-1CC1DE1EF662})
12/04/2012 18:00:20 - requesting resource DSSU_USCIS
12/04/2012 18:00:20 - requesting resource bkferrari.NBU_CLIENT.MAXJOBS.bkusolgwwcis007
12/04/2012 18:00:20 - requesting resource bkferrari.NBU_POLICY.MAXJOBS.USCIS-WIN-CDI
12/04/2012 18:00:50 - granted resource  bkferrari.NBU_CLIENT.MAXJOBS.bkusolgwwcis007
12/04/2012 18:00:50 - granted resource  bkferrari.NBU_POLICY.MAXJOBS.USCIS-WIN-CDI
12/04/2012 18:00:50 - granted resource  MediaID=@aaacn;Path=Z:\USCIS\;MediaServer=bkusolbkmpv03
12/04/2012 18:00:50 - granted resource  DSSU_USCIS
12/04/2012 18:01:40 - estimated 0 kbytes needed
12/04/2012 18:01:40 - Info nbjm (pid=1695) started backup (backupid=bkusolgwwcis007_1354662100) job for client bkusolgwwcis007, policy USCIS-WIN-CDI, schedule Diff on storage unit DSSU_USCIS
12/04/2012 18:01:41 - started process bpbrm (pid=1076)
12/04/2012 18:01:46 - connecting
12/04/2012 18:01:49 - connected; connect time: 0:00:00
12/04/2012 18:01:51 - begin writing
12/04/2012 18:02:45 - end writing; write time: 0:00:54
12/04/2012 18:14:09 - Info bpbrm (pid=1076) bkusolgwwcis007 is the host to backup data from
12/04/2012 18:14:09 - Info bpbrm (pid=1076) reading file list from client
12/04/2012 18:14:12 - Info bpbrm (pid=1076) starting bpbkar32 on client
12/04/2012 18:14:13 - Info bpbkar32 (pid=5992) Backup started
12/04/2012 18:14:13 - Info bptm (pid=4452) start
12/04/2012 18:14:13 - Info bptm (pid=4452) using 262144 data buffer size
12/04/2012 18:14:13 - Info bptm (pid=4452) setting receive network buffer to 1049600 bytes
12/04/2012 18:14:13 - Info bptm (pid=4452) using 30 data buffers
12/04/2012 18:14:14 - Info bptm (pid=4452) start backup
12/04/2012 18:14:14 - Info bptm (pid=4452) backup child process is pid 4592.4200
12/04/2012 18:14:14 - Info bptm (pid=4592) start
12/04/2012 18:15:03 - Error bpbrm (pid=1076) socket read failed, An existing connection was forcibly closed by the remote host.  (10054)
12/04/2012 18:15:03 - Error bptm (pid=4592) socket operation failed - 10054 (at child.c.1294)
12/04/2012 18:15:03 - Error bptm (pid=4592) unable to perform read from client socket, connection may have been broken
12/04/2012 18:15:06 - Error bpbrm (pid=1076) could not send server status message
12/04/2012 18:15:07 - Error bpbrm (pid=1076) cannot send mail to dcsuspsbur@hp.com
file read failed  (13)

Second attempt:

12/04/2012 18:12:45 - Info nbjm (pid=1695) starting backup job (jobid=3510520) for client bkusolgwwcis007, policy USCIS-WIN-CDI, schedule Diff
12/04/2012 18:12:45 - Info nbjm (pid=1695) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=3510520, request id:{1C8C8F60-3E68-11E2-B83C-1CC1DE1EF662})
12/04/2012 18:12:45 - requesting resource DSSU_USCIS
12/04/2012 18:12:45 - requesting resource bkferrari.NBU_CLIENT.MAXJOBS.bkusolgwwcis007
12/04/2012 18:12:45 - requesting resource bkferrari.NBU_POLICY.MAXJOBS.USCIS-WIN-CDI
12/04/2012 18:13:46 - granted resource  bkferrari.NBU_CLIENT.MAXJOBS.bkusolgwwcis007
12/04/2012 18:13:46 - granted resource  bkferrari.NBU_POLICY.MAXJOBS.USCIS-WIN-CDI
12/04/2012 18:13:46 - granted resource  MediaID=@aaacn;Path=Z:\USCIS\;MediaServer=bkusolbkmpv03
12/04/2012 18:13:46 - granted resource  DSSU_USCIS
12/04/2012 18:13:50 - estimated 0 kbytes needed
12/04/2012 18:13:50 - Info nbjm (pid=1695) started backup (backupid=bkusolgwwcis007_1354662830) job for client bkusolgwwcis007, policy USCIS-WIN-CDI, schedule Diff on storage unit DSSU_USCIS
12/04/2012 18:13:51 - started process bpbrm (pid=4852)
12/04/2012 18:13:56 - connecting
12/04/2012 18:13:59 - connected; connect time: 0:00:00
12/04/2012 18:14:01 - begin writing
12/04/2012 18:14:56 - end writing; write time: 0:00:55
12/04/2012 18:26:19 - Info bpbrm (pid=4852) bkusolgwwcis007 is the host to backup data from
12/04/2012 18:26:19 - Info bpbrm (pid=4852) reading file list from client
12/04/2012 18:26:22 - Info bpbrm (pid=4852) starting bpbkar32 on client
12/04/2012 18:26:22 - Info bpbkar32 (pid=5492) Backup started
12/04/2012 18:26:22 - Info bptm (pid=1740) start
12/04/2012 18:26:23 - Info bptm (pid=1740) using 262144 data buffer size
12/04/2012 18:26:23 - Info bptm (pid=1740) setting receive network buffer to 1049600 bytes
12/04/2012 18:26:23 - Info bptm (pid=1740) using 30 data buffers
12/04/2012 18:26:23 - Info bptm (pid=1740) start backup
12/04/2012 18:26:24 - Info bptm (pid=1740) backup child process is pid 1940.4916
12/04/2012 18:26:24 - Info bptm (pid=1940) start
12/04/2012 18:27:13 - Error bpbrm (pid=4852) socket read failed, An existing connection was forcibly closed by the remote host.  (10054)
12/04/2012 18:27:13 - Error bptm (pid=1940) socket operation failed - 10054 (at child.c.1294)
12/04/2012 18:27:13 - Error bptm (pid=1940) unable to perform read from client socket, connection may have been broken
12/04/2012 18:27:16 - Error bpbrm (pid=4852) could not send server status message
12/04/2012 18:27:17 - Error bpbrm (pid=4852) cannot send mail to dcsuspsbur@hp.com
12/04/2012 18:27:21 - begin Delete Snapshot
12/04/2012 18:27:32 - Error bpbrm (pid=4280) from client bkusolgwwcis007: Get bpfis state from bkferrari failed. status = 25
12/04/2012 18:27:32 - Info bpfis (pid=4540) Backup started
12/04/2012 18:27:33 - Error bpbrm (pid=4280) from client bkusolgwwcis007: Delete bpfis state from bkferrari failed. status = 25
12/04/2012 18:27:33 - Info bpfis (pid=4540) done. status: 0
12/04/2012 18:27:33 - end Delete Snapshot; elapsed time 0:00:12
file read failed  (13)

---

Is this something that might require action on the client side? What logs or other information should I gather to assist in troubleshooting?

Thanks,

Wayne

[revarooo]

Is it possible for you to post up the bpbrm and bptm logs from the media server and the bpfis log from the client from the 4th December?

It seems that bpbrm is the issue here, but all 3 logs would be useful. Is this media server only having issues backing up this client?

You mentioned it backed up for several weeks, what has changed since it was working before to now?

Have you tried rebooting the client if possible?

[WayneLackey]

revaroo,

I will have to coordinate with the server admin for that client to see about getting the bpfis log (if it is even enabled), but I can retrieve the other two in short order.

I'm not aware of this media server having problems with other clients at this time, but I don't directly service all the customers that back up to this particular media server. There could be one or two other clients here or there with issues but there are no widespread problems with this media server backing up clients to my knowledge. None of my other customers' clients that back up to this media server (some from the same customer as this problem client) are having issues at this time.

I have no idea what if anything changed with the client - I don't administer their servers nor do I have direct access to them. I will have to inquire with their server admin about that, and about the possibility of it being rebooted (if it hasn't been recently).

Thanks,

Wayne

[Dyneshia]

Running the client at the base install of 7.1 is not good either.  I would update it to at least 7.1.0.3 when you get the chance.

[WayneLackey · Accepted solution]

I checked the policy settings for this client again, and the backup selections were set to C:, D:, and I: - without the backslashes (i.e., C:\). I added the backslashes, and I am getting a status 0 for this client now.