Bacula-users

[Bacula-users] Invalid Tape position - Marking tapes with error

2011-07-06 12:10:29
Subject: [Bacula-users] Invalid Tape position - Marking tapes with error
From: James Woodward <james.woodward AT ualberta DOT ca>
To: bacula-users AT lists.sourceforge DOT net
Date: Wed, 6 Jul 2011 08:29:46 -0600
Hello,

I've tried searching around a bit but I can't seem to find an answer as to what might cause this problem. I have qutie a few tapes that have been marked in error due to Invalid Tape position. I've listed the Invalid tape position errors as well as detail about one of the affected volumes. Has anyone else encountered this or have any idea's as to why it might be happening? For the life of me I can't figure out what the Expected 0 portion refers to. I thought it might refer to volfiles but those numbers don't always match either.

Thank you,

James


Invalid Tape Position Errors
# grep -i "invalid tape position" log
11-Mar 18:01 esqb6-sd JobId 196: Error: Invalid tape position on volume "090137" on device "Drive-2" (/dev/sa2). Expected 0, got 20
27-Mar 18:02 esqb6-sd JobId 353: Error: Invalid tape position on volume "090164" on device "Drive-1" (/dev/sa1). Expected 0, got 77
07-May 00:01 esqb6-sd JobId 867: Error: Invalid tape position on volume "090142" on device "Drive-2" (/dev/sa2). Expected 0, got 152
09-May 00:01 esqb6-sd JobId 907: Error: Invalid tape position on volume "090152" on device "Drive-2" (/dev/sa2). Expected 0, got 102
11-May 00:01 esqb6-sd JobId 950: Error: Invalid tape position on volume "090155" on device "Drive-2" (/dev/sa2). Expected 0, got 9
13-May 00:01 esqb6-sd JobId 993: Error: Invalid tape position on volume "090157" on device "Drive-1" (/dev/sa1). Expected 0, got 65
13-May 18:01 esqb6-sd JobId 1002: Error: Invalid tape position on volume "090175" on device "Drive-1" (/dev/sa1). Expected 0, got 181
15-May 18:13 esqb6-sd JobId 1043: Error: Invalid tape position on volume "090134" on device "Drive-0" (/dev/sa0). Expected 0, got 117
19-May 00:30 esqb6-sd JobId 1123: Error: Invalid tape position on volume "090158" on device "Drive-2" (/dev/sa2). Expected 0, got 134
20-May 18:01 esqb6-sd JobId 1147: Error: Invalid tape position on volume "090159" on device "Drive-1" (/dev/sa1). Expected 0, got 30
21-May 18:03 esqb6-sd JobId 1171: Error: Invalid tape position on volume "090166" on device "Drive-2" (/dev/sa2). Expected 0, got 274
24-May 00:32 esqb6-sd JobId 1231: Error: Invalid tape position on volume "090165" on device "Drive-2" (/dev/sa2). Expected 0, got 55
24-May 18:02 esqb6-sd JobId 1238: Error: Invalid tape position on volume "090160" on device "Drive-1" (/dev/sa1). Expected 0, got 50
30-May 18:04 esqb6-sd JobId 1370: Error: Invalid tape position on volume "090161" on device "Drive-2" (/dev/sa2). Expected 0, got 83
06-Jun 00:31 esqb6-sd JobId 1528: Error: Invalid tape position on volume "090209" on device "Drive-1" (/dev/sa1). Expected 0, got 253
22-Jun 00:31 esqb6-sd JobId 2036: Error: Invalid tape position on volume "090179" on device "Drive-2" (/dev/sa2). Expected 0, got 400
23-Jun 00:31 esqb6-sd JobId 2070: Error: Invalid tape position on volume "090121" on device "Drive-2" (/dev/sa2). Expected 0, got 132
25-Jun 21:01 esqb6-sd JobId 2156: Error: Invalid tape position on volume "090201" on device "Drive-2" (/dev/sa2). Expected 0, got 66
27-Jun 21:01 esqb6-sd JobId 2222: Error: Invalid tape position on volume "090202" on device "Drive-1" (/dev/sa1). Expected 0, got 78
28-Jun 21:01 esqb6-sd JobId 2255: Error: Invalid tape position on volume "090126" on device "Drive-1" (/dev/sa1). Expected 0, got 136
29-Jun 18:05 esqb6-sd JobId 2277: Error: Invalid tape position on volume "090128" on device "Drive-2" (/dev/sa2). Expected 0, got 2
01-Jul 00:31 esqb6-sd JobId 2335: Error: Invalid tape position on volume "090146" on device "Drive-2" (/dev/sa2). Expected 0, got 104
03-Jul 19:01 esqb6-sd JobId 2418: Error: Invalid tape position on volume "090147" on device "Drive-1" (/dev/sa1). Expected 0, got 52


