Thread: Errors with a Freecom Quattro 3.0 attached via firewire/iee1394 - more infos.
Brought to you by:
aeb,
bencollins
From: <pho...@ya...> - 2014-01-22 20:13:39
|
Hello Stefan, here is all the info that I collected about the errors with the Freecom Quattro 3.0 attached via firewire. I am now running 3.13 #> uname -r -v 3.13.0-031300-generic #201401192235 SMP Mon Jan 20 03:36:48 UTC 2014 I have increased log verbosity for creating this log as per your suggestion. I have not yet tried to connect that Freecom Quattro 3.0 to another PC with firewire. However I got hold of another Western Digital disk at a friend's place, connected it via firewire, and it worked just fine. So maybe the Freecom Quattro 3.0 is just crappy engineering :( Best regards P. |
From: Stefan R. <st...@s5...> - 2014-01-29 21:33:59
|
On Jan 22 pho...@ya... wrote: > here is all the info that I collected about the errors with the Freecom > Quattro 3.0 attached via firewire. > > I am now running 3.13 > #> uname -r -v > 3.13.0-031300-generic #201401192235 SMP Mon Jan 20 03:36:48 UTC 2014 > > I have increased log verbosity for creating this log as per your suggestion. > > I have not yet tried to connect that Freecom Quattro 3.0 to another PC > with firewire. However I got hold of another Western Digital disk at a > friend's place, connected it via firewire, and it worked just fine. So > maybe the Freecom Quattro 3.0 is just crappy engineering :( > > Best regards > P. > > > [crapp_fw0_config_rom text/plain (1342 bytes)] > ROM header and bus information block > ----------------------------------------------------------------- > 400 04047561 bus_info_length 4, crc_length 4, crc 30049 > 404 31333934 bus_name "1394" > 408 f000a222 irmc 1, cmc 1, isc 1, bmc 1, pmc 0, cyc_clk_acc 0, > max_rec 10 (2048), max_rom 2, gen 2, spd 2 (S400) > 40c 334fc000 company_id 334fc0 | > 410 33abb470 device_id 0033abb470 | EUI-64 334fc00033abb470 [...] > 454 4a756a75 "Juju" This is the Configuration ROM of the Linux node. Almost all of it in there is defined by the firewire-core kernel driver. A few things aretaken from the hardware though, among them the globally unique ID in EUI-64 form, which is 334fc00033abb470 in the instance of your controller. The company ID part of it, 334fc0, is not a valid OUI from IEEE RAC. However, it is not likely in my opinion that the firmware of the Freecom Quattro cares about that. An SBP-2 target firmware uses the initiator's EUI-64 in order to keep track of the source of requests to the target, but for that purpose the target just needs to store and compare EUI-64 as 64 bits wide blobs without regard to the inner structure of those blobs. [crapp_fw1_config_rom text/plain (2205 bytes)] > ROM header and bus information block > ----------------------------------------------------------------- > 400 0404e11a bus_info_length 4, crc_length 4, crc 57626 (should be > 34316) 404 31333934 bus_name "1394" > 408 00ffb113 irmc 0, cmc 0, isc 0, bmc 0, pmc 0, cyc_clk_acc 255, > max_rec 11 (4096), max_rom 1, gen 1, spd 3 (S800) > 40c 0001db92 company_id 0001db | > 410 00188188 device_id 9200188188 | EUI-64 0001db9200188188 [...] > 44c 46524545 "FREE" > 450 434f4d00 "COM" > > unit directory at 460 > ----------------------------------------------------------------- > 460 000d1486 directory_length 13, crc 5254 > 464 1200609e specifier id: INCITS > 468 13010483 version: SBP-2 > 46c 21000001 SBP-2 revision 1 = SBP-3 > 470 54004008 --> SBP-2 management agent CSR at fffff0010020 > 474 3a003c09 SBP-2 unit char.: mgt_ORB_timeout 30s, ORB_size 9 quadlets > 478 3800609e SBP-2 command set spec id: INCITS > 47c 390104d8 SBP-2 command set: SCSI Primary Commands 2 and related standards > 480 3b000000 SBP-2 command set revision > 484 3c000102 SBP-2 firmware revision 000102 > 488 3d000003 SBP-2 reconnect timeout: max_reconnect_hold 4s > 48c 144e0000 SBP-2 logical unit number: ordered 1, type RBC, lun 0000 [...] > 4ac 48617264 "Hard" > 4b0 20447269 " Dri" > 4b4 76652051 "ve Q" > 4b8 75617474 "uatt" > 4bc 726f2033 "ro 3" This is of course the Configuration ROM of the disk. I am not noticing anything suspicious or wrong in it. Unfortunately, it also does not tell more about the chipset in the device. [dmesg.txt text/plain (7621 bytes)] > [ 817.327764] firewire_ohci 0000:03:01.4: 2 selfIDs, generation 10, local node ID ffc0 > [ 817.327781] firewire_ohci 0000:03:01.4: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc > [ 817.327791] firewire_ohci 0000:03:01.4: selfID 0: 817fc55e, phy 1 [--c] beta gc=63 ?W Li > [ 827.020976] firewire_ohci 0000:03:01.4: 2 selfIDs, generation 11, local node ID ffc0 > [ 827.020991] firewire_ohci 0000:03:01.4: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc > [ 827.021001] firewire_ohci 0000:03:01.4: selfID 0: 817fc55e, phy 1 [--c] beta gc=63 ?W Li > [ 828.338669] scsi7 : SBP-2 IEEE-1394 > [ 828.338743] firewire_core 0000:03:01.4: created device fw1: GUID 0001db9200188188, S400 > [ 828.338749] firewire_core 0000:03:01.4: phy config: new root=ffc0, gap_count=5 > [ 828.339432] firewire_ohci 0000:03:01.4: 2 selfIDs, generation 12, local node ID ffc1 > [ 828.339437] firewire_ohci 0000:03:01.4: selfID 0: 8045c558, phy 0 [--p] beta gc=5 ?W L > [ 828.339441] firewire_ohci 0000:03:01.4: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci > [ 828.554814] firewire_sbp2 fw1.0: logged in to LUN 0000 (0 retries) > [ 828.555818] scsi 7:0:0:0: Direct-Access ST3000DM 001-1CH166 PQ: 0 ANSI: 5 > [ 828.556903] sd 7:0:0:0: Attached scsi generic sg2 type 0 > [ 828.571738] sd 7:0:0:0: [sdb] 5860533152 512-byte logical blocks: (3.00 TB/2.72 TiB) > [ 828.587042] sd 7:0:0:0: [sdb] Write Protect is off > [ 828.587049] sd 7:0:0:0: [sdb] Mode Sense: 10 00 00 00 > [ 828.617036] sd 7:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA > [ 828.699070] sdb: sdb1 > [ 828.761692] sd 7:0:0:0: [sdb] Attached SCSI disk > [ 851.912710] bio: create slab <bio-2> at 2 > [ 852.231531] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) > [ 944.787481] firewire_sbp2 fw1.0: status write for unknown ORB > [ 954.211113] firewire_sbp2 fw1.0: status write for unknown ORB > [ 963.436402] sd 7:0:0:0: [sdb] Unhandled error code > [ 963.436407] sd 7:0:0:0: [sdb] > [ 963.436409] Result: hostbyte=DID_BUS_BUSY driverbyte=DRIVER_OK > [ 963.436412] sd 7:0:0:0: [sdb] CDB: > [ 963.436413] Write(16): 8a 00 00 00 00 00 10 ff 89 00 00 00 04 00 00 00 > [ 963.436425] end_request: I/O error, dev sdb, sector 285182208 > [ 963.436463] EXT4-fs warning (device dm-0): ext4_end_bio:317: I/O error writing to inode 114434179 (offset 8388608 size 8388608 starting block 35647488) > [ 963.436466] Buffer I/O error on device dm-0, logical block 35647488 > [ 963.436470] Buffer I/O error on device dm-0, logical block 35647489 > [ 963.436473] Buffer I/O error on device dm-0, logical block 35647490 > [ 963.436475] Buffer I/O error on device dm-0, logical block 35647491 > [ 963.436482] Buffer I/O error on device dm-0, logical block 35647492 > [ 963.436484] Buffer I/O error on device dm-0, logical block 35647493 > [ 963.436486] Buffer I/O error on device dm-0, logical block 35647494 > [ 963.436488] Buffer I/O error on device dm-0, logical block 35647495 > [ 963.436490] Buffer I/O error on device dm-0, logical block 35647496 > [ 963.436492] Buffer I/O error on device dm-0, logical block 35647497 > [ 963.622762] firewire_sbp2 fw1.0: status write for unknown ORB > [ 982.791361] firewire_sbp2 fw1.0: status write for unknown ORB > [ 992.208952] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1001.432404] sd 7:0:0:0: [sdb] Unhandled error code > [ 1001.432421] sd 7:0:0:0: [sdb] > [ 1001.432426] Result: hostbyte=DID_BUS_BUSY driverbyte=DRIVER_OK > [ 1001.432430] sd 7:0:0:0: [sdb] CDB: > [ 1001.432433] Write(16): 8a 00 00 00 00 00 10 ff cd 00 00 00 04 00 00 00 > [ 1001.432455] end_request: I/O error, dev sdb, sector 285199616 > [ 1001.432517] EXT4-fs warning (device dm-0): ext4_end_bio:317: I/O error writing to inode 114434179 (offset 16777216 size 8388608 starting block 35649664) > [ 1001.432523] buffer_io_error: 118 callbacks suppressed > [ 1001.432527] Buffer I/O error on device dm-0, logical block 35649664 > [ 1001.432534] Buffer I/O error on device dm-0, logical block 35649665 > [ 1001.432539] Buffer I/O error on device dm-0, logical block 35649666 > [ 1001.432543] Buffer I/O error on device dm-0, logical block 35649667 > [ 1001.432547] Buffer I/O error on device dm-0, logical block 35649668 > [ 1001.432551] Buffer I/O error on device dm-0, logical block 35649669 > [ 1001.432555] Buffer I/O error on device dm-0, logical block 35649670 > [ 1001.432559] Buffer I/O error on device dm-0, logical block 35649671 > [ 1001.432563] Buffer I/O error on device dm-0, logical block 35649672 > [ 1001.432567] Buffer I/O error on device dm-0, logical block 35649673 > [ 1001.626577] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1011.026839] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1049.773080] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1068.832685] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1078.617655] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1098.394512] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1107.794741] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1117.496439] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1137.852013] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1177.881913] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1187.470062] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1218.498244] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1227.915797] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1237.140148] sd 7:0:0:0: [sdb] Unhandled error code > [ 1237.140163] sd 7:0:0:0: [sdb] > [ 1237.140167] Result: hostbyte=DID_BUS_BUSY driverbyte=DRIVER_OK > [ 1237.140172] sd 7:0:0:0: [sdb] CDB: > [ 1237.140175] Write(16): 8a 00 00 00 00 00 12 0f 09 00 00 00 04 00 00 00 > [ 1237.140196] end_request: I/O error, dev sdb, sector 302975232 > [ 1237.140245] EXT4-fs warning (device dm-0): ext4_end_bio:317: I/O error writing to inode 114434181 (offset 25165824 size 4194304 starting block 37871616) > [ 1237.140248] buffer_io_error: 118 callbacks suppressed > [ 1237.140250] Buffer I/O error on device dm-0, logical block 37871616 > [ 1237.140254] Buffer I/O error on device dm-0, logical block 37871617 > [ 1237.140256] Buffer I/O error on device dm-0, logical block 37871618 > [ 1237.140258] Buffer I/O error on device dm-0, logical block 37871619 > [ 1237.140260] Buffer I/O error on device dm-0, logical block 37871620 > [ 1237.140262] Buffer I/O error on device dm-0, logical block 37871621 > [ 1237.140264] Buffer I/O error on device dm-0, logical block 37871622 > [ 1237.140265] Buffer I/O error on device dm-0, logical block 37871623 > [ 1237.140267] Buffer I/O error on device dm-0, logical block 37871624 > [ 1237.140269] Buffer I/O error on device dm-0, logical block 37871625 > [ 1237.331110] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1249.108424] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1278.293678] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1288.046882] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1318.483257] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1328.643319] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1366.661827] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1377.213409] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1386.623543] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1396.477497] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1406.642138] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1418.814202] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1440.203493] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1459.279209] firewire_sbp2 fw1.0: status write for unknown ORB > [ 1479.500552] firewire_sbp2 fw1.0: status write for unknown ORB This is interesting. When I asked you for this verbose log, I was wondering whether frequent bus resets are happening during I/O. If yes, they would have been a very sure sign of electrical problems (e.g. electromagnetic interference, overheated components, or the likes). The debug parameter which I gave you does actually not log bus resets, but "self identification complete events" which follow after a successful bus reset phase. As you see, you got selfID events directly when the disk was plugged in (as expected), but not later between the I/O error messages. This means that either there did not in fact happen any bus resets, or they did happen but were not followed up by selfID complete events. However, the presence of "firewire_sbp2 fw1.0: status write for unknown ORB" messages means that we are *not* dealing with bus resets without selfIDs here. This shifts my suspicion away from physical problems towards software problems. "Software" meaning primarily Linux' block/ SCSI/ firewire-sbp2 initiator stack on one hand, and the Quattro's SBP-2 target firmware on the other hand. Call me biased, by out of these, the firmware is my prime suspect. Note that the FireWire part of the Quattro and its USB part run totally independent and very different firmwares. (And the eSATA part is perhaps a firmware-less pass-through, but I am not sure.) Meaning that these the FireWire and USB firmwares of the Quattro differ from each other also with respect to the bugs that they do or do not contain. [lsfirewirephy_with_freecom_quattro_3_0_attached text/plain (94 bytes)] > bus 0, node 0: 00053d:08430b Agere Systems (unknown) > bus 0, node 1: 000cc2:401104 (unknown) [lsfirewirephy_with_nothing_attached text/plain (40 bytes)] > bus 0, node 0: 000cc2:401104 (unknown) 000cc2:401104 is apparently the integrated PHY of the O2 Micro controller of yours, and 00053d:08430b is apparently a discrete LSI/Agere FW843 1394b PHY in the Freecom Quattro. I don't have any device with Agere FW843 myself, but as I argued above, I no longer suspect the physical layer to be the source of the problems. -- Stefan Richter -=====-====- ---= ===-= http://arcgraph.de/sr/ |