External usb HDD disconnects, system gets messed up

Fri Nov 26 07:17:07 UTC 2010

On Friday 26 November 2010 03:01:59 Nezmer wrote:
> On Thu, Nov 25, 2010 at 09:40:19AM +0100, Hans Petter Selasky wrote:
> > On Thursday 25 November 2010 03:55:26 Nezmer wrote:
> > > Hi,
> > > 
> > > FreeBSD 8.1-STABLE r215402M GENERIC  amd64
> > > 
> > > I'm having a weird issue. I have a 300GB external usb HDD with one ext2
> > > partition. I use ZFS for my internal HDD.
> > > 
> > > Almost daily, The usb HDD disconnects(according to dmesg) and the
> > > system gets messed up. Running processes keep responding but they
> > > would not exit. And no new processes would start running. I eventually
> > > would have to hard reset and run fsck.ext2 on the next run.
> > > 
> > > Any idea what's going on?
> > > Do you need any specific information?
> > 
> > Hi,
> > 
> > When this hang happens you can try to turn on umass debugging:
> > 
> > sysctl hw.usb.umass.debug=-1
> > 
> > You need this option in your kernel config or when building the umass
> > module to enable the sysctl above:
> > 
> > options USB_DEBUG
> > 
> > --HPS
> 
> Thank you for the hint. I managed to freeze the system this time.
> 
> 1st, I tried to cd to a dir and got an I/O error. Here is some debug
> output:
> 
> 
> umass0:umass_bbb_dump_csw: CSW 208387: sig = 0x53425355 (valid), tag =
> 0x00032e03, res = 4096, status = 0x01 (failed)
> umass0:umass_t_bbb_status_callback: Command failed, residue = 4096
> umass0:umass_cam_cb: Fetching 32 bytes of sense data
> umass0:umass_bbb_dump_cbw: CBW 208388: cmd = 6b (0x030000002000), data =
> 32b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=32
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=0
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_t_bbb_status_callback: Failed to read CSW: USB_ERR_STALLED,
> try 0 umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208388: sig = 0x53425355 (valid), tag =
> 0x00032e04, res = 14, status = 0x00 (good) (da0:umass-sim0:0:0:0):
> READ(10). CDB: 28 0 0 0 30 57 0 0 8 0
> (da0:umass-sim0:0:0:0): CAM status: SCSI Status Error
> (da0:umass-sim0:0:0:0): SCSI status: Check Condition
> (da0:umass-sim0:0:0:0): SCSI sense: UNIT ATTENTION asc:28,0 (Not ready to
> ready change, medium may have changed) umass0:umass_cam_action:
> 2:0:0:XPT_SCSI_IO: cmd: 0x28, flags: 0x40, 10b cmd/4096b data/32b sense
> umass0:umass_bbb_dump_cbw: CBW 208389: cmd = 10b (0x280000003057...), data
> = 4096b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=4096
> umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208389: sig = 0x53425355 (valid), tag =
> 0x00032e05, res = 4096, status = 0x01 (failed)
> umass0:umass_t_bbb_status_callback: Command failed, residue = 4096
> umass0:umass_cam_cb: Fetching 32 bytes of sense data
> umass0:umass_bbb_dump_cbw: CBW 208390: cmd = 6b (0x030000002000), data =
> 32b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=32
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=0
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_t_bbb_status_callback: Failed to read CSW: USB_ERR_STALLED,
> try 0 umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208390: sig = 0x53425355 (valid), tag =
> 0x00032e06, res = 14, status = 0x00 (good) (da0:umass-sim0:0:0:0):
> READ(10). CDB: 28 0 0 0 30 57 0 0 8 0
> (da0:umass-sim0:0:0:0): CAM status: SCSI Status Error
> (da0:umass-sim0:0:0:0): SCSI status: Check Condition
> (da0:umass-sim0:0:0:0): SCSI sense: UNIT ATTENTION asc:28,0 (Not ready to
> ready change, medium may have changed) umass0:umass_cam_action:
> 2:0:0:XPT_SCSI_IO: cmd: 0x28, flags: 0x40, 10b cmd/4096b data/32b sense
> umass0:umass_bbb_dump_cbw: CBW 208391: cmd = 10b (0x280000003057...), data
> = 4096b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=4096
> umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208391: sig = 0x53425355 (valid), tag =
> 0x00032e07, res = 4096, status = 0x01 (failed)
> umass0:umass_t_bbb_status_callback: Command failed, residue = 4096
> umass0:umass_cam_cb: Fetching 32 bytes of sense data
> umass0:umass_bbb_dump_cbw: CBW 208392: cmd = 6b (0x030000002000), data =
> 32b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=32
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=0
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_t_bbb_status_callback: Failed to read CSW: USB_ERR_STALLED,
> try 0 umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208392: sig = 0x53425355 (valid), tag =
> 0x00032e08, res = 14, status = 0x00 (good) (da0:umass-sim0:0:0:0):
> READ(10). CDB: 28 0 0 0 30 57 0 0 8 0
> (da0:umass-sim0:0:0:0): CAM status: SCSI Status Error
> (da0:umass-sim0:0:0:0): SCSI status: Check Condition
> (da0:umass-sim0:0:0:0): SCSI sense: UNIT ATTENTION asc:28,0 (Not ready to
> ready change, medium may have changed) umass0:umass_cam_action:
> 2:0:0:XPT_SCSI_IO: cmd: 0x28, flags: 0x40, 10b cmd/4096b data/32b sense
> umass0:umass_bbb_dump_cbw: CBW 208393: cmd = 10b (0x280000003057...), data
> = 4096b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=4096
> umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208393: sig = 0x53425355 (valid), tag =
> 0x00032e09, res = 4096, status = 0x01 (failed)
> umass0:umass_t_bbb_status_callback: Command failed, residue = 4096
> umass0:umass_cam_cb: Fetching 32 bytes of sense data
> umass0:umass_bbb_dump_cbw: CBW 208394: cmd = 6b (0x030000002000), data =
> 32b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=32
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=0
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_t_bbb_status_callback: Failed to read CSW: USB_ERR_STALLED,
> try 0 umass0:umass_transfer_start: transfer index = 5
> umass0:umass_transfer_start: transfer index = 8
> umass0:umass_bbb_dump_csw: CSW 208394: sig = 0x53425355 (valid), tag =
> 0x00032e0a, res = 14, status = 0x00 (good) (da0:umass-sim0:0:0:0):
> READ(10). CDB: 28 0 0 0 30 57 0 0 8 0
> (da0:umass-sim0:0:0:0): CAM status: SCSI Status Error
> (da0:umass-sim0:0:0:0): SCSI status: Check Condition
> (da0:umass-sim0:0:0:0): SCSI sense: UNIT ATTENTION asc:28,0 (Not ready to
> ready change, medium may have changed) umass0:umass_cam_action:
> 2:0:0:XPT_SCSI_IO: cmd: 0x28, flags: 0x40, 10b cmd/4096b data/32b sense
> umass0:umass_bbb_dump_cbw: CBW 208395: cmd = 10b (0x280000003057...), data
> = 4096b, lun = 0, dir = in umass0:umass_transfer_start: transfer index = 4
> umass0:umass_t_bbb_data_read_callback: max_bulk=131072, data_rem=4096
> umass0:umass_transfer_start: transfer index = 5
> umass0:umass_tr_error: transfer error, USB_ERR_TIMEOUT -> reset
> umass0:umass_cam_action: 2:0:0:XPT_SCSI_IO: cmd: 0x03, flags: 0x40, 6b
> cmd/32b data/32b sense umass0:umass_t_bbb_reset1_callback: BBB reset!
> umass0:umass_tr_error: transfer error, USB_ERR_TIMEOUT -> reset
> (da0:umass-sim0:0:0:0): AutoSense failed
> g_vfs_done():ext2fs/EXTERNAL[READ(offset=6303744, length=4096)]error = 5
> 
> Then I tried to umount and the system froze. I obviously couldn't save
> any dmesg output. But I think a try to write to the system and
> "fsync giving up on dirty" caused the freeze.
> 
> I took some pictures of the screen. So I can write more output down if
> needed.

Hi,

I think that the USB part of your USB disk has died or there has been a 
firmware crash. Other OS'es will perform a complete device reset in this 
situation and sometimes that help, but still that is hiding a problem about 
the device. We don't do that on FreeBSD, and that might be the reason it does 
not recover.

Check that your disk has external power supply! Sometimes the power supplied 
on the USB port is not sufficient.

--HPS