Drive Not Ready

[ritl]

Hi,

I'm using zmanda on a linux sytem with an exabyte 1x7 tape drive. I keep getting an error of drive not ready and don't understand why? Have increase the wait times but still the same -

Example - debug list

--------------------------------------------------------------------------
1182541382.704743: chg-zd-mtx: debug 1 pid 14529 ruid 0 euid 0: start at Fri Jun
22 15:43:02 2007
15:43:02 Using config file /etc/amanda/daily/changer.conf
15:43:02 Arg info:
$# = 2
$0 = "/usr/lib/amanda/chg-zd-mtx"
$1 = "-slot"
$2 = "next"
15:43:02 Running: mtxRunning: status
15:43:02 Exit code: 0
Stdout:
Storage Changer /dev/sg0:1 Drives, 7 Slots ( 0 Import/Export )
Data Transfer Element 0:Full (Storage Element 1 Loaded):VolumeTag = A00001

Storage Element 1:Empty:VolumeTag=
Storage Element 2:Full :VolumeTag=A00002
Storage Element 3:Full :VolumeTag=A00003
Storage Element 4:Full :VolumeTag=A00004
Storage Element 5:Full :VolumeTag=A00005
Storage Element 6:Full :VolumeTag=A00006
Storage Element 7:Full :VolumeTag=A00007
15:43:02 Config info:
firstslot = "1"
lastslot = "6"
cleanslot = "7"
cleancycle = "120"
offline_before_unload = "0"
unloadpause = "240"
autoclean = "0"
autocleancount = "99"
havereader = "1"
driveslot = "0"
poll_drive_ready = "240"
initial_poll_delay = "240"
max_drive_wait = "240"
15:43:02 LOADSLOT -> load drive 0 (/dev/sg0) from slot next
15:43:02 STATUS -> currently loaded slot = 1
-> currently loaded barcode = "A00001"
15:43:02 EJECT -> ejecting tape from /dev/sg0
15:43:02 STATUS -> currently loaded slot = 1
-> currently loaded barcode = "A00001"
15:43:03 EJECT -> moving tape from drive 0 to storage slot 1
15:47:03 Running: mtxRunning: unloadRunning: 1Running: 0
15:47:23 Exit code: 0
15:47:03 Running: mtxRunning: unloadRunning: 1Running: 0
15:47:23 Exit code: 0
Stdout:
Unloading drive 0 into Storage Element 1...done
15:47:23 -> status 0, result "Unloading" -> status drive, result "0" -> status i
nto, result "Storage" -> status Element, result "1...done"
15:47:23 Return (0) -> 1 /dev/sg0
15:47:23 LOADSLOT -> loading tape from slot 2 to drive 0 (/dev/sg0)
15:47:23 Running: mtxRunning: loadRunning: 2Running: 0
15:47:42 Exit code: 0
Stdout:
Loading media from Storage Element 2 into drive 0...done
15:47:42 -> status 0, result "Loading" -> status media, result "from" -> status
Storage, result "Element" -> status 2, result "into" -> status drive, result "0.
..done"
15:51:42 Running: mtRunning: -fRunning: /dev/sg0Running: rewind
15:51:42 Exit code: 2
Stderr:
/dev/sg0: Operation not permitted
15:55:42 Exit (2) -> 2 Drive not ready after 240 seconds, rewind said "/dev/sg0:
"Drive not ready after Operation seconds, rewind said "not"Drive not ready after
permitted seconds, rewind said ""
1182542142.852422: chg-zd-mtx: pid 15386 finish time Fri Jun 22 15:55:42 2007

--------------------------------------------------------------------------

Any help would be appreicated, think i'm really close to making this work.

Rich

[ktill]

>/dev/sg0: Operation not permitted

what is the "ls -la /dev/sg0" output?
Does amanda user have access right to it?

[ritl]

this is what it shows

crw-rw---- 1 root disk 21, 0 Jun 20 14:38 /dev/sg0

Figured since it was in the same group shouldn't be a problem. Going to give it a try now and see.