HIstory for a single Tape
# grep 090147 log
21-May 18:03 esqb6-dir JobId 1172: Using Volume "090147" from 'Scratch' pool.
01-Jul 00:37 esqb6-sd JobId 2335: Wrote label to prelabeled Volume "090147" on device "Drive-2" (/dev/sa2)
01-Jul 00:39 esqb6-sd JobId 2335: Committing spooled data to Volume "090147". Despooling 2,572,404,289 bytes ...
  Volume name(s):         090147
01-Jul 18:06 esqb6-sd JobId 2341: Volume "090147" previously written, moving to end of data.
01-Jul 18:06 esqb6-sd JobId 2341: Ready to append to end of Volume "090147" at file=1.
01-Jul 18:06 esqb6-sd JobId 2341: Committing spooled data to Volume "090147". Despooling 66,941,308 bytes ...
  Volume name(s):         090147
01-Jul 18:13 esqb6-sd JobId 2342: Committing spooled data to Volume "090147". Despooling 3,509,656,952 bytes ...
  Volume name(s):         090147
01-Jul 19:06 esqb6-sd JobId 2350: Volume "090147" previously written, moving to end of data.
01-Jul 19:06 esqb6-sd JobId 2350: Ready to append to end of Volume "090147" at file=2.
01-Jul 19:06 esqb6-sd JobId 2350: Committing spooled data to Volume "090147". Despooling 121,000,236 bytes ...
  Volume name(s):         090147
01-Jul 20:04 esqb6-sd JobId 2354: Volume "090147" previously written, moving to end of data.
01-Jul 20:04 esqb6-sd JobId 2354: Ready to append to end of Volume "090147" at file=3.
01-Jul 20:05 esqb6-sd JobId 2354: Committing spooled data to Volume "090147". Despooling 22,549 bytes ...
  Volume name(s):         090147
01-Jul 23:01 esqb6-sd JobId 2362: Committing spooled data to Volume "090147". Despooling 684 bytes ...
  Volume name(s):         090147
01-Jul 23:20 esqb6-sd JobId 2360: Volume "090147" previously written, moving to end of data.
01-Jul 23:20 esqb6-sd JobId 2360: Ready to append to end of Volume "090147" at file=5.
01-Jul 23:49 esqb6-sd JobId 2360: Committing spooled data to Volume "090147". Despooling 53,741,787,485 bytes ...
  Volume name(s):         090147
02-Jul 01:01 esqb6-sd JobId 2361: Committing spooled data to Volume "090147". Despooling 110,030,522,584 bytes ...
  Volume name(s):         090147
02-Jul 02:00 esqb6-sd JobId 2372: Committing spooled data to Volume "090147". Despooling 90,452,154 bytes ...
  Volume name(s):         090147
03-Jul 18:07 esqb6-sd JobId 2409: Volume "090147" previously written, moving to end of data.
03-Jul 18:08 esqb6-sd JobId 2409: Ready to append to end of Volume "090147" at file=48.
03-Jul 18:08 esqb6-sd JobId 2409: Committing spooled data to Volume "090147". Despooling 78,236,295 bytes ...
  Volume name(s):         090147
03-Jul 18:12 esqb6-sd JobId 2412: Committing spooled data to Volume "090147". Despooling 1,298,674 bytes ...
  Volume name(s):         090147
03-Jul 18:20 esqb6-sd JobId 2410: Committing spooled data to Volume "090147". Despooling 3,522,989,979 bytes ...
  Volume name(s):         090147
03-Jul 19:01 esqb6-sd JobId 2418: Error: Invalid tape position on volume "090147" on device "Drive-1" (/dev/sa1). Expected 0, got 52
03-Jul 19:01 esqb6-sd JobId 2418: Marking Volume "090147" in Error in Catalog.


