Veritas-bu

[Veritas-bu] Tar Write Errors and Tape Consumption

2006-10-26 09:04:40
Subject: [Veritas-bu] Tar Write Errors and Tape Consumption
From: Greg.Hindle at constellation.com (Hindle, Greg)
Date: Thu, 26 Oct 2006 09:04:40 -0400
NB is probably freezing all of these tapes and that is why you ran out
of tapes. Do you have the correct bar code rule setup for these new
tapes?  



Greg 

-----Original Message-----
From: veritas-bu-bounces at mailman.eng.auburn.edu
[mailto:veritas-bu-bounces at mailman.eng.auburn.edu] On Behalf Of Brooks,
Jason
Sent: Thursday, October 26, 2006 8:51 AM
To: veritas-bu at mailman.eng.auburn.edu
Subject: [Veritas-bu] Tar Write Errors and Tape Consumption

The last two mornings, I've come into work finding my scratch pool all
but empty, consumed by an Exchange policy.  Digging in, I found that the
job reported a Tar write error and requested new media.  This must have
gone through all 50 or so scratch tapes, dumping them into the Exchange
pool with no recorded mounts.  

Looking through the client bpbkar log, I found this:

11:25:32.735 PM: [5640.5132] <16> dtcp_write: TCP - failure: send socket
(1896) (TCP 10054: Connection reset by peer)
11:25:32.735 PM: [5640.5132] <16> dtcp_write: TCP - failure: attempted
to send 32768 bytes
11:25:32.735 PM: [5640.5132] <2> tar_base::V_vTarMsgW: FTL - tar file
write error (10054)
11:25:32.735 PM: [5640.5132] <2> tar_base::V_vTarMsgW: INF - Client
completed sending data for backup
11:25:32.735 PM: [5640.5132] <4> tar_base::V_StopKeepaliveThread: INF -
Waiting for Keepalive Thread to EXIT
11:25:32.735 PM: [5640.5916] <4> tar_base::V_KeepaliveThread: INF -
Keepalive Thread Terminating. Mutex:WAIT_OBJECT_0
11:25:32.735 PM: [5640.5132] <4> tar_base::V_StopKeepaliveThread: INF -
The Keepalive Thread has Exited. Wait Reason:WAIT_OBJECT_0
11:25:32.735 PM: [5640.5132] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS
14: file write failed
11:25:32.735 PM: [5640.5132] <2> tar_base::V_vTarMsgW: WRN - Abnormal
backup status, Exchange Transaction Logs were not truncated
11:25:32.735 PM: [5640.5132] <4> tar_backup::backup_done_state: INF -
Not waiting for server status
11:25:32.751 PM: [5640.5132] <4> OVStopCmd: INF - EXIT - status = 0

The Activity Monitor Details reported this:

