Q280 doesn't seem to image in initiator mode

Kirkman commented 3 months ago

I'm probably doing something wrong, but my first attempts to image a Q280 80-meg hard drive with a BlueSCSI initiator mode have not worked.

It looked and sounded like it was working. I powered up the hard drive, and its LED came on. Then I powered up the BlueSCSI, and its LED flashed then became solid. The hard drive spun up and it sounded like it was busy reading data. This went on for a long time, longer than I would have thought.

I decided to check the log file on the SD card to see if everything was working okay. I powered down the drive, then powered down the Blue SCSI and checked the SD card.

There was no .HD image on the card. There was only the .INI and log. The log looked like this:

Platform: BlueSCSI Pico
FW Version: 2023.11.17-dev Feb 12 2024 21:57:14
I2C Supported
Flash chip size: 2048 kB
SCSI Initiator Mode.  Will scan the bus for drives to image.

=== SD Card Info ===
SD card detected, exFAT volume size: 121910 MB
SD Name: SK128, MID: 0x03, OID: 0x53 0x44
InitiatorID set to ID 7

Initialization complete!
INFO: Pico Voltage: 3.284V.
RequestSense response: 0x70 0x00 0x02 0x00 0x00 0x00 0x00 0x0A 0x00 0x00 0x00 0x00 0xB0 0x00 0x00 0x00 0x00 0x00 
Target 0 reports NOT_READY, running STARTSTOPUNIT
RequestSense response: 0x70 0x00 0x06 0x00 0x00 0x01 0x00 0x0A 0x00 0x00 0x00 0x00 0x29 0x00 0x00 0x00 0x00 0x00 
START STOP UNIT on target 0 failed, sense key 0x06
RequestSense response: 0x70 0x00 0x02 0x00 0x00 0x00 0x00 0x0A 0x00 0x00 0x00 0x00 0xB0 0x00 0x00 0x00 0x00 0x00 
Target 0 reports NOT_READY, running STARTSTOPUNIT
* No response from SCSI ID 0
* No response from SCSI ID 1
* No response from SCSI ID 2
* No response from SCSI ID 3
* No response from SCSI ID 4

I tried again. This time, I powered the BlueSCSI first, and then the drive. But the pattern was the same ... BlueSCSI reported trying to communicate with SCSI 0 for about 1 second. Then no further log entries for 8 minutes, at which point I powered off the hard drive. Then it resumed scanning the bus. I checked the SD card, and again, no HD image. Only the log file and the INI.

Finally, I realized the firmware was old, so I updated and tried again. This time the BlueSCSI LED behaved a bit differently. It was flashing at first and became solid when I powered on the HD. Then while the HD was spinning, sometimes it would go off for a moment, then come back on solid. After a minute or two, the LED turned off completely. At that point I powered off the drive and pulled the following log (with debugging turned on):

Platform: BlueSCSI
FW Version: 2024.05.21-rel May 21 2024 21:21:44
I2C Supported
Flash chip size: 2048 kB
SCSI Initiator Mode.  Will scan the bus for drives to image.

