Ongoing SCSI issues
Jason Selwitz
jselwitz at vvisions.com
Mon Oct 6 15:10:08 UTC 2008
First off I would like to thank everyone so far that has offered
suggestions on the isp driver and for trying to help me get my tape
changer up and working, alas things are still not right in the world so
I have I am hoping some of the debugging info below may help I am so far
at a loss so if anything below sparks any Idea please feel free to drop
me a line.. thanks again..
isp0: <Qlogic ISP 2432 PCI FC-AL Adapter> port 0x5000-0x50ff mem
0xc6ffc000-0xc6ffffff irq 19 at device 0.0 on pci7
isp0: [ITHREAD]
isp0: Board Type 2422, Chip Revision 0x3, resident F/W Revision 4.3.1
sa0 at isp0 bus 0 target 0 lun 0
sa0: <IBM ULTRIUM-TD4 77BB> Removable Sequential Access SCSI-3 device
sa0: 400.000MB/s transfers
sa0: Command Queueing Enabled
ch0: <SPECTRA PYTHON 2000> Removable Changer SCSI-3 device
ch0: 400.000MB/s transfers
ch0: Command Queueing Enabled
ch0: 50 slots, 1 drive, 1 picker, 0 portals
vvalbbacula# mtx -f /dev/pass1 status
Storage Changer /dev/pass1:1 Drives, 50 Slots ( 0 Import/Export )
Data Transfer Element 0:Empty
Storage Element 1:Full :VolumeTag=027739L4
Storage Element 2:Full :VolumeTag=027738L4
Storage Element 3:Full :VolumeTag=027737L4
Storage Element 4:Full :VolumeTag=027736L4
Storage Element 5:Full :VolumeTag=027735L4
Storage Element 6:Full :VolumeTag=028319L4
Storage Element 7:Full :VolumeTag=028318L4
Storage Element 8:Full :VolumeTag=028317L4
Storage Element 9:Full :VolumeTag=028316L4
Storage Element 10:Full
:VolumeTag=028315L4
Storage Element 11:Full
:VolumeTag=027944L4
Storage Element 12:Full
:VolumeTag=027943L4
Storage Element 13:Full
:VolumeTag=027942L4
Storage Element 14:Full
:VolumeTag=027941L4
Storage Element 15:Full
:VolumeTag=027940L4
Storage Element 16:Full
:VolumeTag=028314L4
Storage Element 17:Full
:VolumeTag=028313L4
Storage Element 18:Full
:VolumeTag=028312L4
Storage Element 19:Full
:VolumeTag=028311L4
Storage Element 20:Full
:VolumeTag=028310L4
Storage Element 21:Full
:VolumeTag=029139L4
Storage Element 22:Full
:VolumeTag=029138L4
Storage Element 23:Full
:VolumeTag=029137L4
Storage Element 24:Full
:VolumeTag=029136L4
Storage Element 25:Full
:VolumeTag=029135L4
Storage Element 26:Full
:VolumeTag=029134L4
Storage Element 27:Full
:VolumeTag=029133L4
Storage Element 28:Full
:VolumeTag=029132L4
Storage Element 29:Full
:VolumeTag=029131L4
Storage Element 30:Full
:VolumeTag=029130L4
Storage Element 31:Full
:VolumeTag=027949L4
Storage Element 32:Full
:VolumeTag=027948L4
Storage Element 33:Full
:VolumeTag=027947L4
Storage Element 34:Full
:VolumeTag=027946L4
Storage Element 35:Full
:VolumeTag=027945L4
Storage Element 36:Full
:VolumeTag=028779L4
Storage Element 37:Full
:VolumeTag=028778L4
Storage Element 38:Full
:VolumeTag=028777L4
Storage Element 39:Full
:VolumeTag=028776L4
Storage Element 40:Full
:VolumeTag=028775L4
Storage Element 41:Full
:VolumeTag=027734L4
Storage Element 42:Full
:VolumeTag=027733L4
Storage Element 43:Full
:VolumeTag=027732L4
Storage Element 44:Full
:VolumeTag=027731L4
Storage Element 45:Full
:VolumeTag=027730L4
Storage Element 46:Full
:VolumeTag=028774L4
Storage Element 47:Full
:VolumeTag=028773L4
Storage Element 48:Full
:VolumeTag=028772L4
Storage Element 49:Full
:VolumeTag=028771L4
Storage Element 50:Full
:VolumeTag=028770L4
vvalbbacula# mtx -f /dev/pass1 load 1 0
Loading media from Storage Element 1 into drive 0...mtx: Request Sense:
Long Report=yes
mtx: Request Sense: Valid Residual=no
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Illegal Request
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Additional Sense Code = 25
mtx: Request Sense: Additional Sense Qualifier = 00
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 4096 to 256 Failed
debug data:
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_done
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): camisr
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_release_ccb
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): entering cdgetccb
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_schedule
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): added periph
to queue
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): calling
xpt_run_devq
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_run_dev_allocq
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: qfrozen_cnt == 0x0,
entries == 1, openings == 4096, active == 0
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: running device
0xffffff00015b8800
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_setup_ccb
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: calling periph start
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_action
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): READ ELEMENT
STATUS. CDB: b8 14 1 0 0 1 0 0 11 38 0 0
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_run_dev_sendq
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: running device
0xffffff00015b8800
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): isp_action
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_done
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): camisr
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_release_ccb
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): entering cdgetccb
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_schedule
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): added periph
to queue
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): calling
xpt_run_devq
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_run_dev_allocq
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: qfrozen_cnt == 0x0,
entries == 1, openings == 4096, active == 0
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: running device
0xffffff00015b8800
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_setup_ccb
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: calling periph start
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_action
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): READ ELEMENT
STATUS. CDB: b8 11 0 1 0 1 0 0 11 38 0 0
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: xpt_run_dev_sendq
Oct 6 10:56:35 vvalbbacula kernel: cam_debug: running device
0xffffff00015b8800
Oct 6 10:56:35 vvalbbacula kernel: (pass1:isp0:0:0:1): isp_action
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_done
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): camisr
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: xpt_release_ccb
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): entering cdgetccb
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_schedule
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): added periph
to queue
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): calling
xpt_run_devq
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: xpt_run_dev_allocq
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: qfrozen_cnt == 0x0,
entries == 1, openings == 4096, active == 0
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: running device
0xffffff00015b8800
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_setup_ccb
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: calling periph start
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_action
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): MOVE MEDIUM.
CDB: a5 0 0 1 10 0 1 0 0 0 0 0
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: xpt_run_dev_sendq
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: running device
0xffffff00015b8800
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): isp_action
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): cam completion
status 0xcc
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_done
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): camisr
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_setup_ccb
Oct 6 10:56:36 vvalbbacula kernel: (pass1:isp0:0:0:1): xpt_action
Oct 6 10:56:36 vvalbbacula kernel: cam_debug: xpt_release_ccb
After manually loading a tape into the drive:
vvalbbacula# mt status
mt: /dev/nsa0: Device not configured
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): saopen(0): dev=0x0
softc=0x0
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): entering cdgetccb
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_schedule
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): added periph to
queue
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): calling
xpt_run_devq
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: xpt_run_dev_allocq
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: qfrozen_cnt == 0x0,
entries == 1, openings == 4096, active == 0
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: running device
0xffffff0001361000
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: calling periph start
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): sastart
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: queuing for immediate ccb
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): RESERVE(06). CDB:
16 0 0 0 0 0
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: xpt_run_dev_sendq
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: running device
0xffffff0001361000
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): isp_action
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): cam completion
status 0xcc
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_done
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): camisr
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): CDB[0]=0x16 Key
0x5 ASC/ASCQ 0x25/0x0 CAM STATUS 0xc flags 0x0 resid 0 dxfer_len 0
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:00:49 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:00:49 vvalbbacula kernel: cam_debug: xpt_release_ccb
vvalbbacula# tar -cf /dev/sa0 ./*
tar: Failed to open '/dev/sa0': Device not configured
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): saopen(0): dev=0x0
softc=0x0
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): entering cdgetccb
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_schedule
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): added periph to
queue
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): calling
xpt_run_devq
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: xpt_run_dev_allocq
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: qfrozen_cnt == 0x0,
entries == 1, openings == 4096, active == 0
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: running device
0xffffff0001361000
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: calling periph start
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): sastart
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: queuing for immediate ccb
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): RESERVE(06). CDB:
16 0 0 0 0 0
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: xpt_schedule_dev
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: Inserting onto queue
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: xpt_run_dev_sendq
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: running device
0xffffff0001361000
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): isp_action
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): cam completion
status 0xcc
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_done
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): camisr
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): CDB[0]=0x16 Key
0x5 ASC/ASCQ 0x25/0x0 CAM STATUS 0xc flags 0x0 resid 0 dxfer_len 0
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_setup_ccb
Oct 6 11:02:53 vvalbbacula kernel: (sa0:isp0:0:0:0): xpt_action
Oct 6 11:02:53 vvalbbacula kernel: cam_debug: xpt_release_ccb
--
Jason Selwitz
Network Systems Administrator
Vicarious Visions
150 Broadway
Menands, NY 12204
Phone: 518-701-2488
More information about the freebsd-scsi
mailing list