10/25/2006 8:00:00 PM - requesting resource calvin-hcart3-robot-tld-0
10/25/2006 8:00:00 PM - requesting resource
hobbes.NBU_CLIENT.MAXJOBS.virtus
10/25/2006 8:00:00 PM - requesting resource
hobbes.NBU_POLICY.MAXJOBS.Exchange
10/25/2006 8:00:10 PM - granted resource
hobbes.NBU_CLIENT.MAXJOBS.virtus
10/25/2006 8:00:10 PM - granted resource
hobbes.NBU_POLICY.MAXJOBS.Exchange
10/25/2006 8:00:10 PM - granted resource 000094
10/25/2006 8:00:10 PM - granted resource Tape2
10/25/2006 8:00:10 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:00:21 PM - started process bpbrm (3680)
10/25/2006 8:00:28 PM - connecting
10/25/2006 8:00:30 PM - mounting 000094
10/25/2006 8:00:30 PM - connected; connect time: 00:00:02
10/25/2006 8:05:58 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:06:00 PM - Warning bptm(pid=2116) media id 000094 load
operation reported an error     
10/25/2006 8:06:01 PM - current media 000094 complete, requesting next
media Any
10/25/2006 8:06:11 PM - granted resource 000119
10/25/2006 8:06:11 PM - granted resource Tape2
10/25/2006 8:06:11 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:06:11 PM - mounting 000119
10/25/2006 8:11:51 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:11:53 PM - Warning bptm(pid=2116) media id 000119 load
operation reported an error     
10/25/2006 8:11:54 PM - current media 000119 complete, requesting next
media Any
10/25/2006 8:12:03 PM - granted resource 000095
10/25/2006 8:12:03 PM - granted resource Tape2
10/25/2006 8:12:03 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:12:05 PM - mounting 000095
10/25/2006 8:17:27 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:17:29 PM - Warning bptm(pid=2116) media id 000095 load
operation reported an error     
10/25/2006 8:17:31 PM - current media 000095 complete, requesting next
media Any
10/25/2006 8:17:41 PM - granted resource 000118
10/25/2006 8:17:41 PM - granted resource Tape2
10/25/2006 8:17:41 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:17:43 PM - mounting 000118
10/25/2006 8:23:06 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:23:08 PM - Warning bptm(pid=2116) media id 000118 load
operation reported an error     
10/25/2006 8:23:09 PM - current media 000118 complete, requesting next
media Any
10/25/2006 8:23:19 PM - granted resource 000096
10/25/2006 8:23:19 PM - granted resource Tape2
10/25/2006 8:23:19 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:23:20 PM - mounting 000096
10/25/2006 8:28:45 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:28:47 PM - Warning bptm(pid=2116) media id 000096 load
operation reported an error     
10/25/2006 8:28:49 PM - current media 000096 complete, requesting next
media Any
10/25/2006 8:28:59 PM - granted resource 000117
10/25/2006 8:28:59 PM - granted resource Tape2
10/25/2006 8:28:59 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:29:02 PM - mounting 000117
10/25/2006 8:34:25 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:34:27 PM - Warning bptm(pid=2116) media id 000117 load
operation reported an error     
10/25/2006 8:34:28 PM - current media 000117 complete, requesting next
media Any
10/25/2006 8:34:39 PM - granted resource 000097
10/25/2006 8:34:39 PM - granted resource Tape2
10/25/2006 8:34:39 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:34:41 PM - mounting 000097
10/25/2006 8:40:24 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:40:25 PM - Warning bptm(pid=2116) media id 000097 load
operation reported an error     
10/25/2006 8:40:27 PM - current media 000097 complete, requesting next
media Any
10/25/2006 8:40:38 PM - granted resource 000116
10/25/2006 8:40:38 PM - granted resource Tape2
10/25/2006 8:40:38 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:40:39 PM - mounting 000116
10/25/2006 8:46:19 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:46:21 PM - Warning bptm(pid=2116) media id 000116 load
operation reported an error     
10/25/2006 8:46:22 PM - current media 000116 complete, requesting next
media Any
10/25/2006 8:46:35 PM - granted resource 000098
10/25/2006 8:46:35 PM - granted resource Tape2
10/25/2006 8:46:35 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:46:38 PM - mounting 000098
10/25/2006 8:52:05 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:52:06 PM - Warning bptm(pid=2116) media id 000098 load
operation reported an error     
10/25/2006 8:52:07 PM - current media 000098 complete, requesting next
media Any
10/25/2006 8:52:17 PM - granted resource 000115
10/25/2006 8:52:17 PM - granted resource Tape2
10/25/2006 8:52:17 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:52:20 PM - mounting 000115
10/25/2006 8:57:45 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 8:57:46 PM - Warning bptm(pid=2116) media id 000115 load
operation reported an error     
10/25/2006 8:57:48 PM - current media 000115 complete, requesting next
media Any
10/25/2006 8:57:58 PM - granted resource 000099
10/25/2006 8:57:58 PM - granted resource Tape2
10/25/2006 8:57:58 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 8:58:00 PM - mounting 000099
10/25/2006 9:03:42 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:03:44 PM - Warning bptm(pid=2116) media id 000099 load
operation reported an error     
10/25/2006 9:03:45 PM - current media 000099 complete, requesting next
media Any
10/25/2006 9:03:55 PM - granted resource 000114
10/25/2006 9:03:55 PM - granted resource Tape2
10/25/2006 9:03:55 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:03:57 PM - mounting 000114
10/25/2006 9:09:38 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:09:39 PM - Warning bptm(pid=2116) media id 000114 load
operation reported an error     
10/25/2006 9:09:40 PM - current media 000114 complete, requesting next
media Any
10/25/2006 9:09:56 PM - granted resource 000100
10/25/2006 9:09:56 PM - granted resource Tape2
10/25/2006 9:09:56 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:09:58 PM - mounting 000100
10/25/2006 9:15:46 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:15:48 PM - Warning bptm(pid=2116) media id 000100 load
operation reported an error     
10/25/2006 9:15:49 PM - current media 000100 complete, requesting next
media Any
10/25/2006 9:15:59 PM - granted resource 000104
10/25/2006 9:15:59 PM - granted resource Tape2
10/25/2006 9:15:59 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:16:02 PM - mounting 000104
10/25/2006 9:21:43 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:21:45 PM - Warning bptm(pid=2116) media id 000104 load
operation reported an error     
10/25/2006 9:21:46 PM - current media 000104 complete, requesting next
media Any
10/25/2006 9:21:56 PM - granted resource 000112
10/25/2006 9:21:56 PM - granted resource Tape2
10/25/2006 9:21:56 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:21:56 PM - mounting 000112
10/25/2006 9:27:39 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:27:40 PM - Warning bptm(pid=2116) media id 000112 load
operation reported an error     
10/25/2006 9:27:42 PM - current media 000112 complete, requesting next
media Any
10/25/2006 9:27:52 PM - granted resource 000111
10/25/2006 9:27:52 PM - granted resource Tape2
10/25/2006 9:27:52 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:27:54 PM - mounting 000111
10/25/2006 9:33:36 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:33:38 PM - Warning bptm(pid=2116) media id 000111 load
operation reported an error     
10/25/2006 9:33:39 PM - current media 000111 complete, requesting next
media Any
10/25/2006 9:33:56 PM - granted resource 000105
10/25/2006 9:33:56 PM - granted resource Tape2
10/25/2006 9:33:56 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:33:57 PM - mounting 000105
10/25/2006 9:39:37 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:39:39 PM - Warning bptm(pid=2116) media id 000105 load
operation reported an error     
10/25/2006 9:39:41 PM - current media 000105 complete, requesting next
media Any
10/25/2006 9:39:51 PM - granted resource 000110
10/25/2006 9:39:51 PM - granted resource Tape2
10/25/2006 9:39:51 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:39:54 PM - mounting 000110
10/25/2006 9:45:37 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:45:38 PM - Warning bptm(pid=2116) media id 000110 load
operation reported an error     
10/25/2006 9:45:40 PM - current media 000110 complete, requesting next
media Any
10/25/2006 9:45:50 PM - granted resource 000109
10/25/2006 9:45:50 PM - granted resource Tape2
10/25/2006 9:45:50 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:45:53 PM - mounting 000109
10/25/2006 9:51:36 PM - current media 000109 complete, requesting next
media Any
10/25/2006 9:51:45 PM - granted resource 000015
10/25/2006 9:51:45 PM - granted resource Tape2
10/25/2006 9:51:45 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:51:46 PM - mounting 000015
10/25/2006 9:57:10 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 9:57:11 PM - Warning bptm(pid=2116) media id 000015 load
operation reported an error     
10/25/2006 9:57:12 PM - current media 000015 complete, requesting next
media Any
10/25/2006 9:57:21 PM - granted resource 000058
10/25/2006 9:57:21 PM - granted resource Tape2
10/25/2006 9:57:21 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 9:57:23 PM - mounting 000058
10/25/2006 10:03:05 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:03:06 PM - Warning bptm(pid=2116) media id 000058 load
operation reported an error     
10/25/2006 10:03:08 PM - current media 000058 complete, requesting next
media Any
10/25/2006 10:03:17 PM - granted resource 000016
10/25/2006 10:03:17 PM - granted resource Tape2
10/25/2006 10:03:17 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:03:18 PM - mounting 000016
10/25/2006 10:08:42 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:08:43 PM - Warning bptm(pid=2116) media id 000016 load
operation reported an error     
10/25/2006 10:08:45 PM - current media 000016 complete, requesting next
media Any
10/25/2006 10:08:55 PM - granted resource 000057
10/25/2006 10:08:55 PM - granted resource Tape2
10/25/2006 10:08:55 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:08:58 PM - mounting 000057
10/25/2006 10:14:25 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:14:26 PM - Warning bptm(pid=2116) media id 000057 load
operation reported an error     
10/25/2006 10:14:28 PM - current media 000057 complete, requesting next
media Any
10/25/2006 10:14:38 PM - granted resource 000017
10/25/2006 10:14:38 PM - granted resource Tape2
10/25/2006 10:14:38 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:14:41 PM - mounting 000017
10/25/2006 10:20:20 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:20:22 PM - Warning bptm(pid=2116) media id 000017 load
operation reported an error     
10/25/2006 10:20:23 PM - current media 000017 complete, requesting next
media Any
10/25/2006 10:20:33 PM - granted resource 000056
10/25/2006 10:20:33 PM - granted resource Tape2
10/25/2006 10:20:33 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:20:36 PM - mounting 000056
10/25/2006 10:26:18 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:26:20 PM - Warning bptm(pid=2116) media id 000056 load
operation reported an error     
10/25/2006 10:26:21 PM - current media 000056 complete, requesting next
media Any
10/25/2006 10:26:31 PM - granted resource 000018
10/25/2006 10:26:31 PM - granted resource Tape2
10/25/2006 10:26:31 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:26:34 PM - mounting 000018
10/25/2006 10:31:58 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:32:00 PM - Warning bptm(pid=2116) media id 000018 load
operation reported an error     
10/25/2006 10:32:01 PM - current media 000018 complete, requesting next
media Any
10/25/2006 10:32:11 PM - granted resource 000055
10/25/2006 10:32:11 PM - granted resource Tape2
10/25/2006 10:32:11 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:32:14 PM - mounting 000055
10/25/2006 10:37:53 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:37:54 PM - Warning bptm(pid=2116) media id 000055 load
operation reported an error     
10/25/2006 10:37:56 PM - current media 000055 complete, requesting next
media Any
10/25/2006 10:38:06 PM - granted resource 000019
10/25/2006 10:38:06 PM - granted resource Tape2
10/25/2006 10:38:06 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:38:09 PM - mounting 000019
10/25/2006 10:43:47 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:43:49 PM - Warning bptm(pid=2116) media id 000019 load
operation reported an error     
10/25/2006 10:43:50 PM - current media 000019 complete, requesting next
media Any
10/25/2006 10:43:59 PM - granted resource 000049
10/25/2006 10:43:59 PM - granted resource Tape2
10/25/2006 10:43:59 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:44:01 PM - mounting 000049
10/25/2006 10:49:39 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:49:41 PM - Warning bptm(pid=2116) media id 000049 load
operation reported an error     
10/25/2006 10:49:43 PM - current media 000049 complete, requesting next
media Any
10/25/2006 10:49:52 PM - granted resource 000138
10/25/2006 10:49:52 PM - granted resource Tape2
10/25/2006 10:49:52 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:49:56 PM - mounting 000138
10/25/2006 10:55:35 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 10:55:37 PM - Warning bptm(pid=2116) media id 000138 load
operation reported an error     
10/25/2006 10:55:38 PM - current media 000138 complete, requesting next
media Any
10/25/2006 10:55:48 PM - granted resource 000139
10/25/2006 10:55:48 PM - granted resource Tape2
10/25/2006 10:55:48 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 10:55:51 PM - mounting 000139
10/25/2006 11:01:29 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 11:01:31 PM - Warning bptm(pid=2116) media id 000139 load
operation reported an error     
10/25/2006 11:01:32 PM - current media 000139 complete, requesting next
media Any
10/25/2006 11:01:42 PM - granted resource 000136
10/25/2006 11:01:42 PM - granted resource Tape2
10/25/2006 11:01:42 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 11:01:45 PM - mounting 000136
10/25/2006 11:07:25 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 11:07:27 PM - Warning bptm(pid=2116) media id 000136 load
operation reported an error     
10/25/2006 11:07:28 PM - current media 000136 complete, requesting next
media Any
10/25/2006 11:07:43 PM - granted resource 000135
10/25/2006 11:07:43 PM - granted resource Tape2
10/25/2006 11:07:43 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 11:07:46 PM - mounting 000135
10/25/2006 11:13:26 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 11:13:28 PM - Warning bptm(pid=2116) media id 000135 load
operation reported an error     
10/25/2006 11:13:29 PM - current media 000135 complete, requesting next
media Any
10/25/2006 11:13:40 PM - granted resource 000059
10/25/2006 11:13:40 PM - granted resource Tape2
10/25/2006 11:13:40 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 11:13:42 PM - mounting 000059
10/25/2006 11:19:22 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 11:19:24 PM - Warning bptm(pid=2116) media id 000059 load
operation reported an error     
10/25/2006 11:19:25 PM - current media 000059 complete, requesting next
media Any
10/25/2006 11:19:47 PM - granted resource 000137
10/25/2006 11:19:47 PM - granted resource Tape2
10/25/2006 11:19:47 PM - granted resource calvin-hcart3-robot-tld-0
10/25/2006 11:19:50 PM - mounting 000137
10/25/2006 11:25:17 PM - Error bptm(pid=2116) error requesting media,
TpErrno = Robot operation failed     
10/25/2006 11:25:18 PM - Warning bptm(pid=2116) media id 000137 load
operation reported an error     
10/25/2006 11:25:20 PM - current media 000137 complete, requesting next
media Any
10/25/2006 11:25:32 PM - Critical bpbrm(pid=1268) from client virtus:
FTL - tar file write error (10054)   
10/25/2006 11:25:34 PM - Error bpbrm(pid=1268) could not send server
status message       
10/25/2006 11:25:33 PM - end writing
unable to allocate new media for backup, storage unit has none
available(96)

All the tapes that generated a load error are new.  I'm running a
cleaning now, just in case.  Suggestions on diagnosing this?

Thanks,
Jason

------------
Jason Brooks
Computer Systems Engineer
IITS - Longwood University
voice - (434) 395-2916
fax - (434) 395-2035
mailto:<brooksje at longwood.edu> 

_______________________________________________
Veritas-bu maillist  -  Veritas-bu at mailman.eng.auburn.edu
http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu
>>> This e-mail and any attachments are confidential, may contain legal,
professional or other privileged information, and are intended solely for the
addressee.  If you are not the intended recipient, do not use the information
in this e-mail in any way, delete this e-mail and notify the sender. CEG-IP2