=== SD Card Info ===
SD card detected, exFAT volume size: 121910 MB
SD Name: SK128, MID: 0x03, OID: 0x53 0x44
[501ms] InitiatorID set to ID 7
[1709ms]  
[1709ms] Initialization complete!
[1727ms] INFO: Pico Voltage: 3.280V.
[2982ms] * No response from SCSI ID 0
[4248ms] * No response from SCSI ID 1
[5514ms] * No response from SCSI ID 2
[6780ms] * No response from SCSI ID 3
[8047ms] * No response from SCSI ID 4
[9340ms] * No response from SCSI ID 5
[10605ms] * No response from SCSI ID 6
[11884ms] * No response from SCSI ID 0
[13150ms] * No response from SCSI ID 1
[14428ms] * No response from SCSI ID 2
[15693ms] * No response from SCSI ID 3
[16969ms] * No response from SCSI ID 4
[18235ms] * No response from SCSI ID 5
[19512ms] * No response from SCSI ID 6
[20779ms] * No response from SCSI ID 0
[22057ms] * No response from SCSI ID 1
[23322ms] * No response from SCSI ID 2
[24602ms] * No response from SCSI ID 3
[25867ms] * No response from SCSI ID 4
[27145ms] * No response from SCSI ID 5
[28410ms] * No response from SCSI ID 6
[29494ms] RequestSense response: 0x70 0x00 0x02 0x00 0x00 0x00 0x00 0x0A 0x00 0x00 0x00 0x00 0xB1 0x00 0x00 0x00 0x00 0x00 
[29494ms] Target 0 reports NOT_READY, running STARTSTOPUNIT
[29605ms] RequestSense response: 0x70 0x00 0x06 0x00 0x00 0x01 0x00 0x0A 0x00 0x00 0x00 0x00 0x29 0x00 0x00 0x00 0x00 0x00 
[29606ms] START STOP UNIT on target 0 failed, sense key 0x06
[29714ms] RequestSense response: 0x70 0x00 0x02 0x00 0x00 0x00 0x00 0x0A 0x00 0x00 0x00 0x00 0xB1 0x00 0x00 0x00 0x00 0x00 
[29714ms] Target 0 reports NOT_READY, running STARTSTOPUNIT
[42725ms] --------------
[42725ms] WATCHDOG TIMEOUT, attempting bus reset
[42725ms] Platform: BlueSCSI
[42725ms] FW Version: 2024.05.21-rel May 21 2024 21:21:44
[42725ms] GPIO states: out 0x1EFFFCFF oe 0x0EA08E00 in 0x1EEBF9FF
[42725ms] scsiDev.cdb: 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
[42725ms] scsiDev.phase: -1
[42725ms] SCSI DMA state: IDLE
[42725ms] Current buffer: 0x00000000/0x00000000, next 0x00000000 bytes
[42725ms] SyncOffset: 0 SyncPeriod 0
[42725ms] PIO Parity SM: tx_fifo 0, rx_fifo 0, pc 24, instr 0x000090A0
[42726ms] PIO Data SM: tx_fifo 0, rx_fifo 0, pc 0, instr 0x00000000
[42726ms] PIO Sync SM: tx_fifo 0, rx_fifo 0, pc 0, instr 0x00000000
[42726ms] DMA CH A: ctrl: 0x00000000 count: 0x00000000
[42726ms] DMA CH B: ctrl: 0x00000000 count: 0x00000000
[42726ms] DMA CH C: ctrl: 0x00000000 count: 0x00000000
[42726ms] DMA CH D: ctrl: 0x00000000 count: 0x00000000
[42726ms] GPIO states: 0x1EEBFDFF
[42726ms] STACK 0x20041D50:    0x10031C6B 0x1EEBF9FF 0x100190F5 0x00000000
[42726ms] STACK 0x20041D60:    0x10031C6B 0x00000000 0x20041DD0 0x00000000
[42726ms] STACK 0x20041D70:    0x200193B0 0x0000000C 0x00000000 0x00000001
[42726ms] STACK 0x20041D80:    0x00000000 0x00000000 0x00000000 0x1001A95D
[42726ms] STACK 0x20041D90:    0x20041DE8 0x00000010 0x00000000 0x20041DE8
[42726ms] STACK 0x20041DA0:    0x20003F50 0x00000000 0x00000040 0xFFFFFFF9
[42726ms] STACK 0x20041DB0:    0x20041DE8 0x20041DD4 0x00000000 0x00000001
[42726ms] STACK 0x20041DC0:    0x2000025F 0x100190A1 0x10019092 0x21000000
[42730ms] * No response from SCSI ID 0
[42753ms] Executing BUS RESET after aborted command
[57726ms] --------------
[57726ms] WATCHDOG TIMEOUT, attempting bus reset
[57726ms] Platform: BlueSCSI
[57726ms] FW Version: 2024.05.21-rel May 21 2024 21:21:44
[57726ms] GPIO states: out 0x1EFFFC7D oe 0x0EA08E00 in 0x1EEBFDFF
[57726ms] scsiDev.cdb: 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
[57726ms] scsiDev.phase: -1
[57726ms] SCSI DMA state: IDLE
[57726ms] Current buffer: 0x00000000/0x00000000, next 0x00000000 bytes
[57726ms] SyncOffset: 0 SyncPeriod 0
[57726ms] PIO Parity SM: tx_fifo 0, rx_fifo 0, pc 24, instr 0x000090A0
[57726ms] PIO Data SM: tx_fifo 0, rx_fifo 0, pc 0, instr 0x00000000
[57726ms] PIO Sync SM: tx_fifo 0, rx_fifo 0, pc 0, instr 0x00000000
[57726ms] DMA CH A: ctrl: 0x00000000 count: 0x00000000
[57726ms] DMA CH B: ctrl: 0x00000000 count: 0x00000000
[57726ms] DMA CH C: ctrl: 0x00000000 count: 0x00000000
[57726ms] DMA CH D: ctrl: 0x00000000 count: 0x00000000
[57726ms] GPIO states: 0x1EEBF9FF
[57726ms] STACK 0x20041D50:    0x10031C6B 0x1EEBFDFF 0x00000000 0x00000002
[57726ms] STACK 0x20041D60:    0x10031C6B 0x00000000 0x20041DD0 0x00000000
[57726ms] STACK 0x20041D70:    0x200193B0 0x0000000C 0x200008EC 0x00000001
[57726ms] STACK 0x20041D80:    0x00000000 0x00000000 0x00000000 0x1001A95D
[57727ms] STACK 0x20041D90:    0x00000000 0x00000010 0xD0000160 0x20041DEC
[57727ms] STACK 0x20041DA0:    0x20000928 0x00000000 0x00000040 0xFFFFFFF9
[57727ms] STACK 0x20041DB0:    0x00000000 0x00000000 0xD0000160 0x00000000
[57727ms] STACK 0x20041DC0:    0x2000025F 0x10022CF7 0x100210FC 0x61000000
[57730ms] * No response from SCSI ID 1
[57764ms] Executing BUS RESET after aborted command
[72727ms] --------------
[72727ms] WATCHDOG TIMEOUT, attempting bus reset
[72727ms] Platform: BlueSCSI
[72727ms] FW Version: 2024.05.21-rel May 21 2024 21:21:44
[72727ms] GPIO states: out 0x1EFFFC7B oe 0x0EA08E00 in 0x1EEBFDFF
[72727ms] scsiDev.cdb: 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
[72727ms] scsiDev.phase: -1
[72727ms] SCSI DMA state: IDLE
[72727ms] Current buffer: 0x00000000/0x00000000, next 0x00000000 bytes
[72727ms] SyncOffset: 0 SyncPeriod 0
[72727ms] PIO Parity SM: tx_fifo 0, rx_fifo 0, pc 24, instr 0x000090A0
[72727ms] PIO Data SM: tx_fifo 0, rx_fifo 0, pc 0, instr 0x00000000
[72727ms] PIO Sync SM: tx_fifo 0, rx_fifo 0, pc 0, instr 0x00000000
[72727ms] DMA CH A: ctrl: 0x00000000 count: 0x00000000
[72727ms] DMA CH B: ctrl: 0x00000000 count: 0x00000000
[72727ms] DMA CH C: ctrl: 0x00000000 count: 0x00000000
[72727ms] DMA CH D: ctrl: 0x00000000 count: 0x00000000
[72727ms] GPIO states: 0x1EEBFDFF
[72727ms] STACK 0x20041DC8:    0x10031C6B 0x1EEBFDFF 0x20000928 0x10022CF7
[72727ms] STACK 0x20041DD8:    0x10031C6B 0x00000000 0x20041E48 0x00000000
[72727ms] STACK 0x20041DE8:    0x200193B0 0x0000000C 0x00000000 0x00000001
[72727ms] STACK 0x20041DF8:    0x00000000 0x00000000 0x00000000 0x1001A95D
[72727ms] STACK 0x20041E08:    0x20041E48 0x00000010 0xD0000000 0x00000002
[72727ms] STACK 0x20041E18:    0x200038F8 0x20000855 0x00080000 0xFFFFFFF9
[72727ms] STACK 0x20041E28:    0x20041E48 0x10000000 0xD0000000 0x1EEBFDFF
[72727ms] STACK 0x20041E38:    0x20000383 0x10009FCF 0x10014356 0x21000000
[72731ms] * No response from SCSI ID 2

