mhvtl woes after scsi rescan

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

mhvtl woes after scsi rescan

ap2010
Hi Mark,

have updated to the latest git (as of March 1st, 2013) and found a problem.

I was rescanning iscsi targets on the machine which had one drive and one library configured and working, because I was fiddling with online resize of iscsi targets.

Here are the software requirements:

install lsscsi
install sg3_utils

First show all scsi devices with lsscsi, this will show amongst others both library and drive.
Then run

scsi-rescan --forcerescan

After this you will notice that lsscsi doesn't show the drive anymore, although the daemons are running:

vtl       2149     1  0 10:57 ?        00:00:00 vtltape -q 11
vtl       2153     1  0 10:57 ?        00:00:00 vtllibrary -q 10

I can read out the changer with mtx, but the /dev/st0 /dev/nst0 device is gone now.

It is reproducable (I am using Centos 6.3) so you can have a look at it yourself.

And a service mhvtl stop will freeze the system.

Regards,

Albert
Reply | Threaded
Open this post in threaded view
|

Re: mhvtl woes after scsi rescan

Mark Harvey
Administrator
I've tried the 'scsi-rescan --forcerescan' on my CentOS 6.3 host (no iSCSI involved) a few times with no ill effects.

What was the iSCSI target you are using ?

Do you have the syslog for anaylsis ?
Based on your description, I would guess that a kernel module has oops.
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|

Re: mhvtl woes after scsi rescan

ap2010
Hi Mark,

the iscsi target, a QNAP, is not important, I just noticed this playing with the target. Anyway, used a clean machine this morning,
only scsi devices, the harddrive, the library and one tape.

[root@moonlight ~]# lsscsi
[3:0:0:0]    disk    ATA      WDC WD5000AZRX-0 01.0  /dev/sda
[4:0:0:0]    mediumx HP       MSL G3 Series    0104  /dev/sch0
[4:0:1:0]    tape    HP       Ultrium 3-SCSI   0104  /dev/st0


Now I do a rescan:

[root@moonlight ~]# scsi-rescan --forcerescan
Host adapter 0 (ata_piix) found.
Host adapter 1 (ata_piix) found.
Host adapter 2 (ata_piix) found.
Host adapter 3 (ata_piix) found.
Host adapter 4 (mhvtl) found.
Scanning SCSI subsystem for new devices
 and remove devices that have disappeared
Scanning host 0 for  SCSI target IDs  0 1 2 3 4 5 6 7, all LUNs
Scanning host 1 for  SCSI target IDs  0 1 2 3 4 5 6 7, all LUNs
Scanning host 2 for  SCSI target IDs  0 1 2 3 4 5 6 7, all LUNs
Scanning host 3 for  SCSI target IDs  0 1 2 3 4 5 6 7, all LUNs
Scanning for device 3 0 0 0 ...
OLD: Host: scsi3 Channel: 00 Id: 00 Lun: 00
      Vendor: ATA      Model: WDC WD5000AZRX-0 Rev: 01.0
      Type:   Direct-Access                    ANSI SCSI revision: 05
Scanning host 4 channels  0 for  SCSI target IDs  0 1 2 3 4 5 6 7, all LUNs
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 0 0 ...
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00
OLD: Host: scsi4 Channel: 00 Id: 00 Lun: 00    Rev: 0104
      Vendor: HP       Model: MSL G3 Series    Rev: 0104 revision: 05
      Type:   Medium Changer                   ANSI SCSI revision: 05
Scanning for device 4 0 1 0 ....
REM: Host: scsi4 Channel: 00 Id: 01 Lun: 00
      Vendor: HP       Model: Ultrium 3-SCSI   Rev: 0104
DEL:  Type:   Sequential-Access                ANSI SCSI revision: 05

0 new device(s) found.                write error: Invalid argument
1 device(s) removed.                


As you can see, it removed the tape drive. I had set both library and tape device to full verbose, and so:


Mar  2 09:31:01 moonlight vtllibrary[2128]: processMessageQ(): verbose: enabled at level 3
Mar  2 09:31:05 moonlight vtltape[2124]: processMessageQ(): Verbose: enabled at level 3
Mar  2 09:32:48 moonlight kernel: ata4: soft resetting link
Mar  2 09:32:48 moonlight kernel: ata4.00: configured for UDMA/133
Mar  2 09:32:48 moonlight kernel: ata4: EH complete
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (36) (delay 477205): 00 00 00 00 00 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (36) Online **
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (36), sz: 0, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (37) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (37)
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (37), sz: 64, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (38) (delay 13605): 00 00 00 00 00 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (38) Online **
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (38), sz: 0, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (39) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (39)
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (39), sz: 64, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (40) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (40) Online **
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (40), sz: 0, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (41) (delay 2805): 12 00 00 00 24 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (41)
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (41), sz: 64, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (42) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (42) Online **
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (42), sz: 0, sam_status: 0
Mar  2 09:32:49 moonlight vtllibrary[2128]: CDB (43) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:49 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (43)
Mar  2 09:32:49 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (43), sz: 64, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (44) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (44) Online **
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (44), sz: 0, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (45) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (45)
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (45), sz: 64, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (46) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (46) Online **
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (46), sz: 0, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (47) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (47)
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (47), sz: 64, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (48) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (48) Online **
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (48), sz: 0, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (49) (delay 2805): 12 00 00 00 24 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (49)
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (49), sz: 64, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (50) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (50) Online **
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (50), sz: 0, sam_status: 0
Mar  2 09:32:50 moonlight vtllibrary[2128]: CDB (51) (delay 2805): 12 00 00 00 24 00
Mar  2 09:32:50 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (51)
Mar  2 09:32:50 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (51), sz: 64, sam_status: 0
Mar  2 09:32:51 moonlight vtllibrary[2128]: CDB (52) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:51 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (52) Online **
Mar  2 09:32:51 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (52), sz: 0, sam_status: 0
Mar  2 09:32:51 moonlight vtllibrary[2128]: CDB (53) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:51 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (53)
Mar  2 09:32:51 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (53), sz: 64, sam_status: 0
Mar  2 09:32:51 moonlight vtllibrary[2128]: CDB (54) (delay 14005): 00 00 00 00 00 00
Mar  2 09:32:51 moonlight vtllibrary[2128]: spc_tur(): ** Test Unit Ready : Returning =>  (54) Online **
Mar  2 09:32:51 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (54), sz: 0, sam_status: 0
Mar  2 09:32:51 moonlight vtllibrary[2128]: CDB (55) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:51 moonlight vtllibrary[2128]: spc_inquiry(): INQUIRY ** (55)
Mar  2 09:32:51 moonlight vtllibrary[2128]: completeSCSICommand(): OP s/n: (55), sz: 64, sam_status: 0
Mar  2 09:32:51 moonlight vtltape[2124]: CDB (57) (delay 479605): 00 00 00 00 00 00
Mar  2 09:32:51 moonlight vtltape[2124]: mkSenseBuf(): SENSE [Key/ASC/ASCQ] [02 3a 00]
Mar  2 09:32:51 moonlight vtltape[2124]: ssc_tur(): Test Unit Ready (57) ** : No, No tape loaded
Mar  2 09:32:51 moonlight vtltape[2124]: completeSCSICommand(): OP s/n: (57), sz: 0, sam_status: 2
Mar  2 09:32:51 moonlight vtltape[2124]: completeSCSICommand(): [Key/ASC/ASCQ] [02 3a 00]
Mar  2 09:32:51 moonlight vtltape[2124]: CDB (58) (delay 2405): 12 00 00 00 24 00
Mar  2 09:32:51 moonlight vtltape[2124]: spc_inquiry(): INQUIRY ** (58)
Mar  2 09:32:51 moonlight vtltape[2124]: completeSCSICommand(): OP s/n: (58), sz: 64, sam_status: 0


and thus:

[root@moonlight ~]# lsscsi
[3:0:0:0]    disk    ATA      WDC WD5000AZRX-0 01.0  /dev/sda
[4:0:0:0]    mediumx HP       MSL G3 Series    0104  /dev/sch0


Any ideas, suggestions what to check next?

Cheers,

Albert

On 03/02/2013 05:36 AM, Mark Harvey [via MHVTL - Linux Virtual Tape Library - Community Forums] wrote:
I've tried the 'scsi-rescan --forcerescan' on my CentOS 6.3 host (no iSCSI involved) a few times with no ill effects.

What was the iSCSI target you are using ?

Do you have the syslog for anaylsis ?
Based on your description, I would guess that a kernel module has oops.
Regards from Australia
Mark Harvey



To unsubscribe from mhvtl woes after scsi rescan, click here.
NAML

Reply | Threaded
Open this post in threaded view
|

Re: mhvtl woes after scsi rescan

ap2010
Ok,

I came a bit further now.

When no tape is loaded, the tape drive gives test unit ready error, tape not loaded (obviously) and scsi-rescan removes the device. When a tape is loaded, it leaves it as it is, as the test unit ready is ok.

I guess it works as advertised (the scsi scanning that is).

Albert