now looks like this -

crw-rw---- 1 amandabackup disk 21, 0 Jun 20 14:38 /dev/sg0

same message -

-------------------------------------------------------------------------
07:52:06 Using config file /etc/amanda/daily/changer.conf
07:52:06 Arg info:
$# = 2
$0 = "/usr/lib/amanda/chg-zd-mtx"
$1 = "-slot"
$2 = "current"
07:52:06 Running: mtxRunning: status
07:52:06 Exit code: 0
Stdout:
Storage Changer /dev/sg0:1 Drives, 7 Slots ( 0 Import/Export )
Data Transfer Element 0:Full (Storage Element 2 Loaded):VolumeTag = A00002

Storage Element 1:Full :VolumeTag=A00001
Storage Element 2:Empty:VolumeTag=
Storage Element 3:Full :VolumeTag=A00003
Storage Element 4:Full :VolumeTag=A00004
Storage Element 5:Full :VolumeTag=A00005
Storage Element 6:Full :VolumeTag=A00006
Storage Element 7:Full :VolumeTag=A00007
07:52:06 Config info:
firstslot = "1"
lastslot = "6"
cleanslot = "7"
cleancycle = "120"
offline_before_unload = "0"
unloadpause = "240"
autoclean = "0"
autocleancount = "99"
havereader = "1"
driveslot = "0"
poll_drive_ready = "240"
initial_poll_delay = "240"
max_drive_wait = "240"
07:52:06 LOADSLOT -> load drive 0 (/dev/sg0) from slot current
07:52:06 STATUS -> currently loaded slot = 2
-> currently loaded barcode = "A00002"
07:52:06 EJECT -> ejecting tape from /dev/sg0
07:52:06 STATUS -> currently loaded slot = 2
-> currently loaded barcode = "A00002"
07:52:06 EJECT -> ejecting tape from /dev/sg0
07:52:06 STATUS -> currently loaded slot = 2
-> currently loaded barcode = "A00002"
07:52:06 EJECT -> moving tape from drive 0 to storage slot 2
07:56:06 Running: mtxRunning: unloadRunning: 2Running: 0
07:56:26 Exit code: 0
Stdout:
Unloading drive 0 into Storage Element 2...done
07:56:26 -> status 0, result "Unloading" -> status drive, result "0" -> status i
nto, result "Storage" -> status Element, result "2...done"
07:56:26 Return (0) -> 2 /dev/sg0
07:56:26 LOADSLOT -> loading tape from slot 1 to drive 0 (/dev/sg0)
07:56:26 Running: mtxRunning: loadRunning: 1Running: 0
07:56:47 Exit code: 0
Stdout:
Loading media from Storage Element 1 into drive 0...done
07:56:47 -> status 0, result "Loading" -> status media, result "from" -> status
Storage, result "Element" -> status 1, result "into" -> status drive, result "0.
..done"
08:00:47 Running: mtRunning: -fRunning: /dev/sg0Running: rewind
08:00:47 Exit code: 2
Stderr:
/dev/sg0: Operation not permitted
08:04:47 Exit (2) -> 1 Drive not ready after 240 seconds, rewind said "/dev/sg0:
08:04:47 Exit (2) -> 1 Drive not ready after 240 seconds, rewind said "/dev/sg0:
"Drive not ready after Operation seconds, rewind said "not"Drive not ready after
permitted seconds, rewind said ""
1182773087.126518: chg-zd-mtx: pid 27312 finish time Mon Jun 25 08:04:47 2007
--------------------------------------------------------------------------

Don't understand, what am i missing?

Rich

[ritl]

Seems there may be a script error?
Everything i'm tied to is mtx which runs fine, but i hit code that say only mt which i believe may be the problem. With in this script we run "Run $MT $MTF $tape rewind 2>&1". Shouldn't the $MT be $MTX?

How do i fix to see if i can get past this point?

Thanks
Rich

--------------------------------------------------------------------------

