#638 sbp2 with firewire/usb2 case locks up. Kernel 2.6.8-rc2-mm2

[Anonymous]

Hi,

I bought a BYTECC USB 2.0/IEEE1394 case to use with a
120gb WD hard drive. I'm running a debian system with
the current kernel being 2.6.8-rc2-mm2, pretty bleeding
edge. I can be reached at stoffel@lucent.com if you
need more details.

I can fsck and mount an ext3 filesystem on the device,
and I can even start to write data to it, but it then
locks up completely and just puts all kinds of errors
in the logs. Eventually it times out and the
filesystem goes away, the /proc/partitions entry goes
away and the external enclosure needs to be power
cycled to reset the device. Using gscanbus doesn't
help at all.

Here's a sample from the /var/log/messages file, sorry
for the length:

Aug 3 23:01:00 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:00 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:10 jfsnew kernel: Test Unit Ready 00 00 00
00 00
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=3,
tcode=0x0, speed=2
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=4,
tcode=0x1, speed=2
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x0 tLabel=0x03 ack=0x11
spd=2 data=0x0F000000 ctx=0
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x1 tLabel=0x04 ack=0x11
spd=2 dataLength=8 ctx=0
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:10 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:20 jfsnew kernel: Test Unit Ready 00 00 00
00 00
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=5,
tcode=0x0, speed=2
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=6,
tcode=0x1, speed=2
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x0 tLabel=0x05 ack=0x11
spd=2 data=0x0F000000 ctx=0
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x1 tLabel=0x06 ack=0x11
spd=2 dataLength=8 ctx=0
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:20 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:30 jfsnew kernel: Test Unit Ready 00 00 00
00 00
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=7,
tcode=0x0, speed=2
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=8,
tcode=0x1, speed=2
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x0 tLabel=0x07 ack=0x11
spd=2 data=0x0F000000 ctx=0
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x1 tLabel=0x08 ack=0x11
spd=2 dataLength=8 ctx=0
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:30 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:40 jfsnew kernel: Test Unit Ready 00 00 00
00 00
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=9,
tcode=0x0, speed=2
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=10,
tcode=0x1, speed=2
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x0 tLabel=0x09 ack=0x11
spd=2 data=0x0F000000 ctx=0
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x1 tLabel=0x0A ack=0x11
spd=2 dataLength=8 ctx=0
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:40 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:50 jfsnew kernel: Test Unit Ready 00 00 00
00 00
Aug 3 23:01:50 jfsnew kernel: ohci1394: fw-host0:
Inserting packet for node 0-00:1023, tlabel=11,
tcode=0x0, speed=2
Aug 3 23:01:50 jfsnew kernel: ohci1394: fw-host0:
Waking transmit DMA ctx=0
Aug 3 23:01:50 jfsnew kernel: scsi: Device offlined -
not ready after error recovery: host 5 channel 0 id 0 lun 0
Aug 3 23:01:50 jfsnew kernel: scsi: Device offlined -
not ready after error recovery: host 5 channel 0 id 0 lun 0
Aug 3 23:01:50 jfsnew kernel: ohci1394: fw-host0:
IntEvent: 00000001
Aug 3 23:01:50 jfsnew kernel: ohci1394: fw-host0: Got
reqTxComplete interrupt status=0x00008051
Aug 3 23:01:50 jfsnew kernel: scsi: Device offlined -
not ready after error recovery: host 5 channel 0 id 0 lun 0
Aug 3 23:01:50 jfsnew last message repeated 5 times
Aug 3 23:01:50 jfsnew kernel: ohci1394: fw-host0:
Packet sent to node 0 tcode=0x0 tLabel=0x0B ack=0x11
spd=2 data=0x0F000000 ctx=0
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186279936
Aug 3 23:01:50 jfsnew kernel: lost page write due to
I/O error on sdc2
Aug 3 23:01:50 jfsnew last message repeated 9 times
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186279944
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186280192
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186280440
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186280688
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186280936
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186281184
Aug 3 23:01:50 jfsnew kernel: SCSI error : <5 0 0 0>
return code = 0x50000
Aug 3 23:01:50 jfsnew kernel: end_request: I/O error,
dev sdc, sector 186281432
Aug 3 23:01:51 jfsnew kernel:
__journal_remove_journal_head: freeing b_frozen_data
Aug 3 23:01:51 jfsnew kernel:
__journal_remove_journal_head: freeing b_frozen_data
Aug 3 23:01:51 jfsnew kernel:
__journal_remove_journal_head: freeing b_committed_data
Aug 3 23:01:51 jfsnew kernel:
__journal_remove_journal_head: freeing b_frozen_data
Aug 3 23:01:51 jfsnew kernel:
__journal_remove_journal_head: freeing b_frozen_data
Aug 3 23:01:52 jfsnew kernel:
Aug 3 23:01:52 jfsnew last message repeated 3 times

