Issues using an external IDE<->IEEE1394 combo

Hi folks,

(I've reported some former testing with such device on linux-laptop ML)

system: Dell Inspiron 8200, SuSE 8.1 base
kernel: SuSE 8.1's 2.4.19-4GB or vanilla 2.4.22
ieee1394 version: the one that comes with the kernel?
libraw version: `rpm -q libraw1394` -> libraw1394-0.9.0-181
driver: OHCI/SBP2
system logs and /proc output: attached and below
`lspci -vv`:
02:01.2 FireWire (IEEE 1394): Texas Instruments PCI4451 IEEE-1394 Controller (prog-if 10 [OHCI])
        Subsystem: Dell Computer Corporation: Unknown device 00d4
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr- Stepping- SERR+ FastB2B-
        Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
        Latency: 32 (500ns min, 1000ns max), cache line size 08
        Interrupt: pin A routed to IRQ 11
        Region 0: Memory at f8fff000 (32-bit, non-prefetchable) [size=2K]
        Region 1: Memory at f8ff8000 (32-bit, non-prefetchable) [size=16K]
        Capabilities: [44] Power Management version 2
                Flags: PMEClk- DSI- D1- D2+ AuxCurrent=0mA PME(D0-,D1-,D2+,D3hot+,D3cold-)
                Status: D0 PME-Enable- DSel=0 DScale=0 PME-
external hardware:
        combo/ ConStar ST-2312C(Combo) IDE->USB2/IEEE1394 (full description of the combo is attached)
        hdd/ Hitachi Deskstar 123.5GB (IC35L120AVV207-1)
pcmcia_cs: 3.2.5 (dunno if it's important, since my ieee1394 plug is not a pcmcia card)

I load ieee1394, ohci1394 and sbp2 modules at startup (Linux 2.4.19-4GB,
original SuSE kernel, and vanilla 2.4.22). Once init 3 is reached, I plug in
the firewire disk, turn it on. It is automatically recognized or I have to
rescan-scsi-bus.sh (okay I have to modify my hotplug config to do that
automatically), then I can see partitions in /proc/partitions, and can mount
them.

I've made some tests: copying a large amount of data to the 1st
partition (/dev/sda1) or re-formatting it. The process is fast and
seems OK for a 1 one 2 minutes, then the CPU consumption is very high
and the tranfert rate/format process becomes very low.

Nothing special in /var/log/message for the moment, and after a while
it shows I/O errors, and the disk is no longer accessible.
The partitions are still visible, but no tool can access the disk. For
intance, dumpe2fs /dev/sda1 says:
dumpe2fs: No such device or address while trying to open /dev/sda1
Couldn't find valid filesystem superblock.

No way to re-enable it, even shutting down both machine and hdd for a
few seconds, rescanning scsi bus, un-plug/re-plug..

I've thought about this possible issues:
- problems in the ieee1394 drivers
- firewire cable not OK
- external combo or hdd not OK (overheat?)

Here is a sample of activity, when I did another test the day after:

[startup process (can skip)]

Sep 23 10:21:03 tethys syslogd 1.4.1: restart.
Sep 23 10:21:04 tethys /etc/hotplug/usb.rc[363]: loaded HCD: usb-uhci
Sep 23 10:21:08 tethys insmod: Using /lib/modules/2.4.19-4GB/kernel/drivers/input/mousedev.o
Sep 23 10:21:08 tethys insmod: Symbol version prefix ''
Sep 23 10:21:08 tethys insmod: Using /lib/modules/2.4.19-4GB/kernel/drivers/usb/hid.o
Sep 23 10:21:08 tethys insmod: Symbol version prefix ''
Sep 23 10:21:08 tethys kernel: klogd 1.4.1, log source = /proc/kmsg started.
Sep 23 10:21:08 tethys kernel: Inspecting /boot/System.map-2.4.19-4GB
Sep 23 10:21:08 tethys kernel: Loaded 14329 symbols from /boot/System.map-2.4.19-4GB.
Sep 23 10:21:08 tethys kernel: Symbols match kernel version 2.4.19.
Sep 23 10:21:08 tethys kernel: Loaded 395 symbols from 17 modules.
Sep 23 10:21:08 tethys kernel: Linux Kernel Card Services 3.1.22
Sep 23 10:21:08 tethys kernel: options: [pci] [cardbus] [pm]
Sep 23 10:21:08 tethys kernel: isapnp: Scanning for PnP cards...
Sep 23 10:21:08 tethys kernel: isapnp: No Plug & Play device found
Sep 23 10:21:08 tethys kernel: Intel PCIC probe: not found.
Sep 23 10:21:08 tethys kernel: PCI: Enabling device 02:01.0 (0000 -> 0002)
Sep 23 10:21:08 tethys kernel: PCI: Enabling device 02:01.1 (0000 -> 0002)
Sep 23 10:21:08 tethys kernel: Yenta IRQ list 04b8, PCI irq11
Sep 23 10:21:08 tethys kernel: Socket status: 30000006
Sep 23 10:21:08 tethys kernel: Yenta IRQ list 04b8, PCI irq11
Sep 23 10:21:08 tethys kernel: Socket status: 30000006
Sep 23 10:21:08 tethys kernel: cs: IO port probe 0x0c00-0x0cff: clean.
Sep 23 10:21:08 tethys kernel: cs: IO port probe 0x0820-0x08ff: excluding 0x828-0x837 0x840-0x84f 0x860-0x877 0x880-0x88f 0x898-0x89f 0x8a8-0x8cf 0x8e0-0x8ff
Sep 23 10:21:08 tethys kernel: cs: IO port probe 0x0800-0x080f: excluding 0x800-0x80f
Sep 23 10:21:08 tethys kernel: cs: IO port probe 0x0100-0x04ff: excluding 0x170-0x177 0x280-0x287 0x370-0x37f 0x4d0-0x4d7
Sep 23 10:21:08 tethys kernel: cs: IO port probe 0x0a00-0x0aff: clean.
Sep 23 10:21:08 tethys kernel: 3c59x: Donald Becker and others. www.scyld.com/network/vortex.html
Sep 23 10:21:08 tethys kernel: 02:00.0: 3Com PCI 3c905C Tornado at 0xec80. Vers LK1.1.16
Sep 23 10:21:08 tethys kernel: usb.c: registered new driver usbdevfs
Sep 23 10:21:08 tethys kernel: usb.c: registered new driver hub
Sep 23 10:21:08 tethys kernel: usb-uhci.c: $Revision: 1.275 $ time 13:53:01 Sep 13 2002
Sep 23 10:21:08 tethys kernel: usb-uhci.c: High bandwidth mode enabled
Sep 23 10:21:08 tethys kernel: PCI: Setting latency timer of device 00:1d.0 to 64
Sep 23 10:21:08 tethys kernel: usb-uhci.c: USB UHCI at I/O 0xbf80, IRQ 11
Sep 23 10:21:08 tethys kernel: usb-uhci.c: Detected 2 ports
Sep 23 10:21:08 tethys kernel: usb.c: new USB bus registered, assigned bus number 1
Sep 23 10:21:08 tethys kernel: hub.c: USB hub found
Sep 23 10:21:08 tethys kernel: hub.c: 2 ports detected
Sep 23 10:21:08 tethys kernel: PCI: Setting latency timer of device 00:1d.2 to 64
Sep 23 10:21:08 tethys kernel: usb-uhci.c: USB UHCI at I/O 0xbf20, IRQ 11
Sep 23 10:21:08 tethys kernel: usb-uhci.c: Detected 2 ports
Sep 23 10:21:08 tethys kernel: usb.c: new USB bus registered, assigned bus number 2
Sep 23 10:21:08 tethys kernel: hub.c: USB hub found
Sep 23 10:21:08 tethys kernel: hub.c: 2 ports detected
Sep 23 10:21:08 tethys kernel: usb-uhci.c: v1.275:USB Universal Host Controller Interface driver
Sep 23 10:21:08 tethys kernel: uhci.c: USB Universal Host Controller Interface driver v1.1
Sep 23 10:21:08 tethys kernel: hub.c: USB new device connect on bus2/1, assigned device number 2
Sep 23 10:21:08 tethys kernel: usb.c: USB device 2 (vend/prod 0x45e/0x25) is not claimed by any active driver.
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: initializing sg_major_array ...<4>sg: allocated major 21
Sep 23 10:21:08 tethys kernel: sg: ... found 15:00
Sep 23 10:21:08 tethys kernel: sg_attach: dev0=(21:0)
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:01
Sep 23 10:21:08 tethys kernel: sg_attach: dev1=(21:1)
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:02
Sep 23 10:21:08 tethys kernel: sg_attach: dev2=(21:2)
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:03
Sep 23 10:21:08 tethys kernel: sg_attach: dev3=(21:3)
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:04
Sep 23 10:21:08 tethys kernel: sg_attach: dev4=(21:4)
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:05
Sep 23 10:21:08 tethys kernel: sg_attach: dev5=(21:5)
Sep 23 10:21:08 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:06
Sep 23 10:21:08 tethys kernel: sg_attach: dev6=(21:6)
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr0 at scsi0, channel 0, id 0, lun 0
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr1 at scsi0, channel 0, id 0, lun 1
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr2 at scsi0, channel 0, id 0, lun 2
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr3 at scsi0, channel 0, id 0, lun 3
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr4 at scsi0, channel 0, id 0, lun 4
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr5 at scsi0, channel 0, id 0, lun 5
Sep 23 10:21:08 tethys kernel: Attached scsi CD-ROM sr6 at scsi0, channel 0, id 0, lun 6
Sep 23 10:21:08 tethys kernel: sr0: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: Uniform CD-ROM driver Revision: 3.12
Sep 23 10:21:08 tethys kernel: sr1: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: sr2: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: sr3: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: sr4: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: sr5: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: sr6: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Sep 23 10:21:08 tethys kernel: mice: PS/2 mouse device common for all mice
Sep 23 10:21:08 tethys kernel: usb.c: registered new driver hiddev
Sep 23 10:21:08 tethys kernel: usb.c: registered new driver hid
Sep 23 10:21:08 tethys kernel: usb-uhci.c: interrupt, status 3, frame# 1951
Sep 23 10:21:08 tethys kernel: input0: USB HID v1.00 Mouse [Microsoft Microsoft IntelliMouse ® with IntelliEye] on usb2:2.0
Sep 23 10:21:08 tethys kernel: hid-core.c: v1.8.1 Andreas Gal, Vojtech Pavlik <vojtech@suse.cz>
Sep 23 10:21:08 tethys kernel: hid-core.c: USB HID support drivers
Sep 23 10:21:11 tethys kernel: funned uses obsolete (PF_INET,SOCK_PACKET)
Sep 23 10:21:14 tethys kernel: IPv6 v0.8 for NET4.0
Sep 23 10:21:14 tethys kernel: IPv6 over IPv4 tunneling driver
Sep 23 10:21:15 tethys sshd[629]: Server listening on :: port 22.
Sep 23 10:21:15 tethys sshd[629]: error: Bind to port 22 on 0.0.0.0 failed: Address already in use.
Sep 23 10:21:23 tethys /etc/hotplug/net.agent[647]: No HW description found ... exiting
Sep 23 10:21:25 tethys kernel: eth0: no IPv6 routers present
Sep 23 10:21:26 tethys kernel: ACPI: AC Adapter [AC] (on-line)
Sep 23 10:21:26 tethys kernel: ACPI: Battery Slot [BAT0] (battery present)
Sep 23 10:21:26 tethys kernel: ACPI: Battery Slot [BAT1] (battery present)
Sep 23 10:21:26 tethys kernel: ACPI: Lid Switch [LID]
Sep 23 10:21:26 tethys kernel: ACPI: Power Button (CM) [PBTN]
Sep 23 10:21:26 tethys kernel: ACPI: Sleep Button (CM) [SBTN]
Sep 23 10:21:26 tethys kernel: ACPI: Processor [CPU0] (supports C1 C2, 2 performance states, 8 throttling states)
Sep 23 10:21:26 tethys kernel: ACPI: Thermal Zone [THM] (35 C)
Sep 23 10:21:28 tethys kernel: PCI: Setting latency timer of device 00:1f.5 to 64
Sep 23 10:21:29 tethys kernel: intel8x0: clocking to 48000
Sep 23 10:21:29 tethys modprobe: modprobe: Can't locate module snd-card-1
Sep 23 10:21:29 tethys modprobe: modprobe: Can't locate module snd-card-1
Sep 23 10:21:29 tethys modprobe: modprobe: Can't locate module snd-card-2
Sep 23 10:21:29 tethys modprobe: modprobe: Can't locate module snd-card-2
Sep 23 10:21:29 tethys modprobe: modprobe: Can't locate module snd-card-3
Sep 23 10:21:29 tethys modprobe: modprobe: Can't locate module snd-card-3
Sep 23 10:21:30 tethys in.identd[731]: started
Sep 23 10:21:41 tethys kernel: parport0: PC-style at 0x378 (0x778) [PCSPP,TRISTATE]
Sep 23 10:21:41 tethys kernel: parport0: irq 7 detected
Sep 23 10:21:41 tethys kernel: lp0: using parport0 (polling).
Sep 23 10:21:42 tethys kernel: usb.c: registered new driver serial
Sep 23 10:21:42 tethys kernel: usbserial.c: USB Serial support registered for Generic
Sep 23 10:21:42 tethys kernel: usbserial.c: USB Serial Driver core v1.4
Sep 23 10:21:42 tethys smpppd[934]: smpppd version 0.78 started
Sep 23 10:21:42 tethys ntpdate[967]: step time server 10.0.0.5 offset -1.533546 sec
Sep 23 10:21:42 tethys ntpd[978]: ntpd 4.1.1@1.786 Mon Sep 9 20:57:30 UTC 2002 (1)
Sep 23 10:21:42 tethys ntpd[978]: signal_no_reset: signal 13 had flags 4000000
Sep 23 10:21:43 tethys ntpd[978]: precision = 15 usec
Sep 23 10:21:43 tethys ntpd[978]: kernel time discipline status 0040
Sep 23 10:21:45 tethys /usr/sbin/cron[1058]: (CRON) STARTUP (fork ok)
Sep 23 10:21:51 tethys kernel: Linux video capture interface: v1.00
Sep 23 10:21:52 tethys kernel: ohci1394: $Rev: 530 $ Ben Collins <bcollins@debian.org>
Sep 23 10:21:52 tethys kernel: ohci1394_0: OHCI-1394 1.0 (PCI): IRQ=[11] MMIO=[f8fff000-f8fff800] Max Packet=[2048]
Sep 23 10:21:52 tethys kernel: ieee1394: Host added: Node[00:1023] GUID[364fc00034f7c810] [Linux OHCI-1394]
Sep 23 10:21:52 tethys kernel: scsi1 : IEEE-1394 SBP-2 protocol driver (host: ohci1394)
Sep 23 10:21:52 tethys kernel: $Rev: 530 $ James Goodwin <jamesg@filanet.com>
Sep 23 10:21:52 tethys kernel: SBP-2 module load options:
Sep 23 10:21:52 tethys kernel: - Max speed supported: S400
Sep 23 10:21:52 tethys kernel: - Max sectors per I/O supported: 255
Sep 23 10:21:52 tethys kernel: - Max outstanding commands supported: 8
Sep 23 10:21:52 tethys kernel: - Max outstanding commands per lun supported: 1
Sep 23 10:21:52 tethys kernel: - Serialized I/O (debug): no
Sep 23 10:21:52 tethys kernel: - Exclusive login: yes
Sep 23 10:21:59 tethys root: spamd starting
Sep 23 10:23:48 tethys PAM-warn[1097]: function=[pam_sm_authenticate] service=[gdm] terminal=[:0] user=[wwp] ruser=[gdm] rhost=[localhost]
Sep 23 10:23:50 tethys PAM-warn[1097]: function=[pam_sm_acct_mgmt] service=[gdm] terminal=[:0] user=[wwp] ruser=[gdm] rhost=[localhost]
Sep 23 10:23:50 tethys PAM-warn[1097]: function=[pam_sm_setcred] service=[gdm] terminal=[:0] user=[wwp] ruser=[gdm] rhost=[localhost]
Sep 23 10:23:50 tethys PAM-warn[1097]: function=[pam_sm_open_session] service=[gdm] terminal=[:0] user=[wwp] ruser=[gdm] rhost=[localhost]
Sep 23 10:23:50 tethys gdm-binary[1097]: pam_unix2: session started for user wwp, service gdm
Sep 23 10:23:50 tethys gdm[1097]: gdm_auth_user_add: /home/wwp/.Xauthority is not owned by uid 500.
Sep 23 10:23:56 tethys kernel: CSLIP: code copyright 1989 Regents of the University of California
Sep 23 10:23:56 tethys kernel: PPP generic driver version 2.4.2
Sep 23 10:23:58 tethys insmod: insmod: a module named snd-pcm-oss already exists
Sep 23 10:23:58 tethys insmod: insmod: insmod sound-service-0-3 failed
Sep 23 10:23:59 tethys gconfd (wwp-1203): starting (version 1.2.1), pid 1203 user 'wwp'
Sep 23 10:24:00 tethys gconfd (wwp-1203): Resolved address "xml:readonly:/etc/opt/gnome/gconf/gconf.xml.mandatory" to a read-only config source at position 0
Sep 23 10:24:00 tethys gconfd (wwp-1203): Resolved address "xml:readonly:/etc/opt/gnome/gconf/preconf/gconf.xml.defaults" to a read-only config source at position 1
Sep 23 10:24:00 tethys gconfd (wwp-1203): Resolved address "xml:readwrite:/home/wwp/.gconf" to a writable config source at position 2
Sep 23 10:24:00 tethys modprobe: modprobe: Can't locate module sound-slot-1
Sep 23 10:24:00 tethys modprobe: modprobe: Can't locate module sound-service-1-0
Sep 23 10:26:00 tethys gconfd (wwp-1203): GConf server is not in use, shutting down.
Sep 23 10:26:00 tethys gconfd (wwp-1203): Exiting
Sep 23 10:26:24 tethys su: (to root) wwp on /dev/pts/1
Sep 23 10:26:24 tethys su: pam_unix2: session started for user root, service su
Sep 23 10:26:29 tethys su: (to root) wwp on /dev/pts/0
Sep 23 10:26:29 tethys su: pam_unix2: session started for user root, service su

[plugged in the external drive]

Sep 23 10:27:15 tethys kernel: ohci1394_0: SelfID received outside of bus reset sequence
Sep 23 10:27:16 tethys kernel: ieee1394: Node 01:1023 has non-standard ROM format (0 quads), cannot parse
Sep 23 10:27:32 tethys kernel: ieee1394: sbp2: Logged into SBP-2 device
Sep 23 10:27:32 tethys kernel: ieee1394: sbp2: Node[01:1023]: Max speed [S400] - Max payload [2048]
Sep 23 10:27:32 tethys kernel: ieee1394: Device added: Node[01:1023] GUID[0030e0f4e0101cf0] [Oxford Semiconductor Ltd. ]

[rescan-scsi-bus.sh]

Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 1 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 2 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 3 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 4 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 5 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 6 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 0 0 7 0
Sep 23 10:28:04 tethys kernel: scsi singledevice 1 0 0 0
Sep 23 10:28:07 tethys kernel: Vendor: IC35L120 Model: AVV207-1 Rev:
Sep 23 10:28:07 tethys kernel: Type: Direct-Access ANSI SCSI revision: 06
Sep 23 10:28:07 tethys kernel: sd_init()
Sep 23 10:28:07 tethys kernel: sd: allocated major 8
Sep 23 10:28:07 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:07
Sep 23 10:28:07 tethys kernel: sg_attach: dev7=(21:7)
Sep 23 10:28:07 tethys kernel: sd_attach()
Sep 23 10:28:07 tethys kernel: sd: find_free_slot ...<7>sd: ... found 08:00
Sep 23 10:28:07 tethys kernel: Attached scsi disk sda at scsi1, channel 0, id 0, lun 0
Sep 23 10:28:07 tethys kernel: sd_finish()
Sep 23 10:28:07 tethys kernel: sd_init_onedisk (0,0), sda 08:00
Sep 23 10:28:07 tethys kernel: SCSI device sda: 241254720 512-byte hdwr sectors (123522 MB)
Sep 23 10:28:07 tethys kernel: sda: sda1 sda2
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 1 0
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 2 0
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 3 0
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 4 0
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 5 0
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 6 0
Sep 23 10:28:07 tethys kernel: scsi singledevice 1 0 7 0

[formatting /dev/sda1]

Sep 23 10:30:14 tethys syslogd 1.4.1: restart.
Sep 23 10:30:41 tethys kernel: md: Autodetecting RAID arrays.
Sep 23 10:30:41 tethys kernel: md: autorun ...
Sep 23 10:30:41 tethys kernel: md: ... autorun DONE.
Sep 23 10:30:41 tethys kernel: klogd 1.4.1, ---------- state change ----------
Sep 23 10:30:41 tethys kernel: Inspecting /boot/System.map-2.4.19-4GB
Sep 23 10:30:41 tethys kernel: Loaded 14329 symbols from /boot/System.map-2.4.19-4GB.
Sep 23 10:30:41 tethys kernel: Symbols match kernel version 2.4.19.
Sep 23 10:30:41 tethys kernel: Loaded 1167 symbols from 50 modules.
Sep 23 10:30:41 tethys kernel: LVM version 1.0.5(mp-v6)(15/07/2002) module loaded
Sep 23 10:50:27 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 10:50:27 tethys kernel: 0x2a 00 0b 80 2e 49 00 00 fe 00
Sep 23 10:50:37 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 10:50:37 tethys kernel: 0x00 00 00 00 00 00
Sep 23 10:50:37 tethys kernel: ieee1394: sbp2: reset requested
Sep 23 10:50:37 tethys kernel: ieee1394: sbp2: Generating sbp2 fetch agent reset
Sep 23 10:50:47 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 10:50:47 tethys kernel: 0x00 00 00 00 00 00
Sep 23 10:50:47 tethys kernel: ieee1394: sbp2: reset requested
Sep 23 10:50:47 tethys kernel: ieee1394: sbp2: Generating sbp2 fetch agent reset
Sep 23 10:51:02 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 10:51:02 tethys kernel: 0x00 00 00 00 00 00
Sep 23 10:51:02 tethys kernel: scsi: device set offline - not ready or command retry failed after bus reset: host 1 channel 0 id 0 lun 0
Sep 23 10:51:02 tethys kernel: SCSI disk error : host 1 channel 0 id 0 lun 0 return code = 50000
Sep 23 10:51:02 tethys kernel: I/O error: dev 08:02, sector 67112688
Sep 23 10:51:02 tethys kernel: I/O error: dev 08:02, sector 67112690
..
Sep 23 10:51:02 tethys kernel: I/O error: dev 08:02, sector 68157456
Sep 23 10:51:02 tethys kernel: 756
Sep 23 10:51:02 tethys kernel: I/O error: dev 08:02, sector 74977010
..
Sep 23 10:51:03 tethys kernel: I/O error: dev 08:02, sector 82052358
Sep 23 10:51:03 tethys kernel: 770
Sep 23 10:51:03 tethys kernel: I/O error: dev 08:02, sector 85463024
..
Sep 23 10:51:03 tethys kernel: I/O error: dev 08:02, sector 85721104
..
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 95683084
Sep 23 10:51:04 tethys kernel: dev 08:02, sector 99616260
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 99616514
..
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 99616768
..
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 106171384
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 56
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 106171628
..
Sep 23 10:51:04 tethys kernel: I/O error: dev 08:02, sector 106171882
..
Sep 23 10:51:05 tethys kernel: I/O error: dev 08:02, sector 115347186
Sep 23 10:51:05 tethys kernel: I/O error: dev 08:02, sector 115347440

[if ever I unplug or turn off the external drive]

Sep 23 11:21:05 tethys kernel: ieee1394: Device removed: Node[01:1023] GUID[0030e0f4e0101cf0] [Oxford Semiconductor Ltd. ]
Sep 23 11:21:06 tethys kernel: ieee1394: sbp2: Logged out of SBP-2 device
Sep 23 11:21:07 tethys kernel: scsi : 1 host left.

[if ever I replug or turn on the external drive again and run rescan-scsi-bus.sh]

Sep 23 11:21:33 tethys kernel: ohci1394_0: SelfID received outside of bus reset sequence
Sep 23 11:21:34 tethys kernel: ieee1394: Node 00:1023 has non-standard ROM format (0 quads), cannot parse
Sep 23 11:21:34 tethys kernel: ieee1394: Node 00:1023 changed to 01:1023
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 1 0
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 2 0
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 3 0
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 4 0
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 5 0
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 6 0
Sep 23 11:22:04 tethys kernel: scsi singledevice 0 0 7 0

[by chance, after a few seconds the drive was seen again (never happened before)!]

Sep 23 11:22:31 tethys kernel: ieee1394: Node 01:1023 changed to 00:1023
Sep 23 11:22:31 tethys kernel: ieee1394: Device added: Node[01:1023] GUID[0030e0f4e0101cf0] [Oxford Semiconductor Ltd. ]
Sep 23 11:22:31 tethys kernel: ieee1394: sbp2: Logged into SBP-2 device
Sep 23 11:22:31 tethys kernel: ieee1394: sbp2: Node[01:1023]: Max speed [S400] - Max payload [2048]
Sep 23 11:22:31 tethys kernel: scsi1 : IEEE-1394 SBP-2 protocol driver (host: ohci1394)
Sep 23 11:22:31 tethys kernel: $Rev: 530 $ James Goodwin <jamesg@filanet.com>
Sep 23 11:22:31 tethys kernel: SBP-2 module load options:
Sep 23 11:22:31 tethys kernel: - Max speed supported: S400
Sep 23 11:22:31 tethys kernel: - Max sectors per I/O supported: 255
Sep 23 11:22:31 tethys kernel: - Max outstanding commands supported: 8
Sep 23 11:22:31 tethys kernel: - Max outstanding commands per lun supported: 1
Sep 23 11:22:31 tethys kernel: - Serialized I/O (debug): no
Sep 23 11:22:31 tethys kernel: - Exclusive login: yes
Sep 23 11:22:31 tethys kernel: Vendor: IC35L120 Model: AVV207-1 Rev:
Sep 23 11:22:31 tethys kernel: Type: Direct-Access ANSI SCSI revision: 06
Sep 23 11:22:31 tethys kernel: sd_init()
Sep 23 11:22:31 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:07
Sep 23 11:22:31 tethys kernel: sg_attach: dev7=(21:7)
Sep 23 11:22:31 tethys kernel: sd_attach()
Sep 23 11:22:31 tethys kernel: sd: find_free_slot ...<7>sd: ... found 08:00
Sep 23 11:22:31 tethys kernel: Attached scsi disk sda at scsi1, channel 0, id 0, lun 0
Sep 23 11:22:31 tethys kernel: sd_finish()
Sep 23 11:22:31 tethys kernel: sd_init_onedisk (0,0), sda 08:00
Sep 23 11:22:31 tethys kernel: SCSI device sda: 241254720 512-byte hdwr sectors (123522 MB)

[but nothing about /dev/sda1 and 2 in /proc/partitions, even if the disk /dev/sda is seen.]
[then I try to read the partition table w/ yast]

Sep 23 11:23:31 tethys kernel: sda:<3>ieee1394: sbp2: aborting sbp2 command
Sep 23 11:23:31 tethys kernel: 0x28 00 00 00 00 00 00 00 02 00
Sep 23 11:23:41 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:23:41 tethys kernel: 0x00 00 00 00 00 00
Sep 23 11:23:41 tethys kernel: ieee1394: sbp2: reset requested
Sep 23 11:23:41 tethys kernel: ieee1394: sbp2: Generating sbp2 fetch agent reset
Sep 23 11:23:51 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:23:51 tethys kernel: 0x00 00 00 00 00 00
Sep 23 11:23:51 tethys kernel: ieee1394: sbp2: reset requested
Sep 23 11:23:51 tethys kernel: ieee1394: sbp2: Generating sbp2 fetch agent reset
Sep 23 11:24:06 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:24:06 tethys kernel: 0x00 00 00 00 00 00
Sep 23 11:24:06 tethys kernel: scsi: device set offline - not ready or command retry failed after bus reset: host 1 channel 0 id 0 lun 0
Sep 23 11:24:06 tethys kernel: SCSI disk error : host 1 channel 0 id 0 lun 0 return code = 50000
Sep 23 11:24:06 tethys kernel: I/O error: dev 08:00, sector 0
Sep 23 11:24:06 tethys kernel: I/O error: dev 08:00, sector 2
Sep 23 11:24:16 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:24:16 tethys kernel: 0x12 01 80 00 ff 00
Sep 23 11:24:26 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:24:26 tethys kernel: 0x00 00 00 00 00 00
Sep 23 11:24:26 tethys kernel: ieee1394: sbp2: reset requested
Sep 23 11:24:26 tethys kernel: ieee1394: sbp2: Generating sbp2 fetch agent reset
Sep 23 11:24:36 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:24:36 tethys kernel: 0x00 00 00 00 00 00
Sep 23 11:24:36 tethys kernel: ieee1394: sbp2: reset requested
Sep 23 11:24:36 tethys kernel: ieee1394: sbp2: Generating sbp2 fetch agent reset
Sep 23 11:24:51 tethys kernel: ieee1394: sbp2: aborting sbp2 command
Sep 23 11:24:51 tethys kernel: 0x00 00 00 00 00 00
Sep 23 11:24:51 tethys kernel: scsi: device set offline - not ready or command retry failed after bus reset: host 1 channel 0 id 0 lun 0
Sep 23 11:24:51 tethys kernel: I/O error: dev 08:00, sector 0
Sep 23 11:24:51 tethys insmod: Using /lib/modules/2.4.19-4GB/kernel/drivers/ieee1394/sbp2.o
Sep 23 11:24:51 tethys insmod: Symbol version prefix ''
Sep 23 11:24:51 tethys kernel: unable to read partition table

[end of test]

Sep 23 11:26:39 tethys kernel: ieee1394: Device removed: Node[01:1023] GUID[0030e0f4e0101cf0] [Oxford Semiconductor Ltd. ]
Sep 23 11:26:40 tethys kernel: ieee1394: sbp2: Logged out of SBP-2 device
Sep 23 11:26:40 tethys kernel: scsi : 1 host left.

[to know if the problem comes from the combo/drive, I plug it using USB1 right now]

Sep 23 11:27:46 tethys kernel: hub.c: USB new device connect on bus1/1, assigned device number 2
Sep 23 11:27:46 tethys kernel: usb.c: USB device 2 (vend/prod 0x4b4/0x6830) is not claimed by any active driver.
Sep 23 11:27:47 tethys kernel: Initializing USB Mass Storage driver...
Sep 23 11:27:47 tethys kernel: usb.c: registered new driver usb-storage
Sep 23 11:27:47 tethys kernel: usb-uhci.c: interrupt, status 2, frame# 1841
Sep 23 11:27:47 tethys kernel: scsi2 : SCSI emulation for USB Mass Storage devices
Sep 23 11:27:53 tethys kernel: Vendor: IC35L120 Model: AVV207-1 Rev: 0 0
Sep 23 11:27:53 tethys kernel: Type: Direct-Access ANSI SCSI revision: 02
Sep 23 11:27:53 tethys kernel: sd_init()
Sep 23 11:27:53 tethys kernel: sg: find_free_slot ...<7>sg: ... found 15:07
Sep 23 11:27:53 tethys kernel: sg_attach: dev7=(21:7)
Sep 23 11:27:53 tethys kernel: sd_attach()
Sep 23 11:27:53 tethys kernel: sd: find_free_slot ...<7>sd: ... found 08:00
Sep 23 11:27:53 tethys kernel: Attached scsi disk sda at scsi2, channel 0, id 0, lun 0
Sep 23 11:27:53 tethys kernel: sd_finish()
Sep 23 11:27:53 tethys kernel: sd_init_onedisk (0,0), sda 08:00
Sep 23 11:27:53 tethys kernel: SCSI device sda: 241254720 512-byte hdwr sectors (123522 MB)
Sep 23 11:27:53 tethys insmod: Using /lib/modules/2.4.19-4GB/kernel/drivers/usb/storage/usb-storage.o
Sep 23 11:27:53 tethys insmod: Symbol version prefix ''
Sep 23 11:27:53 tethys kernel: sda: sda1 sda2
Sep 23 11:27:53 tethys kernel: WARNING: USB Mass Storage data integrity not assured
Sep 23 11:27:53 tethys kernel: USB Mass Storage device found at 2
Sep 23 11:27:53 tethys kernel: USB Mass Storage support registered.
Sep 23 11:27:54 tethys /etc/hotplug/usb.agent[6297]: Can't ignore signal CHLD, forcing to default.

[partitions are seens (/proc/partitions)]
[so the IEEE1394 status is broken?]
[let's retry: I unplug from USB]

Sep 23 11:30:22 tethys kernel: usb.c: USB disconnect on device 2
Sep 23 11:30:24 tethys kernel: Device 08:00 not ready.
Sep 23 11:30:24 tethys kernel: I/O error: dev 08:00, sector 0

[then replug to IEEE1394]

Sep 23 11:32:57 tethys kernel: ohci1394_0: SelfID received outside of bus reset sequence
Sep 23 11:32:58 tethys kernel: ieee1394: Node 00:1023 has non-standard ROM format (0 quads), cannot parse
Sep 23 11:32:58 tethys kernel: ieee1394: Node 00:1023 changed to 01:1023

[ah! I get the same than yesterday, no way to use it properly thru firewire again]
[partitions are seen but many errors happen if the drive is accessed]

Sep 23 11:33:37 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:37 tethys kernel: I/O error: dev 08:00, sector 0
Sep 23 11:33:37 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:37 tethys kernel: I/O error: dev 08:00, sector 0
Sep 23 11:33:37 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:37 tethys kernel: I/O error: dev 08:00, sector 0
Sep 23 11:33:37 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:37 tethys kernel: I/O error: dev 08:00, sector 2
Sep 23 11:33:37 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:37 tethys kernel: I/O error: dev 08:00, sector 4
Sep 23 11:33:37 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:37 tethys kernel: I/O error: dev 08:00, sector 6
..
Sep 23 11:33:39 tethys kernel: I/O error: dev 08:00, sector 0
Sep 23 11:33:39 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:39 tethys kernel: I/O error: dev 08:00, sector 2
Sep 23 11:33:39 tethys kernel: Device 08:00 not ready.
Sep 23 11:33:39 tethys kernel: I/O error: dev 08:00, sector 4
..

[let's unplug it]

Sep 23 11:35:45 tethys kernel: ieee1394: Node 01:1023 changed to 00:1023

[modprobe -r sbp2, ohci1394 and ieee1394]

Sep 23 11:36:16 tethys kernel: ieee1394: Host removed: Node[00:1023] GUID[364fc00034f7c810] [Linux OHCI-1394]

[then re-modprobe them in order to try to reset IEEE1394 stuff]

Sep 23 11:37:30 tethys kernel: ohci1394: $Rev: 530 $ Ben Collins <bcollins@debian.org>
Sep 23 11:37:30 tethys kernel: ohci1394_0: OHCI-1394 1.0 (PCI): IRQ=[11] MMIO=[f8fff000-f8fff800] Max Packet=[2048]
Sep 23 11:37:31 tethys kernel: ieee1394: Host added: Node[00:1023] GUID[364fc00034f7c810] [Linux OHCI-1394]

[let's replug the external drive, turn it on again (even its power supply were unplugged]
[then: mount /dev/sda1:]

Sep 23 11:39:51 tethys kernel: ohci1394_0: SelfID received outside of bus reset sequence
Sep 23 11:39:52 tethys kernel: ieee1394: Node 00:1023 has non-standard ROM format (0 quads), cannot parse
Sep 23 11:39:52 tethys kernel: ieee1394: Node 00:1023 changed to 01:1023
Sep 23 11:40:49 tethys kernel: Device 08:01 not ready.
Sep 23 11:40:49 tethys kernel: I/O error: dev 08:01, sector 2
Sep 23 11:40:49 tethys kernel: EXT3-fs: unable to read superblock

[unplug]

Sep 23 11:41:50 tethys kernel: Device 08:02 not ready.
Sep 23 11:41:50 tethys kernel: I/O error: dev 08:02, sector 6
Sep 23 11:42:14 tethys kernel: ieee1394: Node 01:1023 changed to 00:1023

[last attempt to see if it's still OK with USB]

Sep 23 11:43:22 tethys kernel: hub.c: USB new device connect on bus1/1, assigned device number 4
Sep 23 11:43:22 tethys kernel: WARNING: USB Mass Storage data integrity not assured
Sep 23 11:43:22 tethys kernel: USB Mass Storage device found at 4
Sep 23 11:43:29 tethys /etc/hotplug/usb.agent[7228]: Can't ignore signal CHLD, forcing to default.

[then I reformat partitions with yast, nothing in /var/log/message and process went OK]

Anyone had experience such problems, or have nay idea?

Regards,

-- 
wwp

-------------------------------------------------------
This sf.net email is sponsored by:ThinkGeek
Welcome to geek heaven.
http://thinkgeek.com/sf
_______________________________________________
mailing list Linux1394-user@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linux1394-user