###
# Wait for the drive to go online.
###
waittime=0
ready=0
sleep $initial_poll_delay
while [ $waittime -lt $max_drive_wait ]; do
result=`Run $MT $MTF $tape rewind 2>&1`
if [ $? -eq 0 ]; then
ready=1
break
fi
sleep $poll_drive_ready
waittime=`expr $waittime + $poll_drive_ready`
done
if [ $ready -eq 0 ]; then
Exit 2 "$loadslot" `_ 'Drive not ready after %s seconds, rewind
said "%s"' "$max_drive_wait" "$result"`
return $? # in case we are internal
fi

[dustin]

You can certainly edit the script to change it to 'mtx', but the rewind operation applies to a tape drive (mt) rather than a changer (mtx), so I expect that the existing code is correct.

Do you get errors running 'mt' operations as user 'amandabackup'?

If you are using Amanda Enterprise Edition, you can open a support ticket to resolve this issue.

[ritl]

Your right the MT is for the tape device. I did change the script to prove the changer is working which it is (put script back to way it was). Appears my issue is with the tape device itself. according to ltotool it is

Scanning your system for tape devices...OK
Device | Address
------------------------+-----------------
IBM ULTRIUM-TD3 | /dev/sg1


But when i use tapedev=/dev/sg1 i get this error message -

changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot current
tapedev /dev/sg1 is not a tape device!
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next
tapedev /dev/sg1 is not a tape device!
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next

Am i telling tapedev the wrong information?

Thanks
Rich

[paddy]

Set tapedev to tape device name. I think /dev/sg1 is the changer device name.

Paddy

[ritl]

Have sg0 as changer
nst0 as tape device

closer, but still not right - get this error message

ERROR taper no-tape [No writable valid tape found]
WARNING taper fatal changer error: slot 4: Drive not ready after 120 seconds, rewind said "/dev/nst0:"Drive not ready after Device seconds, rewind said "or"Drive not ready after resource seconds, rewind said "busy"
WARNING taper changer problem: Drive not ready after 120 seconds, rewind said "/dev/nst0:"Drive not ready after Device seconds, rewind said "or"Drive not ready after resource seconds, rewind said "busy"
FAIL driver portal5.itlcorp.com /etc/amanda/daily 20070626150832 0 [can't switch to incremental dump]

Think i need to format or erase tapes so how to get past this problem.

Rich

[ritl]

Seems i had a process still running - rebooted - tried again and now this is what i get -- I think some how i need to format or erase these tapes to use the amanda specs. Or at least that's how i'm viewing this issue.


changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot current
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next
changer: opening pipe to: /usr/lib/amanda/chg-zd-mtx -slot next
slot 4:not an amanda tape(Input/output error)
slot 5:not an amanda tape(Cannot allocate memory)
slot 6:not an amanda tape(Cannot allocate memory)
slot 1:not an amanda tape (Read 0 bytes)
slot 2:not an amanda tape(Cannot allocate memory)
slot 3:not an amanda tape(Cannot allocate memory)
changer problem: 3 /dev/nst0
driver: result time 1424.629 from taper: TAPE-ERROR <nohandle> "[slot 4:not an amanda tape(Input/output error)\012slot 5:not an amanda tape(Cannot allocate memory)\012slot 6:not an amanda tape(Cannot allocate memory)\012slot 1:not an amanda tape (Read 0 bytes)\012slot 2:not an amanda tape(Cannot allocate memory)\012slot 3:not an amanda tape(Cannot allocate memory)\012changer problem: 3 /dev/nst0]"
driver: state time 1424.629 free kps: 2000 space: 28859052 taper: idle idle-dump
ers: 4 qlen tapeq: 0 runq: 0 roomq: 0 wakeup: 0 driver-idle: not-idle
driver: interface-state time 1424.629 if default: free 600 if local: free 1000 if le0: free 400
driver: hdisk-state time 1424.629 hdisk 0: free 28859052 dumpers 0
driver: flush size 0
dump of driver schedule before start degraded mode: