Subject: SCSI error with 6-in-1 USB card reader
To: None <netbsd-users@netbsd.org>
From: Klaus Heinz <k.heinz.dez.zwei@onlinehome.de>
List: netbsd-users
Date: 12/10/2002 22:41:59
--CE+1k2dSO48ffgeK
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

Hi,

the device is a Tevion card reader used with a 128MB CF card, OS is
NetBSD/i386 1.5.4_ALPHA (about 3 weeks old).

Attaching the reader to the USB port seems to work:

 umass0 at uhub0 port 2 configuration 1 interface 0
 
 umass0: Generic USBMass Storage Device, rev 1.10/1.33, addr 2
 umass0: using SCSI over BBB-P
 scsibus0 at umass0: 2 targets, 4 luns per target
 scsibus0: waiting 2 seconds for devices to settle...
 sd0 at scsibus0 target 1 lun 0: <Generic, Flash R/W, 2002> SCSI2 0/direct
 removable
 sd0: drive offline
 sd1 at scsibus0 target 1 lun 1: <Generic, Flash R/W, 2002> SCSI2 0/direct
 removable
 sd1: could not mode sense (4/5); using fictitious geometry
 sd1: 122 MB, 122 cyl, 64 head, 32 sec, 512 bytes/sect x 250448 sectors
 sd2 at scsibus0 target 1 lun 2: <Generic, Flash R/W, 2002> SCSI2 0/direct
 removable
 sd2: drive offline
 sd3 at scsibus0 target 1 lun 3: <Generic, Flash R/W, 2002> SCSI2 0/direct
 removable
 sd3: drive offline

When I try to look at sd1 with 'disklabel' I get this:

 # disklabel sd1
 disklabel: can't read master boot record: Invalid argument

 # /dev/rsd1d:
 type: SCSI
 disk: Flash R/W
 label: fictitious
 flags:
 bytes/sector: 512
 sectors/track: 32
 tracks/cylinder: 64
 sectors/cylinder: 2048
 cylinders: 122
 total sectors: 250448
 rpm: 3600
 interleave: 1
 trackskew: 0
 cylinderskew: 0
 headswitch: 0           # microseconds
 track-to-track seek: 0  # microseconds
 drivedata: 0

 4 partitions:
 #        size   offset     fstype   [fsize bsize cpg/sgs]
   d:   250448        0     unused        0     0         # (Cyl.    0 - 122*)
 disklabel: boot block size 0
 disklabel: super block size 0

And syslog shows this:

 sd1: could not mode sense (4/5); using fictitious geometry
 sd1(umass0:1:1):  Check Condition on CDB: 0x08 20 00 00 01 00
     SENSE KEY:  Illegal Request
      ASC/ASCQ:  Invalid Command Operation Code

 sd1: dos partition I/O error
 sd1(umass0:1:1):  Check Condition on CDB: 0x08 20 00 00 01 00
     SENSE KEY:  Illegal Request
      ASC/ASCQ:  Invalid Command Operation Code

Any hints what to do? To me this looks more like some problem in the
scsi layer. Is there anything I could add to a quirk table somewhere?

I have attached a more detailed log (SCSIDEBUG, UMASS_DEBUG and
USB_DEBUG in the kernel, variable 'umassdebug' set to -1 with ddb).

ciao
     Klaus


--CE+1k2dSO48ffgeK
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="usb.05492a.log"

root@silence:SILENCE/ [28]# disklabel sd1
disklabel: can't read master boot record: Invalid argument
# /dev/rsd1d:
type: SCSI
disk: Flash R/W
label: fictitious
flags:
bytes/sector: 512
sectors/track: 32
tracks/cylinder: 64
sectors/cylinder: 2048
cylinders: 122
total sectors: 250448
rpm: 3600
interleave: 1
trackskew: 0
cylinderskew: 0
headswitch: 0           # microseconds
track-to-track seek: 0  # microseconds
drivedata: 0 

4 partitions:
#        size   offset     fstype   [fsize bsize cpg/sgs]
  d:   250448        0     unused        0     0         # (Cyl.    0 - 122*)