But first let me give you some configuration information:

Kernel config:
# IEEE 1394 (FireWire) support
CONFIG_IEEE1394=m
CONFIG_IEEE1394_VERBOSEDEBUG=y
CONFIG_IEEE1394_OUI_DB=y
CONFIG_IEEE1394_EXTRA_CONFIG_ROMS=y
# CONFIG_IEEE1394_CONFIG_ROM_IP1394 is not set
# CONFIG_IEEE1394_PCILYNX is not set
CONFIG_IEEE1394_OHCI1394=m
CONFIG_IEEE1394_VIDEO1394=m
CONFIG_IEEE1394_SBP2=m
# CONFIG_IEEE1394_SBP2_PHYS_DMA is not set
# CONFIG_IEEE1394_ETH1394 is not set
CONFIG_IEEE1394_DV1394=m
CONFIG_IEEE1394_RAWIO=m
# CONFIG_IEEE1394_CMP is not set

I'm using an adaptec dual USB/Firewire card. Here's
the output of lspci -v for the entire device, USB and all:
0000:03:08.0 USB Controller: NEC Corporation USB (rev
41) (prog-if 10 [OHCI])
Subsystem: Adaptec: Unknown device 0235
Flags: bus master, medium devsel, latency 64,
IRQ 18
Memory at fafff000 (32-bit, non-prefetchable)
[size=4K]
Capabilities: <available only to root>

0000:03:08.1 USB Controller: NEC Corporation USB (rev
41) (prog-if 10 [OHCI])
Subsystem: Adaptec: Unknown device 0235
Flags: bus master, medium devsel, latency 64,
IRQ 19
Memory at faffe000 (32-bit, non-prefetchable)
[size=4K]
Capabilities: <available only to root>

0000:03:08.2 USB Controller: NEC Corporation USB 2.0
(rev 02) (prog-if 20 [EHCI])
Subsystem: Adaptec: Unknown device 02e0
Flags: bus master, medium devsel, latency 64,
IRQ 16
Memory at faffdc00 (32-bit, non-prefetchable)
[size=256]
Capabilities: <available only to root>

0000:03:0b.0 FireWire (IEEE 1394): Texas Instruments
TSB12LV26 IEEE-1394 Controller (Link) (prog-if 10 [OHCI])
Subsystem: Texas Instruments: Unknown device 8010
Flags: bus master, medium devsel, latency 64,
IRQ 17
Memory at faffd000 (32-bit, non-prefetchable)
[size=2K]
Memory at faff8000 (32-bit, non-prefetchable)
[size=16K]
Capabilities: <available only to root>

Here's the detailed output from gscanbus for both the
controller, and the single device I have attached to
the bus:
SelfID Info
-----------
Physical ID: 1
Link active: Yes
Gap Count: 63
PHY Speed: S400
PHY Delay: <=144ns
IRM Capable: Yes
Power Class: +15W
Port 0: Not connected
Port 1: Connected to child node
Port 2: Not connected
Init. reset: Yes

CSR ROM Info
------------
GUID: 0x005042B500016243
Node Capabilities: 0x000083C0
Vendor ID: 0x00005042
Unit Spec ID: 0x00000000
Unit SW Version: 0x00000000
Model ID: 0x00000000
Nr. Textual Leafes: 1

Vendor: SCI MANUFACTURING
Textual Leafes:
Linux - ohci1394

AV/C Subunits
-------------
N/A

# Storage device gscanbus info here.

SelfID Info
-----------
Physical ID: 0
Link active: Yes
Gap Count: 63
PHY Speed: S400
PHY Delay: <=144ns
IRM Capable: No
Power Class: -10W
Port 0: Connected to parent node
Port 1: Not connected
Init. reset: No

CSR ROM Info
------------
GUID: 0x0050770E300033B6
Node Capabilities: 0x000083C0
Vendor ID: 0x00005077
Unit Spec ID: 0x0000609E
Unit SW Version: 0x00010483
Model ID: 0x00000001
Nr. Textual Leafes: 1

Vendor: PROLIFIC TECHNOLOGY, INC.
Textual Leafes:
Prolific PL3507 Combo Device

AV/C Subunits
-------------
N/A

Unfortunately, there is no info in /proc/bus/ieee1394
at all, that entry isn't even created for some reason.
I need to research this some more.

Please let me know if there's any other information I
can provide here to get this working properly. Next,
it's back to testing under USB2.0 as well, though that
too locked up at times.

Sigh...

John
stoffel@lucent.com