Hi Jean,
On 31/03/11 11:22, Jean-Louis Martineau wrote:
My tape is currently in variable mode, though I can see the following
in my reports:
I never trust what user say, prove it, what's the output of: mt status
:-)
[amanda@solo ~/bin]$ mt -f /dev/nsa0 status
Mode Density Blocksize bpi Compression
Current: 0x46 variable 0 disabled
---------available modes---------
0: 0x46 variable 0 0x1
1: 0x46 variable 0 0x1
2: 0x46 variable 0 0x1
3: 0x46 variable 0 0x1
---------------------------------
Current Driver State: at rest.
---------------------------------
File Number: 0 Record Number: 2 Residual Count 0
[amanda@solo ~/bin]$ mt -f /dev/nsa0 status
Mode Density Blocksize bpi Compression
Current: 0x46 variable 0 disabled
---------available modes---------
0: 0x46 variable 0 0x1
1: 0x46 variable 0 0x1
2: 0x46 variable 0 0x1
3: 0x46 variable 0 0x1
---------------------------------
Current Driver State: at rest.
---------------------------------
File Number: 0 Record Number: 2 Residual Count 0
host1.linguamatics.com / lev 0 partial taper: Error writing block:
Short write on tape device: Tried 131072, got 65536. Is the drive
using a block size smaller than 131072 bytes?
Sometime it is the OS that is not configured to allow bigger block,
check the kernel configuration.
Try with another software, can you use dd to write 128k block on the tape?
I wasn't clear sorry. The situation is, that amanda is vigorously
writing the tape with 128k blocks, but at some point it stops with this
cryptic message:
Excerpt from the report:
USAGE BY TAPE:
Label Time Size % DLEs Parts
Daily-31 6:34 20803M 2.7 4 4
Daily-32 2:58 654719M 86.5 146 146
NOTES:
taper: tape Daily-32 kb 669935059 fm 146 [OK]
taper: tape Daily-31 kb 17090742 fm 4 [OK]
I can supply the full taper.debug log in private if it helps or let me
know if you would like higher verbosity.
If I see the taper log, I can see, that it started to tape at 9:55am to
Daily-32, (I would be interested why didn't it start both tapes in
parallel, but this is a different issue). It tapes a lot of DLEs to
Daily-32 (bottom_drive).
At 12:40 I see the following:
Thu Mar 31 12:40:37 2011: taper: xfer_start size 0
Thu Mar 31 12:40:37 2011: taper: Starting<Xfer@0x805810830 (<XferSourceHolding@0x804a08dc0>
-> <XferDestTaperSplitter@0x804b51450>)>
Thu Mar 31 12:40:37 2011: taper: Final linkage:<XferSourceHolding@0x804a08dc0>
-(PULL_BUFFER)-> <XferElementGlue@0x804a09510> -(PUSH_BUFFER)->
<XferDestTaperSplitter@0x804b51450>
Thu Mar 31 12:40:37 2011: taper: Building type SPLIT_FILE header of
131072-131072 bytes with name='files.linguamatics.com'
disk='/export/home/cambridge/user1' dumplevel=1 and blocksize=131072
Thu Mar 31 12:40:41 2011: taper: Amanda::Taper::Scribe preparing to write, part
size 0, using no cache (PEOM will be fatal) (splitter) (no LEOM)
Thu Mar 31 12:40:41 2011: taper: xfer_start size 0
Thu Mar 31 12:40:41 2011: taper: Starting<Xfer@0x8058c6fb0 (<XferSourceHolding@0x804a08c10>
-> <XferDestTaperSplitter@0x804b51590>)>
Thu Mar 31 12:40:41 2011: taper: Final linkage:<XferSourceHolding@0x804a08c10>
-(PULL_BUFFER)-> <XferElementGlue@0x804a09190> -(PUSH_BUFFER)->
<XferDestTaperSplitter@0x804b51590>
Thu Mar 31 12:40:41 2011: taper: Building type SPLIT_FILE header of
131072-131072 bytes with name='files.linguamatics.com'
disk='/export/home/cambridge/user2' dumplevel=1 and blocksize=131072
Thu Mar 31 12:43:28 2011: taper: empty write to tape; treating as LEOM early
warning and retrying
Thu Mar 31 12:43:28 2011: taper: Device bottom_drive error = 'Error writing
block: Short write on tape device: Tried 131072, got 65536. Is the drive using
a block size smaller than 131072 bytes?'
Thu Mar 31 12:43:28 2011: taper: Device bottom_drive setting status flag(s):
DEVICE_STATUS_DEVICE_ERROR
Thu Mar 31 12:43:33 2011: taper: Cancelling<Xfer@0x8058c6fb0
(<XferSourceHolding@0x804a08c10> -> <XferDestTaperSplitter@0x804b51590>)>
Thu Mar 31 12:43:33 2011: taper: Amanda::Taper::Scribe preparing to write, part
size 0, using no cache (PEOM will be fatal) (splitter) (no LEOM)
Thu Mar 31 12:43:33 2011: taper: xfer_start size 0
Thu Mar 31 12:43:33 2011: taper: Starting<Xfer@0x8058867e0 (<XferSourceHolding@0x804a08ca0>
-> <XferDestTaperSplitter@0x804b51590>)>
Thu Mar 31 12:43:33 2011: taper: Final linkage:<XferSourceHolding@0x804a08ca0>
-(PULL_BUFFER)-> <XferElementGlue@0x804a09430> -(PUSH_BUFFER)->
<XferDestTaperSplitter@0x804b51590>
Thu Mar 31 13:16:52 2011: taper: Building type SPLIT_FILE header of
131072-131072 bytes with name='files.linguamatics.com'
disk='/export/home/cambridge/user2' dumplevel=1 and blocksize=131072
Thu Mar 31 16:31:21 2011: taper: Device top_drive error = 'Error writing block:
Short write on tape device: Tried 131072, got 65536. Is the drive using a
block size smaller than 131072 bytes?'
Thu Mar 31 16:31:21 2011: taper: Device top_drive setting status flag(s):
DEVICE_STATUS_DEVICE_ERROR
Thu Mar 31 16:31:25 2011: taper: Cancelling<Xfer@0x8058867e0
(<XferSourceHolding@0x804a08ca0> -> <XferDestTaperSplitter@0x804b51590>)>
Thu Mar 31 16:31:25 2011: taper: Amanda::Taper::Scribe preparing to write, part
size 0, using no cache (PEOM will be fatal) (splitter) (no LEOM)
Thu Mar 31 16:31:25 2011: taper: xfer_start size 0
Thu Mar 31 16:31:25 2011: taper: Starting<Xfer@0x805886790 (<XferSourceHolding@0x804a08d30>
-> <XferDestTaperSplitter@0x804b51450>)>
Thu Mar 31 16:31:25 2011: taper: Final linkage:<XferSourceHolding@0x804a08d30>
-(PULL_BUFFER)-> <XferElementGlue@0x804a090b0> -(PUSH_BUFFER)->
<XferDestTaperSplitter@0x804b51450>
Thu Mar 31 16:31:25 2011: taper: Cancelling<Xfer@0x805886790
(<XferSourceHolding@0x804a08d30> -> <XferDestTaperSplitter@0x804b51450>)>
Thu Mar 31 16:31:25 2011: taper: pid 39046 finish time Thu Mar 31 16:31:25 2011
As you can see, there's a DLE of user2, what Amanda can't tape neither
to the top drive or the bottom drive.
It's definitely not an EOM on the top_drive.
Let's see what's happening tomorrow morning. I have a feeling, this
issue emerged since I upgraded 3.2.1->3.2.2...
Thank you in advance for tracking this down,
Attila