List Media
# echo "List Media" | bconsole | grep Error
+---------+------------+-----------+---------+-------------------+----------+--------------+---------+------+-----------+-----------+---------------------+
| mediaid | volumename | volstatus | enabled | volbytes          | volfiles | volretention | recycle | slot | inchanger | mediatype | lastwritten         |
+---------+------------+-----------+---------+-------------------+----------+--------------+---------+------+-----------+-----------+---------------------+
|      14 | 090142     | Error     |       1 |   532,309,091,328 |      152 |    5,443,200 |       1 |   14 |         1 | LTO4      | 2011-05-06 23:12:54 |
|      16 | 090152     | Error     |       1 |   370,396,422,144 |      102 |    5,443,200 |       1 |   16 |         1 | LTO4      | 2011-05-08 23:13:28 |
|      19 | 090155     | Error     |       1 |    13,712,025,600 |        9 |    5,443,200 |       1 |   19 |         1 | LTO4      | 2011-05-10 23:17:28 |
|      21 | 090157     | Error     |       1 |   229,235,521,536 |       65 |    5,443,200 |       1 |   21 |         1 | LTO4      | 2011-05-12 23:16:13 |
|      22 | 090158     | Error     |       1 |   486,459,832,320 |      133 |    5,443,200 |       1 |   22 |         1 | LTO4      | 2011-05-19 00:03:37 |
|      23 | 090159     | Error     |       1 |   109,382,805,504 |       29 |    5,443,200 |       1 |   23 |         1 | LTO4      | 2011-05-20 03:09:05 |
|      24 | 090160     | Error     |       1 |   160,630,170,624 |       49 |    5,443,200 |       1 |   24 |         1 | LTO4      | 2011-05-24 03:09:28 |
|      25 | 090161     | Error     |       1 |   270,060,134,400 |       82 |    5,443,200 |       1 |   25 |         1 | LTO4      | 2011-05-30 00:32:03 |
|      45 | 090209     | Error     |       1 |   918,759,131,136 |      252 |    5,443,200 |       1 |   45 |         1 | LTO4      | 2011-06-06 00:06:04 |
|      87 | 090121     | Error     |       1 |   494,803,685,376 |      131 |    5,443,200 |       1 |   87 |         1 | LTO4      | 2011-06-23 00:04:55 |
|      92 | 090126     | Error     |       1 |   498,742,272,000 |      136 |    5,443,200 |       1 |   92 |         1 | LTO4      | 2011-06-28 20:10:41 |
|      94 | 090128     | Error     |       1 |     2,197,407,744 |        1 |    5,443,200 |       1 |   94 |         1 | LTO4      | 2011-06-29 00:36:23 |
|      97 | 090146     | Error     |       1 |   395,668,546,560 |      103 |    5,443,200 |       1 |   97 |         1 | LTO4      | 2011-07-01 00:04:14 |
|      98 | 090147     | Error     |       1 |   173,703,591,936 |       51 |    5,443,200 |       1 |   98 |         1 | LTO4      | 2011-07-03 18:22:52 |
|       6 | 090134     | Error     |       1 |   224,378,542,080 |      116 |    5,443,200 |       1 |    6 |         1 | LTO4      | 2011-05-15 18:12:57 |
|      28 | 090164     | Error     |       1 |   199,141,770,240 |       76 |    5,443,200 |       1 |   28 |         1 | LTO4      | 2011-03-26 23:38:07 |
|      29 | 090165     | Error     |       1 |    16,201,092,096 |       54 |    5,443,200 |       1 |   29 |         1 | LTO4      | 2011-05-24 00:01:36 |
|      30 | 090166     | Error     |       1 |   730,228,359,168 |      273 |    5,443,200 |       1 |   30 |         1 | LTO4      | 2011-05-21 00:33:09 |
|      31 | 090175     | Error     |       1 |   502,387,651,584 |      180 |    5,443,200 |       1 |   31 |         1 | LTO4      | 2011-05-13 00:34:40 |
|      32 | 090176     | Error     |       1 |     2,816,077,824 |       13 |    5,443,200 |       1 |   32 |         1 | LTO4      | 2011-05-04 00:33:40 |
|      35 | 090179     | Error     |       1 |   911,010,465,792 |      399 |    5,443,200 |       1 |   35 |         1 | LTO4      | 2011-06-22 00:02:12 |
|      37 | 090201     | Error     |       1 |   198,560,452,608 |       66 |    5,443,200 |       1 |   37 |         1 | LTO4      | 2011-06-25 20:06:27 |
|      38 | 090202     | Error     |       1 |   272,433,724,416 |       78 |    5,443,200 |       1 |   38 |         1 | LTO4      | 2011-06-27 20:02:17 |

------------------------------------------------------------------------------
All of the data generated in your IT infrastructure is seriously valuable.
Why? It contains a definitive record of application performance, security 
threats, fraudulent activity, and more. Splunk takes this data and makes 
sense of it. IT sense. And common sense.
http://p.sf.net/sfu/splunk-d2d-c2
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users