androda commented 3 months ago

According to the drive manual it looks like these codes indicate the drive is having a hard time spinning up and stabilizing at operating speed.

In the first log messages, the logs say:

Sense Code 0x02 is 'not ready' and additional code '0xB0' indicates the drive is in recalibration.
Sense code 0x06 is 'unit attention' and additional code '0x29' indicates the drive entered a reset condition.
Sense Code 0x02 is 'not ready' and additional code '0xB0' indicates the drive is in recalibration. No response to commands following this.

In the second set of log messages, we have this series of events:

Sense Code 0x02 is 'not ready' and additional code '0xB1' indicates the drive has not reached a stable working RPM for at least two seconds.
Sense code 0x06 is 'unit attention' and additional code '0x29' indicates the drive entered a reset condition.
Sense Code 0x02 is 'not ready' and additional code '0xB1' indicates the drive has not reached a stable working RPM for at least two seconds.

So the drive succeeded in performing recalibration (probably does this regularly every certain number of spin-ups) because we no longer see B0 in the second set of log messages. But B1 isn't any better, the drive can't reach a stable RPM and then fails to respond to further commands which is triggering the watchdog reset.

Kirkman commented 3 months ago

Thanks so much. So it's a drive issue rather than Blue SCSI, then. Can you recommend any resources where I could find a solution to these drive issues? (I'm wondering if it can't get stable RPM, should I try lubricating something? Switch out the power supply? etc)

BlueSCSI / BlueSCSI-v2

Q280 doesn't seem to image in initiator mode #158