disklabel: boot block size 0
disklabel: super block size 0




 sd1(umass0:1:1): sdopen: dev=0xd0b (unit 1 (of 4), partition 3)
 sd1(umass0:1:1): scsi_scsipi_cmd
 sd1(umass0:1:1): scsipi_get_xs
 sd1(umass0:1:1): calling pool_get
 sd1(umass0:1:1): returning
 scsipi_exec_cmd: xs(0xc0f84000): xs_control(0x000001a0)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0xea60)cmd(0xc0f84084)len(0x6)data(0x0)len(0x0)res(0x0)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1b,0x20,0x0,0x0,0x1,0x0-[0 bytes]
 
 umass0: umass_scsi_cmd:  1:1 xs=0xc0f84000 cmd=0x1b (quirks=0x100e, poll=0)
 xs(0xc0f84000): xs_control(0x000001a0)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0xea60)cmd(0xc0f84084)len(0x6)data(0x0)len(0x0)res(0x0)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1b,0x20,0x0,0x0,0x1,0x0-[0 bytes]
 umass_scsi_cmd: async dir=0, cmdlen=6 datalen=0
 umass0: umass_bbb_transfer cmd=0x1b
 umass0: CBW 240: cmd = 6b (0x1b2000000100), data = 0 bytes, dir = out
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: no data phase
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 240: sig = 0x53425355 (valid), tag = 240, res = 0, status = 0x00 (good)
 umass_scsipi_cb: xs=0xc0f84000 residue=0 status=0
 umass_scsipi_cb: return xs->error=0, xs->xs_status=0x1 xs->resid=0
 sd1(umass0:1:1): scsipi_done
 sd1(umass0:1:1): command: 0x1b,0x20,0x0,0x0,0x1,0x0-[0 bytes]
 sd1(umass0:1:1): back in cmd()
 sd1(umass0:1:1): sc_err1,err = 0x0 
 sd1(umass0:1:1): scsipi_free_xs
 sd1(umass0:1:1): calling private start()
 sd1(umass0:1:1): sdstart sd1(umass0:1:1): scsi_scsipi_cmd
 sd1(umass0:1:1): scsipi_get_xs
 sd1(umass0:1:1): calling pool_get
 sd1(umass0:1:1): returning
 scsipi_exec_cmd: xs(0xc0f84000): xs_control(0x00000180)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0x1388)cmd(0xc0f84084)len(0x6)data(0x0)len(0x0)res(0x0)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1e,0x20,0x0,0x0,0x1,0x0-[0 bytes]
 
 umass0: umass_scsi_cmd:  1:1 xs=0xc0f84000 cmd=0x1e (quirks=0x100e, poll=0)
 xs(0xc0f84000): xs_control(0x00000180)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0x1388)cmd(0xc0f84084)len(0x6)data(0x0)len(0x0)res(0x0)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1e,0x20,0x0,0x0,0x1,0x0-[0 bytes]
 umass_scsi_cmd: async dir=0, cmdlen=6 datalen=0
 umass0: umass_bbb_transfer cmd=0x1e
 umass0: CBW 241: cmd = 6b (0x1e2000000100), data = 0 bytes, dir = out
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: no data phase
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 241: sig = 0x53425355 (valid), tag = 241, res = 0, status = 0x00 (good)
 umass_scsipi_cb: xs=0xc0f84000 residue=0 status=0
 umass_scsipi_cb: return xs->error=0, xs->xs_status=0x1 xs->resid=0
 sd1(umass0:1:1): scsipi_done
 sd1(umass0:1:1): command: 0x1e,0x20,0x0,0x0,0x1,0x0-[0 bytes]
 sd1(umass0:1:1): back in cmd()
 sd1(umass0:1:1): sc_err1,err = 0x0 
 sd1(umass0:1:1): scsipi_free_xs
 sd1(umass0:1:1): calling private start()
 sd1(umass0:1:1): sdstart sd1(umass0:1:1): scsi_scsipi_cmd
 sd1(umass0:1:1): scsipi_get_xs
 sd1(umass0:1:1): calling pool_get
 sd1(umass0:1:1): returning
 scsipi_exec_cmd: xs(0xc0f84000): xs_control(0x00040820)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0x1770)cmd(0xc0f84084)len(0x6)data(0xe4121d50)len(0x2c)res(0x2c)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1a,0x20,0x4,0x0,0x20,0x0-[44 bytes]
 ------------------------------
 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 032: 00 00 00 00 00 00 00 00 00 00 00 00 
 ------------------------------
 
 umass0: umass_scsi_cmd:  1:1 xs=0xc0f84000 cmd=0x1a (quirks=0x100e, poll=0)
 xs(0xc0f84000): xs_control(0x00040820)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0x1770)cmd(0xc0f84084)len(0x6)data(0xe4121d50)len(0x2c)res(0x2c)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1a,0x20,0x4,0x0,0x20,0x0-[44 bytes]
 ------------------------------
 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 032: 00 00 00 00 00 00 00 00 00 00 00 00 
 ------------------------------
 umass_scsi_cmd: async dir=1, cmdlen=6 datalen=44
 umass0: umass_bbb_transfer cmd=0x1a
 umass0: CBW 242: cmd = 6b (0x1a2004002000), data = 44 bytes, dir = in
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: start xfer buffer=0xe3f4c000 buflen=44 flags=0x5 timeout=10403
 umass0: Handling BBB state 2 (BBB Data), xfer=0xc0f54f00, STALLED
 umass0: Data-in 44b failed, STALLED
 umass0: Clear endpoint 0x82 stall
 umass0: Handling BBB state 3 (BBB Data bulk-in/-out clear stall), xfer=0xc0ebb900, NORMAL_COMPLETION
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 242: sig = 0x53425355 (valid), tag = 242, res = 44, status = 0x01 (failed)
 umass0: Command Failed, res = 44
 umass_scsipi_cb: xs=0xc0f84000 residue=44 status=2
 umass0: umass_bbb_transfer cmd=0x03
 umass0: CBW 243: cmd = 6b (0x032000002000), data = 32 bytes, dir = in
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: start xfer buffer=0xe3f4c000 buflen=32 flags=0x5 timeout=10403
 umass0: Handling BBB state 2 (BBB Data), xfer=0xc0f54f00, NORMAL_COMPLETION
 umass0: 0x 700005000000000c0000000024000000 buffer=0xc0f8405c, buflen=32
 umass0: 0x 00000000000000000000000000000000
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 ta), xfer=0xc0f54f00, STALLED
 umass0: Data-in 512b failed, STALLED
 umass0: Clear endpoint 0x82 stall
 umass0: Handling BBB state 3 (BBB Data bulk-in/-out clear stall), xfer=0xc0ebb900, NORMAL_COMPLETION
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 247: sig = 0x53425355 (valid), tag = 247, res = 512, status = 0x01 (failed)
 umass0: Command Failed, res = 512
 umass_scsipi_cb: xs=0xc0f84000 residue=512 status=2
 umass0: umass_bbb_transfer cmd=0x03
 umass0: CBW 248: cmd = 6b (0x032000002000), data = 32 bytes, dir = in
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: start xfer buffer=0xe3f4c000 buflen=32 flags=0x5 timeout=10403
 umass0: Handling BBB state 2 (BBB Data), xfer=0xc0f54f00, NORMAL_COMPLETION
 umass0: 0x 700005000000000c0000000020000000 buffer=0xc0f8405c, buflen=32
 umass0: 0x 00000000000000000000000000000000
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 248: sig = 0x53425355 (valid), tag = 248, res = 12, status = 0x00 (good)
 umass_scsipi_sense_cb: xs=0xc0f84000 residue=12 status=0
 umass_scsipi_sense_cb: return xs->error=2, xs->xs_status=0x1 xs->resid=512
 sd1(umass0:1:1): scsipi_done
 sd1(umass0:1:1): command: 0x8,0x20,0x0,0x0,0x1,0x0-[512 bytes]
 ------------------------------
 000: 30 2c 33 32 3b 70 61 5f 73 6c 6f 74 3a 28 36 38 
 016: 2c 32 29 2c 33 32 2c 33 32 3b 3b 00 2e 2e 2f 2e 
 032: 2e 2f 2e 2e 2f 2e 2e 2f 64 65 76 2f 70 63 6b 62 
 048: 63 2f 70 73 6d 72 65 67 2e 68 00 2e 2e 2f 2e 2e 
 ------------------------------
 sd1(umass0:1:1): sc_err1,err = 0x2 
 code 0x70 valid 0x0 seg 0x0 key 0x5 ili 0x0 eom 0x0 fmark 0x0
 info: 0x0 0x0 0x0 0x0 followed by 12 extra bytes
 extra: 0x0 0x0 0x0 0x0 0x20 0x0 0x0 0x0 0x0 0x0 0x0 0x0 
 sd1(umass0:1:1): calling private err_handler()
 sd1(umass0:1:1):  Check Condition on CDB: 0x08 20 00 00 01 00
     SENSE KEY:  Illegal Request
      ASC/ASCQ:  Invalid Command Operation Code
 
 sd1(umass0:1:1): scsipi_interpret_sense returned 22
 sd1(umass0:1:1): scsipi_free_xs
 sd1(umass0:1:1): calling private start()
 sd1(umass0:1:1): sdstart sd1: dos partition I/O error
 sd1(umass0:1:1): Disklabel loaded sd1(umass0:1:1): open complete
 sd1(umass0:1:1): sdstrategy sd1(umass0:1:1): 512 bytes @ blk 0
 sd1(umass0:1:1): sdstart sd1(umass0:1:1): scsi_scsipi_cmd
 sd1(umass0:1:1): scsipi_get_xs
 sd1(umass0:1:1): calling pool_get
 sd1(umass0:1:1): returning
 scsipi_exec_cmd: xs(0xc0f84000): xs_control(0x00000809)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0xea60)cmd(0xc0f84084)len(0x6)data(0xe3459620)len(0x200)res(0x200)err(0x0)bp(0xc0e52000)sd1(umass0:1:1): command: 0x8,0x20,0x0,0x0,0x1,0x0-[512 bytes]
 ------------------------------
 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 032: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 048: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 ------------------------------
 
 umass0: umass_scsi_cmd:  1:1 xs=0xc0f84000 cmd=0x08 (quirks=0x100e, poll=0)
 xs(0xc0f84000): xs_control(0x00000809)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0xea60)cmd(0xc0f84084)len(0x6)data(0xe3459620)len(0x200)res(0x200)err(0x0)bp(0xc0e52000)sd1(umass0:1:1): command: 0x8,0x20,0x0,0x0,0x1,0x0-[512 bytes]
 ------------------------------
 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 032: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 048: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 ------------------------------
 umass_scsi_cmd: async dir=1, cmdlen=6 datalen=512
 umass0: umass_bbb_transfer cmd=0x08
 umass0: CBW 249: cmd = 6b (0x082000000100), data = 512 bytes, dir = in
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: start xfer buffer=0xe3f4c000 buflen=512 flags=0x5 timeout=10403
 umass0: Handling BBB state 2 (BBB Data), xfer=0xc0f54f00, STALLED
 umass0: Data-in 512b failed, STALLED
 umass0: Clear endpoint 0x82 stall
 umass0: Handling BBB state 3 (BBB Data bulk-in/-out clear stall), xfer=0xc0ebb900, NORMAL_COMPLETION
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 249: sig = 0x53425355 (valid), tag = 249, res = 512, status = 0x01 (failed)
 umass0: Command Failed, res = 512
 umass_scsipi_cb: xs=0xc0f84000 residue=512 status=2
 umass0: umass_bbb_transfer cmd=0x03
 umass0: CBW 250: cmd = 6b (0x032000002000), data = 32 bytes, dir = in
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: start xfer buffer=0xe3f4c000 buflen=32 flags=0x5 timeout=10403
 umass0: Handling BBB state 2 (BBB Data), xfer=0xc0f54f00, NORMAL_COMPLETION
 umass0: 0x 700005000000000c0000000020000000 buffer=0xc0f8405c, buflen=32
 umass0: 0x 00000000000000000000000000000000
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 250: sig = 0x53425355 (valid), tag = 250, res = 12, status = 0x00 (good)
 umass_scsipi_sense_cb: xs=0xc0f84000 residue=12 status=0
 umass_scsipi_sense_cb: return xs->error=2, xs->xs_status=0x1 xs->resid=512
 sd1(umass0:1:1): scsipi_done
 sd1(umass0:1:1): command: 0x8,0x20,0x0,0x0,0x1,0x0-[512 bytes]
 ------------------------------
 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 032: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 048: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 ------------------------------
 sd1(umass0:1:1): sc_err1,err = 0x2 
 code 0x70 valid 0x0 seg 0x0 key 0x5 ili 0x0 eom 0x0 fmark 0x0
 info: 0x0 0x0 0x0 0x0 followed by 12 extra bytes
 extra: 0x0 0x0 0x0 0x0 0x20 0x0 0x0 0x0 0x0 0x0 0x0 0x0 
 sd1(umass0:1:1): calling private err_handler()
 sd1(umass0:1:1):  Check Condition on CDB: 0x08 20 00 00 01 00
     SENSE KEY:  Illegal Request
      ASC/ASCQ:  Invalid Command Operation Code
 
 sd1(umass0:1:1): scsipi_interpret_sense returned 22
 sd1(umass0:1:1): scsipi_free_xs
 sd1(umass0:1:1): calling private start()
 sd1(umass0:1:1): sdstart sd1(umass0:1:1): sdioctl 0x41946465 sd1(umass0:1:1): scsi_scsipi_cmd
 sd1(umass0:1:1): scsipi_get_xs
 sd1(umass0:1:1): calling pool_get
 sd1(umass0:1:1): returning
 scsipi_exec_cmd: xs(0xc0f84000): xs_control(0x00000140)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0x1388)cmd(0xc0f84084)len(0x6)data(0x0)len(0x0)res(0x0)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1e,0x20,0x0,0x0,0x0,0x0-[0 bytes]
 
 umass0: umass_scsi_cmd:  1:1 xs=0xc0f84000 cmd=0x1e (quirks=0x100e, poll=0)
 xs(0xc0f84000): xs_control(0x00000140)xs_status(0x00000000)sc_link(0xc0fa4280)retr(0x4)timo(0x1388)cmd(0xc0f84084)len(0x6)data(0x0)len(0x0)res(0x0)err(0x0)bp(0x0)sd1(umass0:1:1): command: 0x1e,0x20,0x0,0x0,0x0,0x0-[0 bytes]
 umass_scsi_cmd: async dir=0, cmdlen=6 datalen=0
 umass0: umass_bbb_transfer cmd=0x1e
 umass0: CBW 251: cmd = 6b (0x1e2000000000), data = 0 bytes, dir = out
 umass0: start xfer buffer=0xc0fda05c buflen=31 flags=0x0 timeout=10403
 umass0: Handling BBB state 1 (BBB CBW), xfer=0xc0ebb100, NORMAL_COMPLETION
 umass0: no data phase
 umass0: start xfer buffer=0xc0fda07b buflen=13 flags=0x0 timeout=10403
 umass0: Handling BBB state 4 (BBB CSW, 1st attempt), xfer=0xc0f54500, NORMAL_COMPLETION
 umass0: CSW 251: sig = 0x53425355 (valid), tag = 251, res = 0, status = 0x00 (good)
 umass_scsipi_cb: xs=0xc0f84000 residue=0 status=0
 umass_scsipi_cb: return xs->error=0, xs->xs_status=0x1 xs->resid=0
 sd1(umass0:1:1): scsipi_done
 sd1(umass0:1:1): command: 0x1e,0x20,0x0,0x0,0x0,0x0-[0 bytes]
 sd1(umass0:1:1): back in cmd()
 sd1(umass0:1:1): sc_err1,err = 0x0 
 sd1(umass0:1:1): scsipi_free_xs
 sd1(umass0:1:1): calling private start()
 sd1(umass0:1:1): sdstart 

--CE+1k2dSO48ffgeK--