Thread: half a loop
Brought to you by:
aeb,
bencollins
Menu
▾
▴
linux1394-user
|
From: Carl K. <ca...@pe...> - 2011-12-18 00:23:51
|
same hardware, but new flavor of problem: 2 controllers in one box, cable looped from one to the other. (it is the 2m cable that seems to cause the "isochronous cycle inconsistent" in the other thread. juser@pc8:~$ ls /dev/fw? /dev/fw0 /dev/fw1 /dev/fw2 juser@pc8:~$ uname -a Linux pc8 3.2.0-4-generic #10-Ubuntu SMP Sat Dec 10 17:46:09 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux juser@pc8:~$ dmesg |grep fire [ 1.935578] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 [ 1.988295] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 [ 1.988453] firewire_ohci: isochronous cycle inconsistent [ 1.993092] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 [ 1.993098] firewire_ohci 0000:04:00.0: setting latency timer to 64 [ 2.051121] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 [ 2.051204] firewire_ohci: isochronous cycle inconsistent [ 2.488158] firewire_core: created device fw0: GUID 00241b00964cac00, S400 [ 2.552154] firewire_core: created device fw1: GUID 0108000000006351, S800 [ 23.608055] firewire_ohci: AT spd 0 tl 06, ffc1 -> ffc0, ack_pending , QR req, fffff0000400 [ 23.608064] firewire_ohci: AR spd 0 tl 06, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 23.608083] firewire_ohci: AT spd 0 tl 07, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 23.608090] firewire_ohci: AR spd 0 tl 07, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 23.608128] firewire_ohci: AT spd 0 tl 08, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 23.608135] firewire_ohci: AR spd 0 tl 08, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 23.608160] firewire_ohci: AT spd 0 tl 09, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 23.608167] firewire_ohci: AR spd 0 tl 09, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 23.608192] firewire_ohci: AT spd 0 tl 0a, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 23.608199] firewire_ohci: AR spd 0 tl 0a, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 23.608232] firewire_ohci: AT spd 2 tl 0b, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 23.648054] firewire_ohci: AT spd 0 tl 04, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 [ 23.648064] firewire_ohci: AR spd 0 tl 04, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 23.648092] firewire_ohci: AT spd 0 tl 05, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 23.648099] firewire_ohci: AR spd 0 tl 05, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 23.648133] firewire_ohci: AT spd 0 tl 06, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 23.648140] firewire_ohci: AR spd 0 tl 06, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 23.648165] firewire_ohci: AT spd 0 tl 07, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 23.648171] firewire_ohci: AR spd 0 tl 07, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 23.648196] firewire_ohci: AT spd 0 tl 08, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 23.648203] firewire_ohci: AR spd 0 tl 08, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 23.648229] firewire_ohci: AT spd 2 tl 09, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 26.616045] firewire_ohci: AR spd 0 tl 0c, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 26.616053] firewire_ohci: AT spd 0 tl 0c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 26.616071] firewire_ohci: AT spd 0 tl 0d, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 26.616080] firewire_ohci: AR spd 0 tl 0d, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 26.616103] firewire_ohci: AT spd 0 tl 0e, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 26.616122] firewire_ohci: AR spd 0 tl 0e, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 26.616151] firewire_ohci: AT spd 0 tl 0f, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 26.616157] firewire_ohci: AR spd 0 tl 0f, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 26.616182] firewire_ohci: AT spd 0 tl 10, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 26.616189] firewire_ohci: AR spd 0 tl 10, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 26.616223] firewire_ohci: AT spd 2 tl 11, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 26.656045] firewire_ohci: AT spd 0 tl 0a, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 [ 26.656053] firewire_ohci: AR spd 0 tl 0a, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 26.656080] firewire_ohci: AT spd 0 tl 0b, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 26.656087] firewire_ohci: AR spd 0 tl 0b, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 26.656127] firewire_ohci: AT spd 0 tl 0c, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 26.656134] firewire_ohci: AR spd 0 tl 0c, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 26.656159] firewire_ohci: AT spd 0 tl 0d, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 26.656165] firewire_ohci: AR spd 0 tl 0d, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 26.656190] firewire_ohci: AT spd 0 tl 0e, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 26.656197] firewire_ohci: AR spd 0 tl 0e, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 26.656233] firewire_ohci: AT spd 2 tl 0f, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 29.624057] firewire_ohci: AR spd 0 tl 12, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 29.624064] firewire_ohci: AT spd 0 tl 12, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 29.624086] firewire_ohci: AT spd 0 tl 13, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 29.624095] firewire_ohci: AR spd 0 tl 13, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 29.624119] firewire_ohci: AR spd 0 tl 14, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 29.624123] firewire_ohci: AT spd 0 tl 14, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 [ 29.624158] firewire_ohci: AR spd 0 tl 15, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 29.624162] firewire_ohci: AT spd 0 tl 15, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 29.624189] firewire_ohci: AT spd 0 tl 16, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 29.624196] firewire_ohci: AR spd 0 tl 16, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 29.624229] firewire_ohci: AT spd 2 tl 17, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 29.664049] firewire_ohci: AR spd 0 tl 10, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 29.664056] firewire_ohci: AT spd 0 tl 10, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 29.664086] firewire_ohci: AT spd 0 tl 11, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 29.664095] firewire_ohci: AR spd 0 tl 11, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 29.664133] firewire_ohci: AT spd 0 tl 12, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 29.664140] firewire_ohci: AR spd 0 tl 12, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 29.664169] firewire_ohci: AT spd 0 tl 13, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 29.664175] firewire_ohci: AR spd 0 tl 13, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 29.664204] firewire_ohci: AT spd 0 tl 14, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 29.664211] firewire_ohci: AR spd 0 tl 14, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 29.664264] firewire_ohci: AT spd 2 tl 15, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 32.632068] firewire_ohci: AR spd 0 tl 18, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 32.632075] firewire_ohci: AT spd 0 tl 18, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 32.632111] firewire_ohci: AR spd 0 tl 19, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 32.632119] firewire_ohci: AT spd 0 tl 19, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 32.632146] firewire_ohci: AT spd 0 tl 1a, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 32.632155] firewire_ohci: AR spd 0 tl 1a, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 32.632185] firewire_ohci: AR spd 0 tl 1b, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 32.632189] firewire_ohci: AT spd 0 tl 1b, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 32.632217] firewire_ohci: AT spd 0 tl 1c, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 32.632225] firewire_ohci: AR spd 0 tl 1c, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 32.632258] firewire_ohci: AT spd 2 tl 1d, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 32.632272] firewire_core: giving up on config rom for node id ffc0 [ 32.672061] firewire_ohci: AR spd 0 tl 16, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 32.672068] firewire_ohci: AT spd 0 tl 16, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 32.672109] firewire_ohci: AR spd 0 tl 17, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 32.672116] firewire_ohci: AT spd 0 tl 17, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404 [ 32.672142] firewire_ohci: AT spd 0 tl 18, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 32.672150] firewire_ohci: AR spd 0 tl 18, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 32.672173] firewire_ohci: AT spd 0 tl 19, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 32.672179] firewire_ohci: AR spd 0 tl 19, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 32.672204] firewire_ohci: AT spd 0 tl 1a, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 32.672210] firewire_ohci: AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 32.672262] firewire_ohci: AT spd 2 tl 1b, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 32.672269] firewire_core: giving up on config rom for node id ffc1 [ 32.672275] firewire_core: phy config: card 0, new root=ffc0, gap_count=5 [ 32.672295] firewire_ohci: AT ack_complete, PHY 00c50000 ff3affff [ 32.672299] firewire_ohci: AR ack_complete, PHY 00c50000 ff3affff [ 32.672324] firewire_ohci: AR evt_bus_reset, generation 5 [ 32.672327] firewire_ohci: AR evt_bus_reset, generation 3 [ 32.672335] firewire_ohci: 2 selfIDs, generation 5, local node ID ffc0 [ 32.672339] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc [ 32.672342] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci [ 32.672356] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc1 [ 32.672359] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc [ 32.672362] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci [ 32.928047] firewire_ohci: AR spd 0 tl 1e, ffc1 -> ffc0, ack_complete, Lk resp 4,2 [ 32.928052] firewire_ohci: AT spd 0 tl 1e, ffc0 -> ffc1, pending/cancelled, Lk req, fffff000021c 8,2 [ 33.172042] firewire_ohci: AR spd 0 tl 1f, ffc1 -> ffc0, ack_complete, QR resp = 0404e334 [ 33.172047] firewire_ohci: AT spd 0 tl 1f, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 33.172070] firewire_ohci: AT spd 0 tl 20, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 33.172078] firewire_ohci: AR spd 0 tl 20, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 33.172097] firewire_ohci: AR spd 0 tl 21, ffc1 -> ffc0, ack_complete, QR resp = f000a222 [ 33.172102] firewire_ohci: AT spd 0 tl 21, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000408 [ 33.172121] firewire_ohci: AT spd 0 tl 22, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 33.172128] firewire_ohci: AR spd 0 tl 22, ffc1 -> ffc0, ack_complete, QR resp = 00241b00 [ 33.172148] firewire_ohci: AR spd 0 tl 23, ffc1 -> ffc0, ack_complete, QR resp = 964cac00 [ 33.172152] firewire_ohci: AT spd 0 tl 23, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000410 [ 33.172170] firewire_ohci: AR spd 2 tl 24, ffc1 -> ffc0, ack_complete, QR resp = 0005dd0b [ 33.172174] firewire_ohci: AT spd 2 tl 24, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000414 [ 33.172192] firewire_ohci: AT spd 2 tl 25, ffc0 -> ffc1, ack_pending , QR req, fffff0000418 [ 33.172199] firewire_ohci: AR spd 2 tl 25, ffc1 -> ffc0, ack_complete, QR resp = 0c0083c0 [ 33.172217] firewire_ohci: AT spd 2 tl 26, ffc0 -> ffc1, ack_pending , QR req, fffff000041c [ 33.172224] firewire_ohci: AR spd 2 tl 26, ffc1 -> ffc0, ack_complete, QR resp = 03d00d1e [ 33.172242] firewire_ohci: AT spd 2 tl 27, ffc0 -> ffc1, ack_pending , QR req, fffff0000420 [ 33.172249] firewire_ohci: AR spd 2 tl 27, ffc1 -> ffc0, ack_complete, QR resp = 81000003 [ 33.172267] firewire_ohci: AT spd 2 tl 28, ffc0 -> ffc1, ack_pending , QR req, fffff0000424 [ 33.172274] firewire_ohci: AR spd 2 tl 28, ffc1 -> ffc0, ack_complete, QR resp = 17000001 [ 33.172292] firewire_ohci: AR spd 2 tl 29, ffc1 -> ffc0, ack_complete, QR resp = 81000008 [ 33.172296] firewire_ohci: AT spd 2 tl 29, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000428 [ 33.172315] firewire_ohci: AT spd 2 tl 2a, ffc0 -> ffc1, ack_pending , QR req, fffff0000448 [ 33.172322] firewire_ohci: AR spd 2 tl 2a, ffc1 -> ffc0, ack_complete, QR resp = 0003ff1c [ 33.172340] firewire_ohci: AT spd 2 tl 2b, ffc0 -> ffc1, ack_pending , QR req, fffff000044c [ 33.172347] firewire_ohci: AR spd 2 tl 2b, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 33.172365] firewire_ohci: AR spd 2 tl 2c, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 33.172369] firewire_ohci: AT spd 2 tl 2c, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000450 [ 33.172388] firewire_ohci: AR spd 2 tl 2d, ffc1 -> ffc0, ack_complete, QR resp = 4a756a75 [ 33.172392] firewire_ohci: AT spd 2 tl 2d, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000454 [ 33.172411] firewire_ohci: AT spd 2 tl 2e, ffc0 -> ffc1, ack_pending , QR req, fffff000042c [ 33.172417] firewire_ohci: AR spd 2 tl 2e, ffc1 -> ffc0, ack_complete, QR resp = 00064cb7 [ 33.172436] firewire_ohci: AT spd 2 tl 2f, ffc0 -> ffc1, ack_pending , QR req, fffff0000430 [ 33.172442] firewire_ohci: AR spd 2 tl 2f, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 33.172460] firewire_ohci: AR spd 2 tl 30, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 33.172464] firewire_ohci: AT spd 2 tl 30, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000434 [ 33.172483] firewire_ohci: AT spd 2 tl 31, ffc0 -> ffc1, ack_pending , QR req, fffff0000438 [ 33.172490] firewire_ohci: AR spd 2 tl 31, ffc1 -> ffc0, ack_complete, QR resp = 4c696e75 [ 33.172508] firewire_ohci: AR spd 2 tl 32, ffc1 -> ffc0, ack_complete, QR resp = 78204669 [ 33.172512] firewire_ohci: AT spd 2 tl 32, ffc0 -> ffc1, pending/cancelled, QR req, fffff000043c [ 33.172531] firewire_ohci: AT spd 2 tl 33, ffc0 -> ffc1, ack_pending , QR req, fffff0000440 [ 33.172537] firewire_ohci: AR spd 2 tl 33, ffc1 -> ffc0, ack_complete, QR resp = 72657769 [ 33.172555] firewire_ohci: AT spd 2 tl 34, ffc0 -> ffc1, ack_pending , QR req, fffff0000444 [ 33.172562] firewire_ohci: AR spd 2 tl 34, ffc1 -> ffc0, ack_complete, QR resp = 72650000 [ 33.172679] firewire_core: created device fw2: GUID 00241b00964cac00, S400 [ 33.172698] firewire_ohci: AT spd 2 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 [ 33.172704] firewire_ohci: AR spd 2 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 [ 33.172724] firewire_ohci: AR spd 2 tl 35, ffc1 -> ffc0, ack_complete, QR resp = c000001f [ 33.172729] firewire_ohci: AT spd 2 tl 35, ffc1 -> ffc0, ack_complete, QR resp = c000001f [ 33.172753] firewire_ohci: AT spd 2 tl 36, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f [ 33.172758] firewire_ohci: AR spd 2 tl 36, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f [ 33.172776] firewire_ohci: AR spd 2 tl 36, ffc1 -> ffc0, ack_complete, W resp [ 33.172781] firewire_ohci: AT spd 2 tl 36, ffc1 -> ffc0, ack_complete, W resp [ 33.172804] firewire_ohci: AT spd 0 tl 37, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2 [ 33.172811] firewire_ohci: AR spd 0 tl 37, ffc1 -> ffc0, ack_complete, Lk resp 4,2 rebooted, now both ends show up: juser@pc8:~$ dmesg |grep fire [ 2.012380] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 [ 2.068068] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 [ 2.068416] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 [ 2.068422] firewire_ohci 0000:04:00.0: setting latency timer to 64 [ 2.125123] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 [ 2.125154] firewire_ohci: isochronous cycle inconsistent [ 2.568156] firewire_core: created device fw0: GUID 00241b00964cac00, S400 [ 2.568172] firewire_core: phy config: card 0, new root=ffc1, gap_count=5 [ 2.624160] firewire_core: created device fw1: GUID 0108000000006351, S800 [ 2.624724] firewire_core: created device fw2: GUID 00241b00964cac00, S400 [ 5.576653] firewire_core: created device fw3: GUID 0108000000006351, S400, 1 config ROM retries juser@pc8:~$ dmesg |grep fire [ 2.012380] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 [ 2.068068] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 [ 2.068416] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 [ 2.068422] firewire_ohci 0000:04:00.0: setting latency timer to 64 [ 2.125123] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 [ 2.125154] firewire_ohci: isochronous cycle inconsistent [ 2.568156] firewire_core: created device fw0: GUID 00241b00964cac00, S400 [ 2.568172] firewire_core: phy config: card 0, new root=ffc1, gap_count=5 [ 2.624160] firewire_core: created device fw1: GUID 0108000000006351, S800 [ 2.624724] firewire_core: created device fw2: GUID 00241b00964cac00, S400 [ 5.576653] firewire_core: created device fw3: GUID 0108000000006351, S400, 1 config ROM retries juser@pc8:~$ ls /dev/fw? /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3 -- Carl K |
|
From: Stefan R. <st...@s5...> - 2011-12-18 13:57:43
|
On Dec 17 Carl Karsten wrote:
> same hardware, but new flavor of problem: 2 controllers in one box,
> cable looped from one to the other. (it is the 2m cable that seems to
> cause the "isochronous cycle inconsistent" in the other thread.
I don't think it causes the isoch cycle inconsistency, the topology change
does. See Clemens' explanation. It may however cause the Configuration
ROM read failure.
> juser@pc8:~$ ls /dev/fw?
> /dev/fw0 /dev/fw1 /dev/fw2
>
> juser@pc8:~$ uname -a
> Linux pc8 3.2.0-4-generic #10-Ubuntu SMP Sat Dec 10 17:46:09 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux
>
> juser@pc8:~$ dmesg |grep fire
>
> [ 1.935578] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5
> [ 1.988295] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1
> [ 1.988453] firewire_ohci: isochronous cycle inconsistent
> [ 1.993092] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16
> [ 1.993098] firewire_ohci 0000:04:00.0: setting latency timer to 64
> [ 2.051121] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10
> [ 2.051204] firewire_ohci: isochronous cycle inconsistent
> [ 2.488158] firewire_core: created device fw0: GUID 00241b00964cac00, S400
> [ 2.552154] firewire_core: created device fw1: GUID 0108000000006351, S800
> [ 23.608055] firewire_ohci: AT spd 0 tl 06, ffc1 -> ffc0, ack_pending , QR req, fffff0000400
With firewire-ohci debug=3, there should be a few log lines from the
self-ID reception DMA between the two last lines above. Why are they
missing?
(By the way, I have a patch here waiting to be posted which adds device
prefixes to firewire-ohci's debug messages --- for us folk who have more
than one controller in the PC and wonder which controller is emitting
what messages.)
> [ 23.608064] firewire_ohci: AR spd 0 tl 06, ffc0 -> ffc1, ack_complete, QR resp = 0404e334
> [ 23.608083] firewire_ohci: AT spd 0 tl 07, ffc1 -> ffc0, ack_pending , QR req, fffff0000404
> [ 23.608090] firewire_ohci: AR spd 0 tl 07, ffc0 -> ffc1, ack_complete, QR resp = 31333934
> [ 23.608128] firewire_ohci: AT spd 0 tl 08, ffc1 -> ffc0, ack_pending , QR req, fffff0000408
> [ 23.608135] firewire_ohci: AR spd 0 tl 08, ffc0 -> ffc1, ack_complete, QR resp = f000a222
> [ 23.608160] firewire_ohci: AT spd 0 tl 09, ffc1 -> ffc0, ack_pending , QR req, fffff000040c
> [ 23.608167] firewire_ohci: AR spd 0 tl 09, ffc0 -> ffc1, ack_complete, QR resp = 00241b00
> [ 23.608192] firewire_ohci: AT spd 0 tl 0a, ffc1 -> ffc0, ack_pending , QR req, fffff0000410
> [ 23.608199] firewire_ohci: AR spd 0 tl 0a, ffc0 -> ffc1, ack_complete, QR resp = 964cac00
> [ 23.608232] firewire_ohci: AT spd 2 tl 0b, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414
> [ 23.648054] firewire_ohci: AT spd 0 tl 04, ffc0 -> ffc1, ack_pending , QR req, fffff0000400
> [ 23.648064] firewire_ohci: AR spd 0 tl 04, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d
> [ 23.648092] firewire_ohci: AT spd 0 tl 05, ffc0 -> ffc1, ack_pending , QR req, fffff0000404
> [ 23.648099] firewire_ohci: AR spd 0 tl 05, ffc1 -> ffc0, ack_complete, QR resp = 31333934
> [ 23.648133] firewire_ohci: AT spd 0 tl 06, ffc0 -> ffc1, ack_pending , QR req, fffff0000408
> [ 23.648140] firewire_ohci: AR spd 0 tl 06, ffc1 -> ffc0, ack_complete, QR resp = f000b223
> [ 23.648165] firewire_ohci: AT spd 0 tl 07, ffc0 -> ffc1, ack_pending , QR req, fffff000040c
> [ 23.648171] firewire_ohci: AR spd 0 tl 07, ffc1 -> ffc0, ack_complete, QR resp = 01080000
> [ 23.648196] firewire_ohci: AT spd 0 tl 08, ffc0 -> ffc1, ack_pending , QR req, fffff0000410
> [ 23.648203] firewire_ohci: AR spd 0 tl 08, ffc1 -> ffc0, ack_complete, QR resp = 00006351
> [ 23.648229] firewire_ohci: AT spd 2 tl 09, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414
[...]
> [ 32.632258] firewire_ohci: AT spd 2 tl 1d, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414
> [ 32.632272] firewire_core: giving up on config rom for node id ffc0
> [ 32.672061] firewire_ohci: AR spd 0 tl 16, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d
> [ 32.672068] firewire_ohci: AT spd 0 tl 16, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400
> [ 32.672109] firewire_ohci: AR spd 0 tl 17, ffc1 -> ffc0, ack_complete, QR resp = 31333934
> [ 32.672116] firewire_ohci: AT spd 0 tl 17, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404
> [ 32.672142] firewire_ohci: AT spd 0 tl 18, ffc0 -> ffc1, ack_pending , QR req, fffff0000408
> [ 32.672150] firewire_ohci: AR spd 0 tl 18, ffc1 -> ffc0, ack_complete, QR resp = f000b223
> [ 32.672173] firewire_ohci: AT spd 0 tl 19, ffc0 -> ffc1, ack_pending , QR req, fffff000040c
> [ 32.672179] firewire_ohci: AR spd 0 tl 19, ffc1 -> ffc0, ack_complete, QR resp = 01080000
> [ 32.672204] firewire_ohci: AT spd 0 tl 1a, ffc0 -> ffc1, ack_pending , QR req, fffff0000410
> [ 32.672210] firewire_ohci: AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = 00006351
> [ 32.672262] firewire_ohci: AT spd 2 tl 1b, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414
> [ 32.672269] firewire_core: giving up on config rom for node id ffc1
Up to this point, the S800 controller fails to read from the S400
controller, and the S400 controller fails to read from the S800
controller, always with the read request to the 6th quadlet of the
Configuration ROM, always at S400 ( = "spd 2", whereas the first 5
quadlets are always successfully read at S100 = "spd 0"), always with
transaction failure due to missing ACK in the request subaction.
Im my experience, an "evt_missing_ack" can occur
- with an electrically unstable bus, e.g. caused by a bad cable,
- if the gap count at one or more nodes is too low,
- if a packet is sent at a larger speed than the peer node (or any
repeater node between sender and receiver) can handle.
Gap count /should/ not be the issue here, because both PHYs were just
switched on and are supposed to feature a gap count of 63, which is the
power reset value and the absolute maximum.
A mismatch of transmission speed vs. supported speed cannot be the issue
here, according to your log from after reboot (below).
By the way, firewire-core always reads the first 5 quadlets ( = one header
quadlet and the four quadlets of bus information of the Configuration ROM
register) only at S100 as the only speed that is guaranteed to be
supported. The rest of the Configuration ROM is read at a higher speed
which is either determined from self-ID data of all PHYs and link speed
from the bus information block (the latter taken with a grain of salt;
this is not the actual link speed but the one that the firmware writer is
wanting us to believe) or determined from a speed probe, using read tests
at fffff0000400 at several speeds. In case of your two particular cards
plugged together, firewire-core does not perform a speed probe but decides
that both devices can talk to each other at S400.
After the above, one of the two nodes performs bus management,
particularly decides to switch all PHYs to a lower gap count to increase
asynchronous bandwidth:
> [ 32.672275] firewire_core: phy config: card 0, new root=ffc0, gap_count=5
> [ 32.672295] firewire_ohci: AT ack_complete, PHY 00c50000 ff3affff
> [ 32.672299] firewire_ohci: AR ack_complete, PHY 00c50000 ff3affff
> [ 32.672324] firewire_ohci: AR evt_bus_reset, generation 5
> [ 32.672327] firewire_ohci: AR evt_bus_reset, generation 3
> [ 32.672335] firewire_ohci: 2 selfIDs, generation 5, local node ID ffc0
> [ 32.672339] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc
> [ 32.672342] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci
> [ 32.672356] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc1
> [ 32.672359] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc
> [ 32.672362] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci
This involves transmission of a PHY packet by one node, reception of that
packet by the other one, bus reset by the former node, and self-ID
reception by both nodes. Then there is arbitration for bus manager role,
with ffc0 as requester and ffc1 (which is the IRM) as responder:
> [ 32.928047] firewire_ohci: AR spd 0 tl 1e, ffc1 -> ffc0, ack_complete, Lk resp 4,2
> [ 32.928052] firewire_ohci: AT spd 0 tl 1e, ffc0 -> ffc1, pending/cancelled, Lk req, fffff000021c 8,2
The fact that node ffc1 (phy 1) issued a bus reset is taken as a signal to
firewire-core on node ffc0 (phy 0) to re-read the Configuration ROM of
node ffc1:
> [ 33.172042] firewire_ohci: AR spd 0 tl 1f, ffc1 -> ffc0, ack_complete, QR resp = 0404e334
> [ 33.172047] firewire_ohci: AT spd 0 tl 1f, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400
> [ 33.172070] firewire_ohci: AT spd 0 tl 20, ffc0 -> ffc1, ack_pending , QR req, fffff0000404
> [ 33.172078] firewire_ohci: AR spd 0 tl 20, ffc1 -> ffc0, ack_complete, QR resp = 31333934
> [ 33.172097] firewire_ohci: AR spd 0 tl 21, ffc1 -> ffc0, ack_complete, QR resp = f000a222
> [ 33.172102] firewire_ohci: AT spd 0 tl 21, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000408
> [ 33.172121] firewire_ohci: AT spd 0 tl 22, ffc0 -> ffc1, ack_pending , QR req, fffff000040c
> [ 33.172128] firewire_ohci: AR spd 0 tl 22, ffc1 -> ffc0, ack_complete, QR resp = 00241b00
> [ 33.172148] firewire_ohci: AR spd 0 tl 23, ffc1 -> ffc0, ack_complete, QR resp = 964cac00
> [ 33.172152] firewire_ohci: AT spd 0 tl 23, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000410
> [ 33.172170] firewire_ohci: AR spd 2 tl 24, ffc1 -> ffc0, ack_complete, QR resp = 0005dd0b
> [ 33.172174] firewire_ohci: AT spd 2 tl 24, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000414
> [ 33.172192] firewire_ohci: AT spd 2 tl 25, ffc0 -> ffc1, ack_pending , QR req, fffff0000418
> [ 33.172199] firewire_ohci: AR spd 2 tl 25, ffc1 -> ffc0, ack_complete, QR resp = 0c0083c0
> [ 33.172217] firewire_ohci: AT spd 2 tl 26, ffc0 -> ffc1, ack_pending , QR req, fffff000041c
> [ 33.172224] firewire_ohci: AR spd 2 tl 26, ffc1 -> ffc0, ack_complete, QR resp = 03d00d1e
[...]
> [ 33.172531] firewire_ohci: AT spd 2 tl 33, ffc0 -> ffc1, ack_pending , QR req, fffff0000440
> [ 33.172537] firewire_ohci: AR spd 2 tl 33, ffc1 -> ffc0, ack_complete, QR resp = 72657769
> [ 33.172555] firewire_ohci: AT spd 2 tl 34, ffc0 -> ffc1, ack_pending , QR req, fffff0000444
> [ 33.172562] firewire_ohci: AR spd 2 tl 34, ffc1 -> ffc0, ack_complete, QR resp = 72650000
> [ 33.172679] firewire_core: created device fw2: GUID 00241b00964cac00, S400
Curiously, now all of the Configuration ROM can be read without incident!
> [ 33.172698] firewire_ohci: AT spd 2 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff0000234
> [ 33.172704] firewire_ohci: AR spd 2 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff0000234
> [ 33.172724] firewire_ohci: AR spd 2 tl 35, ffc1 -> ffc0, ack_complete, QR resp = c000001f
> [ 33.172729] firewire_ohci: AT spd 2 tl 35, ffc1 -> ffc0, ack_complete, QR resp = c000001f
> [ 33.172753] firewire_ohci: AT spd 2 tl 36, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f
> [ 33.172758] firewire_ohci: AR spd 2 tl 36, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f
> [ 33.172776] firewire_ohci: AR spd 2 tl 36, ffc1 -> ffc0, ack_complete, W resp
> [ 33.172781] firewire_ohci: AT spd 2 tl 36, ffc1 -> ffc0, ack_complete, W resp
> [ 33.172804] firewire_ohci: AT spd 0 tl 37, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2
> [ 33.172811] firewire_ohci: AR spd 0 tl 37, ffc1 -> ffc0, ack_complete, Lk resp 4,2
These lines show a few requests from ffc0 to ffc1 and their responses,
which are routinely done when firewire-core probed a new node. Again no
missing ACK anymore.
Carl,
can you try this once more and check which gap counts are reported in the
self ID reception event right after you plugged the cable in == right
before the nodes unsuccessfully attempt to get each other's Configuration
ROM?
Furthermore, tell us whether you end up with two or three /dev/fw* again
(i.e. whether neither node succeeded to probe the other, or one of them
succeeded to probe the other). Then, run either gscanbus or firecontrol
on _each_ "port" and use it to trigger a bus reset, then watch if this
results in all four expected /dev/fw* becoming available.
> rebooted, now both ends show up:
>
>
> juser@pc8:~$ dmesg |grep fire
[...]
> [ 2.125123] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10
> [ 2.125154] firewire_ohci: isochronous cycle inconsistent
> [ 2.568156] firewire_core: created device fw0: GUID 00241b00964cac00, S400
> [ 2.568172] firewire_core: phy config: card 0, new root=ffc1, gap_count=5
> [ 2.624160] firewire_core: created device fw1: GUID 0108000000006351, S800
> [ 2.624724] firewire_core: created device fw2: GUID 00241b00964cac00, S400
> [ 5.576653] firewire_core: created device fw3: GUID 0108000000006351, S400, 1 config ROM retries
>
> juser@pc8:~$ ls /dev/fw?
> /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3
The "1 config ROM retries" is a hint that the connection still is not
fully stable.
--
Stefan Richter
-=====-==-== ==-- =--=-
http://arcgraph.de/sr/
|
|
From: Carl K. <ca...@pe...> - 2011-12-18 22:54:13
|
On Sun, Dec 18, 2011 at 7:57 AM, Stefan Richter <st...@s5...> wrote: > On Dec 17 Carl Karsten wrote: >> same hardware, but new flavor of problem: 2 controllers in one box, >> cable looped from one to the other. (it is the 2m cable that seems to >> cause the "isochronous cycle inconsistent" in the other thread. > > I don't think it causes the isoch cycle inconsistency, the topology change > does. See Clemens' explanation. It may however cause the Configuration > ROM read failure. > >> juser@pc8:~$ ls /dev/fw? >> /dev/fw0 /dev/fw1 /dev/fw2 >> >> juser@pc8:~$ uname -a >> Linux pc8 3.2.0-4-generic #10-Ubuntu SMP Sat Dec 10 17:46:09 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux >> >> juser@pc8:~$ dmesg |grep fire >> >> [ 1.935578] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 >> [ 1.988295] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 >> [ 1.988453] firewire_ohci: isochronous cycle inconsistent >> [ 1.993092] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 >> [ 1.993098] firewire_ohci 0000:04:00.0: setting latency timer to 64 >> [ 2.051121] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 >> [ 2.051204] firewire_ohci: isochronous cycle inconsistent >> [ 2.488158] firewire_core: created device fw0: GUID 00241b00964cac00, S400 >> [ 2.552154] firewire_core: created device fw1: GUID 0108000000006351, S800 >> [ 23.608055] firewire_ohci: AT spd 0 tl 06, ffc1 -> ffc0, ack_pending , QR req, fffff0000400 > > With firewire-ohci debug=3, there should be a few log lines from the > self-ID reception DMA between the two last lines above. Why are they > missing? wold the log lines contain "firewire"? If not, that's why they are missing, to keep the dmesg post under 50K. anything else I should include? > > (By the way, I have a patch here waiting to be posted which adds device > prefixes to firewire-ohci's debug messages --- for us folk who have more > than one controller in the PC and wonder which controller is emitting > what messages.) My one and only accepted kernel contribution is the same thing for a v4l device. > >> [ 23.608064] firewire_ohci: AR spd 0 tl 06, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 >> [ 23.608083] firewire_ohci: AT spd 0 tl 07, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 >> [ 23.608090] firewire_ohci: AR spd 0 tl 07, ffc0 -> ffc1, ack_complete, QR resp = 31333934 >> [ 23.608128] firewire_ohci: AT spd 0 tl 08, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 >> [ 23.608135] firewire_ohci: AR spd 0 tl 08, ffc0 -> ffc1, ack_complete, QR resp = f000a222 >> [ 23.608160] firewire_ohci: AT spd 0 tl 09, ffc1 -> ffc0, ack_pending , QR req, fffff000040c >> [ 23.608167] firewire_ohci: AR spd 0 tl 09, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 >> [ 23.608192] firewire_ohci: AT spd 0 tl 0a, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 >> [ 23.608199] firewire_ohci: AR spd 0 tl 0a, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 >> [ 23.608232] firewire_ohci: AT spd 2 tl 0b, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 >> [ 23.648054] firewire_ohci: AT spd 0 tl 04, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 >> [ 23.648064] firewire_ohci: AR spd 0 tl 04, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d >> [ 23.648092] firewire_ohci: AT spd 0 tl 05, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 >> [ 23.648099] firewire_ohci: AR spd 0 tl 05, ffc1 -> ffc0, ack_complete, QR resp = 31333934 >> [ 23.648133] firewire_ohci: AT spd 0 tl 06, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 >> [ 23.648140] firewire_ohci: AR spd 0 tl 06, ffc1 -> ffc0, ack_complete, QR resp = f000b223 >> [ 23.648165] firewire_ohci: AT spd 0 tl 07, ffc0 -> ffc1, ack_pending , QR req, fffff000040c >> [ 23.648171] firewire_ohci: AR spd 0 tl 07, ffc1 -> ffc0, ack_complete, QR resp = 01080000 >> [ 23.648196] firewire_ohci: AT spd 0 tl 08, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 >> [ 23.648203] firewire_ohci: AR spd 0 tl 08, ffc1 -> ffc0, ack_complete, QR resp = 00006351 >> [ 23.648229] firewire_ohci: AT spd 2 tl 09, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 > [...] >> [ 32.632258] firewire_ohci: AT spd 2 tl 1d, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 >> [ 32.632272] firewire_core: giving up on config rom for node id ffc0 >> [ 32.672061] firewire_ohci: AR spd 0 tl 16, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d >> [ 32.672068] firewire_ohci: AT spd 0 tl 16, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 >> [ 32.672109] firewire_ohci: AR spd 0 tl 17, ffc1 -> ffc0, ack_complete, QR resp = 31333934 >> [ 32.672116] firewire_ohci: AT spd 0 tl 17, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404 >> [ 32.672142] firewire_ohci: AT spd 0 tl 18, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 >> [ 32.672150] firewire_ohci: AR spd 0 tl 18, ffc1 -> ffc0, ack_complete, QR resp = f000b223 >> [ 32.672173] firewire_ohci: AT spd 0 tl 19, ffc0 -> ffc1, ack_pending , QR req, fffff000040c >> [ 32.672179] firewire_ohci: AR spd 0 tl 19, ffc1 -> ffc0, ack_complete, QR resp = 01080000 >> [ 32.672204] firewire_ohci: AT spd 0 tl 1a, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 >> [ 32.672210] firewire_ohci: AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = 00006351 >> [ 32.672262] firewire_ohci: AT spd 2 tl 1b, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 >> [ 32.672269] firewire_core: giving up on config rom for node id ffc1 > > Up to this point, the S800 controller fails to read from the S400 > controller, and the S400 controller fails to read from the S800 > controller, always with the read request to the 6th quadlet of the > Configuration ROM, always at S400 ( = "spd 2", whereas the first 5 > quadlets are always successfully read at S100 = "spd 0"), always with > transaction failure due to missing ACK in the request subaction. > > Im my experience, an "evt_missing_ack" can occur > - with an electrically unstable bus, e.g. caused by a bad cable, > - if the gap count at one or more nodes is too low, > - if a packet is sent at a larger speed than the peer node (or any > repeater node between sender and receiver) can handle. > > Gap count /should/ not be the issue here, because both PHYs were just > switched on and are supposed to feature a gap count of 63, which is the > power reset value and the absolute maximum. > > A mismatch of transmission speed vs. supported speed cannot be the issue > here, according to your log from after reboot (below). > > By the way, firewire-core always reads the first 5 quadlets ( = one header > quadlet and the four quadlets of bus information of the Configuration ROM > register) only at S100 as the only speed that is guaranteed to be > supported. The rest of the Configuration ROM is read at a higher speed > which is either determined from self-ID data of all PHYs and link speed > from the bus information block (the latter taken with a grain of salt; > this is not the actual link speed but the one that the firmware writer is > wanting us to believe) or determined from a speed probe, using read tests > at fffff0000400 at several speeds. In case of your two particular cards > plugged together, firewire-core does not perform a speed probe but decides > that both devices can talk to each other at S400. > > After the above, one of the two nodes performs bus management, > particularly decides to switch all PHYs to a lower gap count to increase > asynchronous bandwidth: > >> [ 32.672275] firewire_core: phy config: card 0, new root=ffc0, gap_count=5 >> [ 32.672295] firewire_ohci: AT ack_complete, PHY 00c50000 ff3affff >> [ 32.672299] firewire_ohci: AR ack_complete, PHY 00c50000 ff3affff >> [ 32.672324] firewire_ohci: AR evt_bus_reset, generation 5 >> [ 32.672327] firewire_ohci: AR evt_bus_reset, generation 3 >> [ 32.672335] firewire_ohci: 2 selfIDs, generation 5, local node ID ffc0 >> [ 32.672339] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc >> [ 32.672342] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci >> [ 32.672356] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc1 >> [ 32.672359] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc >> [ 32.672362] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci > > This involves transmission of a PHY packet by one node, reception of that > packet by the other one, bus reset by the former node, and self-ID > reception by both nodes. Then there is arbitration for bus manager role, > with ffc0 as requester and ffc1 (which is the IRM) as responder: > >> [ 32.928047] firewire_ohci: AR spd 0 tl 1e, ffc1 -> ffc0, ack_complete, Lk resp 4,2 >> [ 32.928052] firewire_ohci: AT spd 0 tl 1e, ffc0 -> ffc1, pending/cancelled, Lk req, fffff000021c 8,2 > > The fact that node ffc1 (phy 1) issued a bus reset is taken as a signal to > firewire-core on node ffc0 (phy 0) to re-read the Configuration ROM of > node ffc1: > >> [ 33.172042] firewire_ohci: AR spd 0 tl 1f, ffc1 -> ffc0, ack_complete, QR resp = 0404e334 >> [ 33.172047] firewire_ohci: AT spd 0 tl 1f, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 >> [ 33.172070] firewire_ohci: AT spd 0 tl 20, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 >> [ 33.172078] firewire_ohci: AR spd 0 tl 20, ffc1 -> ffc0, ack_complete, QR resp = 31333934 >> [ 33.172097] firewire_ohci: AR spd 0 tl 21, ffc1 -> ffc0, ack_complete, QR resp = f000a222 >> [ 33.172102] firewire_ohci: AT spd 0 tl 21, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000408 >> [ 33.172121] firewire_ohci: AT spd 0 tl 22, ffc0 -> ffc1, ack_pending , QR req, fffff000040c >> [ 33.172128] firewire_ohci: AR spd 0 tl 22, ffc1 -> ffc0, ack_complete, QR resp = 00241b00 >> [ 33.172148] firewire_ohci: AR spd 0 tl 23, ffc1 -> ffc0, ack_complete, QR resp = 964cac00 >> [ 33.172152] firewire_ohci: AT spd 0 tl 23, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000410 >> [ 33.172170] firewire_ohci: AR spd 2 tl 24, ffc1 -> ffc0, ack_complete, QR resp = 0005dd0b >> [ 33.172174] firewire_ohci: AT spd 2 tl 24, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000414 >> [ 33.172192] firewire_ohci: AT spd 2 tl 25, ffc0 -> ffc1, ack_pending , QR req, fffff0000418 >> [ 33.172199] firewire_ohci: AR spd 2 tl 25, ffc1 -> ffc0, ack_complete, QR resp = 0c0083c0 >> [ 33.172217] firewire_ohci: AT spd 2 tl 26, ffc0 -> ffc1, ack_pending , QR req, fffff000041c >> [ 33.172224] firewire_ohci: AR spd 2 tl 26, ffc1 -> ffc0, ack_complete, QR resp = 03d00d1e > [...] >> [ 33.172531] firewire_ohci: AT spd 2 tl 33, ffc0 -> ffc1, ack_pending , QR req, fffff0000440 >> [ 33.172537] firewire_ohci: AR spd 2 tl 33, ffc1 -> ffc0, ack_complete, QR resp = 72657769 >> [ 33.172555] firewire_ohci: AT spd 2 tl 34, ffc0 -> ffc1, ack_pending , QR req, fffff0000444 >> [ 33.172562] firewire_ohci: AR spd 2 tl 34, ffc1 -> ffc0, ack_complete, QR resp = 72650000 >> [ 33.172679] firewire_core: created device fw2: GUID 00241b00964cac00, S400 > > Curiously, now all of the Configuration ROM can be read without incident! > >> [ 33.172698] firewire_ohci: AT spd 2 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 >> [ 33.172704] firewire_ohci: AR spd 2 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 >> [ 33.172724] firewire_ohci: AR spd 2 tl 35, ffc1 -> ffc0, ack_complete, QR resp = c000001f >> [ 33.172729] firewire_ohci: AT spd 2 tl 35, ffc1 -> ffc0, ack_complete, QR resp = c000001f >> [ 33.172753] firewire_ohci: AT spd 2 tl 36, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f >> [ 33.172758] firewire_ohci: AR spd 2 tl 36, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f >> [ 33.172776] firewire_ohci: AR spd 2 tl 36, ffc1 -> ffc0, ack_complete, W resp >> [ 33.172781] firewire_ohci: AT spd 2 tl 36, ffc1 -> ffc0, ack_complete, W resp >> [ 33.172804] firewire_ohci: AT spd 0 tl 37, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2 >> [ 33.172811] firewire_ohci: AR spd 0 tl 37, ffc1 -> ffc0, ack_complete, Lk resp 4,2 > > These lines show a few requests from ffc0 to ffc1 and their responses, > which are routinely done when firewire-core probed a new node. Again no > missing ACK anymore. > > Carl, > can you try this once more and check which gap counts are reported in the > self ID reception event right after you plugged the cable in == right > before the nodes unsuccessfully attempt to get each other's Configuration > ROM? > [ 2.040261] firewire_core: phy config: card 1, new root=ffc1, gap_count=5 > Furthermore, tell us whether you end up with two or three /dev/fw* again > (i.e. whether neither node succeeded to probe the other, or one of them > succeeded to probe the other). So I have been gathering stats on what seams to do what. What I really need is a way to un/plug the firewire cable, and hit the power button. (which isn't out of the question given Jason is a friend of mine: http://www.ubergizmo.com/2011/10/robot-plays-angry-birds) Till then, we have my scripts and occasional human interaction. I am doing the best I can to keep the hardware in a consistent state: same laptop, pcie card, cable, network, etc. and not moving things around, so the cable is always in the same proximity to the laptop power supply and lcd. given the results I have seen, I don't think the cable is picking up noise. I would hope that it isn't susceptible to such sources. I have the box looping: # /etc/rc.local printf "$(date --rfc-3339=ns)" >> /home/juser/fwx.txt ls -C /dev/fw? >> /home/juser/fwx.txt reboot which gives me: 2011-12-18 13:41:37.406091760-06:00 /dev/fw0 /dev/fw1 /dev/fw2 2011-12-18 13:44:59.911457999-06:00 /dev/fw0 /dev/fw1 ... 2011-12-18 14:10:03.532900719-06:00 /dev/fw0 /dev/fw1 2011-12-18 14:13:50.814516139-06:00 /dev/fw0 /dev/fw1 After 6 hours of this, still just fw0 and 1. If I run shutdown, then hit the 'power' button, (which I have done 10+ times) it seems (I am not taking careful notes on this one) that seems to inject some randomness that causes it to maybe change from 0,1,2 connections being completed. If I then run the log/reboot loop, it goes back to just fw0,1 (0 connections). un/re plugging the firewire cable also seems to have the same random 0,1,2 connections. > Then, run either gscanbus seems pretty buggy. should I try and report bugs given the unstable state of my box? > or firecontrol http://firecontrol.svn.sourceforge.net/viewvc/firecontrol/trunk/ configure.in ... how do I automake configure? anyone around here able to make a .deb for this? Then I can stick it in my ppa and apt-get it when needed. I'll even push it into the debconf-video team land and see if it can get into the propper repos. > on _each_ "port" and use it to trigger a bus reset, then watch if this > results in all four expected /dev/fw* becoming available. > >> rebooted, now both ends show up: >> >> >> juser@pc8:~$ dmesg |grep fire > [...] >> [ 2.125123] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 >> [ 2.125154] firewire_ohci: isochronous cycle inconsistent >> [ 2.568156] firewire_core: created device fw0: GUID 00241b00964cac00, S400 >> [ 2.568172] firewire_core: phy config: card 0, new root=ffc1, gap_count=5 >> [ 2.624160] firewire_core: created device fw1: GUID 0108000000006351, S800 >> [ 2.624724] firewire_core: created device fw2: GUID 00241b00964cac00, S400 >> [ 5.576653] firewire_core: created device fw3: GUID 0108000000006351, S400, 1 config ROM retries >> >> juser@pc8:~$ ls /dev/fw? >> /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3 > > The "1 config ROM retries" is a hint that the connection still is not > fully stable. > -- > Stefan Richter > -=====-==-== ==-- =--=- > http://arcgraph.de/sr/ -- Carl K |
|
From: Stefan R. <st...@s5...> - 2011-12-19 21:59:28
|
On Dec 18 Carl Karsten wrote:
> On Sun, Dec 18, 2011 at 7:57 AM, Stefan Richter
> <st...@s5...> wrote:
> > On Dec 17 Carl Karsten wrote:
> >> [ 2.051121] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10
> >> [ 2.051204] firewire_ohci: isochronous cycle inconsistent
> >> [ 2.488158] firewire_core: created device fw0: GUID 00241b00964cac00, S400
> >> [ 2.552154] firewire_core: created device fw1: GUID 0108000000006351, S800
> >> [ 23.608055] firewire_ohci: AT spd 0 tl 06, ffc1 -> ffc0, ack_pending , QR req, fffff0000400
> >
> > With firewire-ohci debug=3, there should be a few log lines from the
> > self-ID reception DMA between the two last lines above. Why are they
> > missing?
>
> wold the log lines contain "firewire"? If not, that's why they are
> missing, to keep the dmesg post under 50K. anything else I should
> include?
A selfID-complete event is logged like this if debug flag 2 is specified
(i.e. fw-ohci's debug parameter is 2 or 3 or 6 or 7, etc.):
> >> [ 32.672335] firewire_ohci: 2 selfIDs, generation 5, local node ID ffc0
> >> [ 32.672339] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc
> >> [ 32.672342] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci
First there is the line with how many selfID packets were received in
which bus generation, and which ID the local node has in this bus
generation.
Then each self ID packet is logged; can be 1 or 2 per node (or more, but
all PHYs that are on the market have <= 6 ports and hence emit <= 2 selfID
packets). Each line contains packet type ("0" or "n", depending on how
many selfID packets a PHY emits), the entire packet content, the PHY ID,
the population with ports ("." port not present, "-" port not connected,
"c" port connected to child node, "p" port connected to parent node),
speed code of the PHY, gap count, power class, "L" if the "active link
layer" bit is set, "c" if the "contender for IRM role" bit is set, "i" if
the "initiated this bus reset" bit is set.
Here is an example of a somewhat more crowded bus, with PHY 9 being a
6-port 1394a PHY and the rest being a bunch of 3-port 1394b PHYs. Most of
them happen to be repeaters without link layer or storage devices with
powered-down link layer.
firewire_ohci: 13 selfIDs, generation 3, local node ID ffcb
firewire_ohci: selfID 0: 807fc094, phy 0 [p--] beta gc=63 +0W L
firewire_ohci: selfID 0: 813fc478, phy 1 [-cp] beta gc=63 -3W
firewire_ohci: selfID 0: 823fc458, phy 2 [--p] beta gc=63 -3W
firewire_ohci: selfID 0: 833fc464, phy 3 [-p-] beta gc=63 -3W
firewire_ohci: selfID 0: 843fc4f8, phy 4 [ccp] beta gc=63 -3W
firewire_ohci: selfID 0: 857fc458, phy 5 [--p] beta gc=63 -3W L
firewire_ohci: selfID 0: 863fc49c, phy 6 [p-c] beta gc=63 -3W
firewire_ohci: selfID 0: 873fc4bc, phy 7 [pcc] beta gc=63 -3W
firewire_ohci: selfID 0: 883fc4ec, phy 8 [cpc] beta gc=63 -3W
firewire_ohci: selfID 0: 893f8455, phy 9 [---] S400 gc=63 -3W
firewire_ohci: selfID n: 89819000, phy 9 [-p-.....]
firewire_ohci: selfID 0: 8a7fc4e6, phy 10 [cp-] beta gc=63 -3W Li
firewire_ohci: selfID 0: 8b7fccf4, phy 11 [cc-] beta gc=63 -3W Lc
The very last selfID is the one of the root node; its ports can only be
connected to child nodes. The very first PHY (the one with the lowest ID)
can only be connected to one parent node. Each other node can only be
connected to one parent and 0..many child nodes.
SelfID packets are autonomously generated by the PHY hardware. Some bits
in the selfID (like the L and c bits and the power class) are controlled
by hardwired pins or by pins connected to the link layer controller and are
therefore susceptible to the occasional mistake by board designers. E.g.
the power class is often wrong, hence the Linux drivers ignore it.
--
Stefan Richter
-=====-==-== ==-- =--==
http://arcgraph.de/sr/
|
|
From: Carl K. <ca...@pe...> - 2011-12-19 18:32:48
|
On Mon, Dec 19, 2011 at 12:20 PM, Carl Karsten <ca...@pe...> wrote: > On Sun, Dec 18, 2011 at 7:57 AM, Stefan Richter > <st...@s5...> wrote: >> Furthermore, tell us whether you end up with two or three /dev/fw* again >> (i.e. whether neither node succeeded to probe the other, or one of them >> succeeded to probe the other). Then, run either gscanbus or firecontrol >> on _each_ "port" and use it to trigger a bus reset, then watch if this >> results in all four expected /dev/fw* becoming available. juser@pc8:~$ ls /dev/fw? /dev/fw0 /dev/fw1 /dev/fw2 juser@pc8:~/firecontrol$ sudo ./firecontrol 0 firecontrol trunk_20111218 Copyright (C) 2002-2007 by Manfred Weihs <mw...@us...> This software comes with absolutely no warranty. successfully got handle current generation number (driver): 0 2 card(s) found nodes on bus: 2, card name: /dev/fw2 nodes on bus: 2, card name: /dev/fw0 using adapter 0 found: 2 nodes on bus, local ID is 0, IRM is 1 current generation number (adapter): 2 entering command mode Type 'help' for more information! Command: br successfully reset the bus (long bus reset) Command: bus reset occurred. new generation number: 3, 2 nodes on the bus, local ID: 0 juser@pc8:~/firecontrol$ ls /dev/fw? /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3 juser@pc8:~/firecontrol$ dmesg | grep fire | xclip [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-4-generic root=UUID=b5c83a0b-baed-4a8b-a828-b65be5fe3d29 ro firewire-ohci.debug=3 [ 0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-4-generic root=UUID=b5c83a0b-baed-4a8b-a828-b65be5fe3d29 ro firewire-ohci.debug=3 [ 0.173416] pci 0000:02:05.0: proprietary Ricoh MMC controller disabled (via firewire function) [ 1.229598] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 [ 1.284106] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 [ 1.284223] firewire_ohci: AR evt_bus_reset, generation 1 [ 1.284317] firewire_ohci: 2 selfIDs, generation 1, local node ID ffc0 [ 1.284382] firewire_ohci: selfID 0: 807f8882, phy 0 [p..] S400 gc=63 +0W Lci [ 1.284447] firewire_ohci: selfID 0: 813fc4d4, phy 1 [c--] beta gc=63 -3W [ 1.284599] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 [ 1.284678] firewire_ohci 0000:04:00.0: setting latency timer to 64 [ 1.340283] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 [ 1.340367] firewire_ohci: isochronous cycle inconsistent [ 1.340460] firewire_ohci: AR evt_bus_reset, generation 1 [ 1.340462] firewire_ohci: AR evt_bus_reset, generation 2 [ 1.340495] firewire_ohci: 2 selfIDs, generation 2, local node ID ffc0 [ 1.340499] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc [ 1.340502] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci [ 1.340530] firewire_ohci: AT spd 0 tl 01, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2 [ 1.340540] firewire_ohci: AR spd 0 tl 01, ffc1 -> ffc0, ack_complete, Lk resp 4,2 [ 1.340948] firewire_ohci: 2 selfIDs, generation 1, local node ID ffc1 [ 1.341028] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc [ 1.341095] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci [ 1.784094] firewire_ohci: AT spd 0 tl 18, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 [ 1.784177] firewire_ohci: AR spd 0 tl 18, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 1.784273] firewire_ohci: AT spd 0 tl 19, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 1.784352] firewire_ohci: AR spd 0 tl 19, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 1.786888] firewire_core: created device fw0: GUID 00241b00964cac00, S400 [ 1.786957] firewire_ohci: AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 1.787034] firewire_ohci: AT spd 0 tl 1a, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000408 [ 1.787151] firewire_ohci: AR spd 0 tl 1c, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 1.787227] firewire_ohci: AT spd 0 tl 1c, ffc0 -> ffc1, pending/cancelled, QR req, fffff000040c [ 1.787323] firewire_ohci: AT spd 0 tl 1e, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 1.787402] firewire_ohci: AR spd 0 tl 1e, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 1.787511] firewire_ohci: AT spd 2 tl 1f, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 1.840100] firewire_ohci: AR spd 0 tl 18, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 1.840183] firewire_ohci: AT spd 0 tl 18, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 1.840285] firewire_ohci: AT spd 0 tl 19, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 1.840364] firewire_ohci: AR spd 0 tl 19, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 1.840462] firewire_core: created device fw1: GUID 0108000000006351, S800 [ 1.840546] firewire_ohci: AT spd 0 tl 1c, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 1.840625] firewire_ohci: AR spd 0 tl 1c, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 1.840719] firewire_ohci: AT spd 0 tl 1f, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 1.840799] firewire_ohci: AR spd 0 tl 1f, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 1.840902] firewire_ohci: AR spd 0 tl 20, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 1.840979] firewire_ohci: AT spd 0 tl 20, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000410 [ 1.841082] firewire_ohci: AT spd 2 tl 21, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 4.792051] firewire_ohci: AR spd 0 tl 20, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 4.792134] firewire_ohci: AT spd 0 tl 20, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 4.792233] firewire_ohci: AT spd 0 tl 21, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 4.792313] firewire_ohci: AR spd 0 tl 21, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 4.792410] firewire_ohci: AT spd 0 tl 22, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 4.792489] firewire_ohci: AR spd 0 tl 22, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 4.792586] firewire_ohci: AT spd 0 tl 23, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 4.792665] firewire_ohci: AR spd 0 tl 23, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 4.792772] firewire_ohci: AT spd 0 tl 24, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 4.792852] firewire_ohci: AR spd 0 tl 24, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 4.792960] firewire_ohci: AT spd 2 tl 25, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 4.848043] firewire_ohci: AR spd 0 tl 22, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 4.848120] firewire_ohci: AT spd 0 tl 22, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 4.848215] firewire_ohci: AT spd 0 tl 23, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 4.848294] firewire_ohci: AR spd 0 tl 23, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 4.848399] firewire_ohci: AT spd 0 tl 24, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 4.848477] firewire_ohci: AR spd 0 tl 24, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 4.848571] firewire_ohci: AR spd 0 tl 25, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 4.848647] firewire_ohci: AT spd 0 tl 25, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 4.848741] firewire_ohci: AT spd 0 tl 26, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 4.848820] firewire_ohci: AR spd 0 tl 26, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 4.848923] firewire_ohci: AT spd 2 tl 27, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 7.800058] firewire_ohci: AT spd 0 tl 26, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 [ 7.800143] firewire_ohci: AR spd 0 tl 26, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 7.800242] firewire_ohci: AT spd 0 tl 27, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 7.800321] firewire_ohci: AR spd 0 tl 27, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 7.800419] firewire_ohci: AT spd 0 tl 28, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 7.800498] firewire_ohci: AR spd 0 tl 28, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 7.800594] firewire_ohci: AT spd 0 tl 29, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 7.800673] firewire_ohci: AR spd 0 tl 29, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 7.800781] firewire_ohci: AT spd 0 tl 2a, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 7.800860] firewire_ohci: AR spd 0 tl 2a, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 7.800968] firewire_ohci: AT spd 2 tl 2b, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 7.856047] firewire_ohci: AR spd 0 tl 28, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 7.856123] firewire_ohci: AT spd 0 tl 28, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 7.856218] firewire_ohci: AT spd 0 tl 29, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 7.856297] firewire_ohci: AR spd 0 tl 29, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 7.856397] firewire_ohci: AT spd 0 tl 2a, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 7.856476] firewire_ohci: AR spd 0 tl 2a, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 7.856570] firewire_ohci: AT spd 0 tl 2b, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 7.856649] firewire_ohci: AR spd 0 tl 2b, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 7.856743] firewire_ohci: AT spd 0 tl 2c, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 7.856822] firewire_ohci: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 7.856924] firewire_ohci: AT spd 2 tl 2d, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 10.808059] firewire_ohci: AR spd 0 tl 2c, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 10.808142] firewire_ohci: AT spd 0 tl 2c, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 10.808242] firewire_ohci: AT spd 0 tl 2d, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 10.808323] firewire_ohci: AR spd 0 tl 2d, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 10.808420] firewire_ohci: AT spd 0 tl 2e, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 10.808499] firewire_ohci: AR spd 0 tl 2e, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 10.808596] firewire_ohci: AT spd 0 tl 2f, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 10.808675] firewire_ohci: AR spd 0 tl 2f, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 10.808778] firewire_ohci: AT spd 0 tl 30, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 10.808857] firewire_ohci: AR spd 0 tl 30, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 10.808986] firewire_ohci: AT spd 2 tl 31, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 10.864044] firewire_ohci: AR spd 0 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 10.864120] firewire_ohci: AT spd 0 tl 2e, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 10.864214] firewire_ohci: AT spd 0 tl 2f, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 10.864293] firewire_ohci: AR spd 0 tl 2f, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 10.864394] firewire_ohci: AR spd 0 tl 30, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 10.864470] firewire_ohci: AT spd 0 tl 30, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 [ 10.864565] firewire_ohci: AR spd 0 tl 31, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 10.864641] firewire_ohci: AT spd 0 tl 31, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 10.864770] firewire_ohci: AT spd 0 tl 32, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 10.864849] firewire_ohci: AR spd 0 tl 32, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 10.864951] firewire_ohci: AT spd 2 tl 33, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 13.816069] firewire_ohci: AR spd 0 tl 32, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 13.816151] firewire_ohci: AT spd 0 tl 32, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 13.816265] firewire_ohci: AT spd 0 tl 33, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 13.816345] firewire_ohci: AR spd 0 tl 33, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 13.818891] firewire_ohci: AT spd 0 tl 34, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 13.818970] firewire_ohci: AR spd 0 tl 34, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 13.819067] firewire_ohci: AT spd 0 tl 35, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 13.819146] firewire_ohci: AR spd 0 tl 35, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 13.819244] firewire_ohci: AT spd 0 tl 36, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 13.819322] firewire_ohci: AR spd 0 tl 36, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 13.819431] firewire_ohci: AT spd 2 tl 37, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 13.872042] firewire_ohci: AR spd 0 tl 34, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 13.872118] firewire_ohci: AT spd 0 tl 34, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 13.872213] firewire_ohci: AR spd 0 tl 35, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 13.872289] firewire_ohci: AT spd 0 tl 35, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 13.872391] firewire_ohci: AT spd 0 tl 36, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 13.872471] firewire_ohci: AR spd 0 tl 36, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 13.872565] firewire_ohci: AT spd 0 tl 37, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 13.872644] firewire_ohci: AR spd 0 tl 37, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 13.872738] firewire_ohci: AR spd 0 tl 38, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 13.872813] firewire_ohci: AT spd 0 tl 38, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000410 [ 13.872917] firewire_ohci: AT spd 2 tl 39, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 16.824060] firewire_ohci: AR spd 0 tl 38, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 16.824142] firewire_ohci: AT spd 0 tl 38, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 16.824242] firewire_ohci: AT spd 0 tl 39, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 16.824322] firewire_ohci: AR spd 0 tl 39, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 16.824418] firewire_ohci: AT spd 0 tl 3a, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 16.824497] firewire_ohci: AR spd 0 tl 3a, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 16.824594] firewire_ohci: AT spd 0 tl 3b, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 16.824673] firewire_ohci: AR spd 0 tl 3b, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 16.824773] firewire_ohci: AT spd 0 tl 3c, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 16.824852] firewire_ohci: AR spd 0 tl 3c, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 16.824961] firewire_ohci: AT spd 2 tl 3d, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 16.880044] firewire_ohci: AR spd 0 tl 3a, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 16.880120] firewire_ohci: AT spd 0 tl 3a, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 16.880214] firewire_ohci: AT spd 0 tl 3b, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 16.880293] firewire_ohci: AR spd 0 tl 3b, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 16.880389] firewire_ohci: AR spd 0 tl 3c, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 16.880466] firewire_ohci: AT spd 0 tl 3c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 [ 16.880560] firewire_ohci: AR spd 0 tl 3d, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 16.880639] firewire_ohci: AT spd 0 tl 3d, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 16.880733] firewire_ohci: AT spd 0 tl 3e, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 16.880812] firewire_ohci: AR spd 0 tl 3e, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 16.880914] firewire_ohci: AT spd 2 tl 3f, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 19.832057] firewire_ohci: AR spd 0 tl 3e, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 19.832064] firewire_ohci: AT spd 0 tl 3e, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 19.832091] firewire_ohci: AT spd 0 tl 3f, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 19.832099] firewire_ohci: AR spd 0 tl 3f, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 19.832138] firewire_ohci: AT spd 0 tl 00, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 19.832145] firewire_ohci: AR spd 0 tl 00, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 19.832168] firewire_ohci: AT spd 0 tl 01, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 19.832175] firewire_ohci: AR spd 0 tl 01, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 19.832199] firewire_ohci: AT spd 0 tl 02, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 19.832206] firewire_ohci: AR spd 0 tl 02, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 19.832242] firewire_ohci: AT spd 2 tl 03, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 19.888047] firewire_ohci: AR spd 0 tl 00, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 19.888054] firewire_ohci: AT spd 0 tl 00, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 19.888075] firewire_ohci: AT spd 0 tl 01, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 19.888083] firewire_ohci: AR spd 0 tl 01, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 19.888107] firewire_ohci: AT spd 0 tl 02, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 19.888114] firewire_ohci: AR spd 0 tl 02, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 19.888147] firewire_ohci: AT spd 0 tl 03, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 19.888154] firewire_ohci: AR spd 0 tl 03, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 19.888179] firewire_ohci: AT spd 0 tl 04, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 19.888186] firewire_ohci: AR spd 0 tl 04, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 19.888220] firewire_ohci: AT spd 2 tl 05, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 22.840064] firewire_ohci: AR spd 0 tl 04, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 22.840071] firewire_ohci: AT spd 0 tl 04, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 22.840096] firewire_ohci: AT spd 0 tl 05, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 22.840105] firewire_ohci: AR spd 0 tl 05, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 22.840143] firewire_ohci: AT spd 0 tl 06, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 22.840150] firewire_ohci: AR spd 0 tl 06, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 22.840174] firewire_ohci: AT spd 0 tl 07, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 22.840180] firewire_ohci: AR spd 0 tl 07, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 22.840205] firewire_ohci: AT spd 0 tl 08, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 22.840211] firewire_ohci: AR spd 0 tl 08, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 22.840247] firewire_ohci: AT spd 2 tl 09, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 22.900057] firewire_ohci: AR spd 0 tl 06, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 22.900063] firewire_ohci: AT spd 0 tl 06, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 22.900085] firewire_ohci: AR spd 0 tl 07, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 22.900089] firewire_ohci: AT spd 0 tl 07, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 22.900117] firewire_ohci: AT spd 0 tl 08, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 22.900135] firewire_ohci: AR spd 0 tl 08, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 22.900164] firewire_ohci: AR spd 0 tl 09, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 22.900168] firewire_ohci: AT spd 0 tl 09, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 22.900195] firewire_ohci: AT spd 0 tl 0a, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 22.900203] firewire_ohci: AR spd 0 tl 0a, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 22.900236] firewire_ohci: AT spd 2 tl 0b, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 25.852064] firewire_ohci: AT spd 0 tl 0a, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 [ 25.852074] firewire_ohci: AR spd 0 tl 0a, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 25.852095] firewire_ohci: AT spd 0 tl 0b, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 25.852102] firewire_ohci: AR spd 0 tl 0b, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 25.852139] firewire_ohci: AT spd 0 tl 0c, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 25.852146] firewire_ohci: AR spd 0 tl 0c, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 25.852170] firewire_ohci: AT spd 0 tl 0d, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 25.852176] firewire_ohci: AR spd 0 tl 0d, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 25.852201] firewire_ohci: AT spd 0 tl 0e, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 25.852207] firewire_ohci: AR spd 0 tl 0e, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 25.852243] firewire_ohci: AT spd 2 tl 0f, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 25.904215] firewire_ohci: AR spd 0 tl 0c, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 25.904224] firewire_ohci: AT spd 0 tl 0c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 25.904262] firewire_ohci: AR spd 0 tl 0d, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 25.904266] firewire_ohci: AT spd 0 tl 0d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 25.904300] firewire_ohci: AR spd 0 tl 0e, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 25.904304] firewire_ohci: AT spd 0 tl 0e, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 [ 25.904336] firewire_ohci: AR spd 0 tl 0f, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 25.904339] firewire_ohci: AT spd 0 tl 0f, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 25.904388] firewire_ohci: AT spd 0 tl 10, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 25.904394] firewire_ohci: AR spd 0 tl 10, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 25.904431] firewire_ohci: AT spd 2 tl 11, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 28.856050] firewire_ohci: AR spd 0 tl 10, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 28.856057] firewire_ohci: AT spd 0 tl 10, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 28.856083] firewire_ohci: AT spd 0 tl 11, ffc0 -> ffc1, ack_pending , QR req, fffff0000404 [ 28.856090] firewire_ohci: AR spd 0 tl 11, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 28.856114] firewire_ohci: AT spd 0 tl 12, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 28.856120] firewire_ohci: AR spd 0 tl 12, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 28.856147] firewire_ohci: AT spd 0 tl 13, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 28.856154] firewire_ohci: AR spd 0 tl 13, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 28.856178] firewire_ohci: AT spd 0 tl 14, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 28.856185] firewire_ohci: AR spd 0 tl 14, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 28.856221] firewire_ohci: AT spd 2 tl 15, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 28.912047] firewire_ohci: AR spd 0 tl 12, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 28.912052] firewire_ohci: AT spd 0 tl 12, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 28.912074] firewire_ohci: AR spd 0 tl 13, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 28.912078] firewire_ohci: AT spd 0 tl 13, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 28.912106] firewire_ohci: AT spd 0 tl 14, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 28.912125] firewire_ohci: AR spd 0 tl 14, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 28.912153] firewire_ohci: AT spd 0 tl 15, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 28.912160] firewire_ohci: AR spd 0 tl 15, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 28.912185] firewire_ohci: AT spd 0 tl 16, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 28.912192] firewire_ohci: AR spd 0 tl 16, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 28.912225] firewire_ohci: AT spd 2 tl 17, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 [ 31.864079] firewire_ohci: AR spd 0 tl 16, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 31.864085] firewire_ohci: AT spd 0 tl 16, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 31.864123] firewire_ohci: AR spd 0 tl 17, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 31.864131] firewire_ohci: AT spd 0 tl 17, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404 [ 31.864170] firewire_ohci: AT spd 0 tl 18, ffc0 -> ffc1, ack_pending , QR req, fffff0000408 [ 31.864179] firewire_ohci: AR spd 0 tl 18, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 31.864206] firewire_ohci: AT spd 0 tl 19, ffc0 -> ffc1, ack_pending , QR req, fffff000040c [ 31.864213] firewire_ohci: AR spd 0 tl 19, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 31.864240] firewire_ohci: AT spd 0 tl 1a, ffc0 -> ffc1, ack_pending , QR req, fffff0000410 [ 31.864247] firewire_ohci: AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 31.864299] firewire_ohci: AT spd 2 tl 1b, ffc0 -> ffc1, evt_missing_ack, QR req, fffff0000414 [ 31.864311] firewire_core: giving up on config rom for node id ffc1 [ 31.864317] firewire_core: phy config: card 0, new root=ffc0, gap_count=5 [ 31.864335] firewire_ohci: AT ack_complete, PHY 00c50000 ff3affff [ 31.864353] firewire_ohci: AR ack_complete, PHY 00c50000 ff3affff [ 31.864380] firewire_ohci: AR evt_bus_reset, generation 2 [ 31.864383] firewire_ohci: AR evt_bus_reset, generation 3 [ 31.864398] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc1 [ 31.864402] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc [ 31.864405] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci [ 31.864418] firewire_ohci: 2 selfIDs, generation 2, local node ID ffc0 [ 31.864422] firewire_ohci: selfID 0: 8045cc94, phy 0 [p--] beta gc=5 -3W Lc [ 31.864425] firewire_ohci: selfID 0: 814588c2, phy 1 [c..] S400 gc=5 +0W Lci [ 31.920042] firewire_ohci: AR spd 0 tl 18, ffc1 -> ffc0, ack_complete, QR resp = 0404e334 [ 31.920048] firewire_ohci: AT spd 0 tl 18, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400 [ 31.920076] firewire_ohci: AR spd 0 tl 19, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 31.920081] firewire_ohci: AT spd 0 tl 19, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404 [ 31.920106] firewire_ohci: AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = f000a222 [ 31.920111] firewire_ohci: AT spd 0 tl 1a, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000408 [ 31.920139] firewire_ohci: AR spd 0 tl 1b, ffc1 -> ffc0, ack_complete, QR resp = 00241b00 [ 31.920143] firewire_ohci: AT spd 0 tl 1b, ffc0 -> ffc1, pending/cancelled, QR req, fffff000040c [ 31.920169] firewire_ohci: AR spd 0 tl 1c, ffc1 -> ffc0, ack_complete, QR resp = 964cac00 [ 31.920173] firewire_ohci: AT spd 0 tl 1c, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000410 [ 31.920198] firewire_ohci: AR spd 2 tl 1d, ffc1 -> ffc0, ack_complete, QR resp = 0005dd0b [ 31.920202] firewire_ohci: AT spd 2 tl 1d, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000414 [ 31.920227] firewire_ohci: AR spd 2 tl 1e, ffc1 -> ffc0, ack_complete, QR resp = 0c0083c0 [ 31.920231] firewire_ohci: AT spd 2 tl 1e, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000418 [ 31.920256] firewire_ohci: AR spd 2 tl 1f, ffc1 -> ffc0, ack_complete, QR resp = 03d00d1e [ 31.920260] firewire_ohci: AT spd 2 tl 1f, ffc0 -> ffc1, pending/cancelled, QR req, fffff000041c [ 31.920284] firewire_ohci: AR spd 2 tl 20, ffc1 -> ffc0, ack_complete, QR resp = 81000003 [ 31.920289] firewire_ohci: AT spd 2 tl 20, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000420 [ 31.920313] firewire_ohci: AR spd 2 tl 21, ffc1 -> ffc0, ack_complete, QR resp = 17000001 [ 31.920317] firewire_ohci: AT spd 2 tl 21, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000424 [ 31.920341] firewire_ohci: AR spd 2 tl 22, ffc1 -> ffc0, ack_complete, QR resp = 81000008 [ 31.920345] firewire_ohci: AT spd 2 tl 22, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000428 [ 31.920370] firewire_ohci: AT spd 2 tl 23, ffc0 -> ffc1, ack_pending , QR req, fffff0000448 [ 31.920378] firewire_ohci: AR spd 2 tl 23, ffc1 -> ffc0, ack_complete, QR resp = 0003ff1c [ 31.920402] firewire_ohci: AT spd 2 tl 24, ffc0 -> ffc1, ack_pending , QR req, fffff000044c [ 31.920410] firewire_ohci: AR spd 2 tl 24, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 31.920434] firewire_ohci: AR spd 2 tl 25, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 31.920438] firewire_ohci: AT spd 2 tl 25, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000450 [ 31.920462] firewire_ohci: AT spd 2 tl 26, ffc0 -> ffc1, ack_pending , QR req, fffff0000454 [ 31.920469] firewire_ohci: AR spd 2 tl 26, ffc1 -> ffc0, ack_complete, QR resp = 4a756a75 [ 31.920494] firewire_ohci: AT spd 2 tl 27, ffc0 -> ffc1, ack_pending , QR req, fffff000042c [ 31.920501] firewire_ohci: AR spd 2 tl 27, ffc1 -> ffc0, ack_complete, QR resp = 00064cb7 [ 31.920525] firewire_ohci: AT spd 2 tl 28, ffc0 -> ffc1, ack_pending , QR req, fffff0000430 [ 31.920532] firewire_ohci: AR spd 2 tl 28, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 31.920557] firewire_ohci: AT spd 2 tl 29, ffc0 -> ffc1, ack_pending , QR req, fffff0000434 [ 31.920564] firewire_ohci: AR spd 2 tl 29, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 31.920589] firewire_ohci: AT spd 2 tl 2a, ffc0 -> ffc1, ack_pending , QR req, fffff0000438 [ 31.920596] firewire_ohci: AR spd 2 tl 2a, ffc1 -> ffc0, ack_complete, QR resp = 4c696e75 [ 31.920620] firewire_ohci: AT spd 2 tl 2b, ffc0 -> ffc1, ack_pending , QR req, fffff000043c [ 31.920628] firewire_ohci: AR spd 2 tl 2b, ffc1 -> ffc0, ack_complete, QR resp = 78204669 [ 31.920652] firewire_ohci: AR spd 2 tl 2c, ffc1 -> ffc0, ack_complete, QR resp = 72657769 [ 31.920656] firewire_ohci: AT spd 2 tl 2c, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000440 [ 31.920681] firewire_ohci: AR spd 2 tl 2d, ffc1 -> ffc0, ack_complete, QR resp = 72650000 [ 31.920685] firewire_ohci: AT spd 2 tl 2d, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000444 [ 31.920814] firewire_core: created device fw2: GUID 00241b00964cac00, S400, 10 config ROM retries [ 31.920832] firewire_ohci: AT spd 2 tl 2e, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 [ 31.920837] firewire_ohci: AR spd 2 tl 2e, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 [ 31.920855] firewire_ohci: AR spd 2 tl 2e, ffc1 -> ffc0, ack_complete, QR resp = c000001f [ 31.920861] firewire_ohci: AT spd 2 tl 2e, ffc1 -> ffc0, ack_complete, QR resp = c000001f [ 31.920878] firewire_ohci: AT spd 2 tl 2f, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f [ 31.920884] firewire_ohci: AR spd 2 tl 2f, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f [ 31.920900] firewire_ohci: AR spd 2 tl 2f, ffc1 -> ffc0, ack_complete, W resp [ 31.920905] firewire_ohci: AT spd 2 tl 2f, ffc1 -> ffc0, ack_complete, W resp [ 32.120063] firewire_ohci: AR spd 0 tl 30, ffc1 -> ffc0, ack_complete, Lk resp 4,2 [ 32.120070] firewire_ohci: AT spd 0 tl 30, ffc0 -> ffc1, pending/cancelled, Lk req, fffff000021c 8,2 [ 256.468051] firewire_ohci: AT ack_complete, PHY 00450000 ffbaffff [ 256.468061] firewire_ohci: AR ack_complete, PHY 00450000 ffbaffff [ 256.468084] firewire_ohci: AR evt_bus_reset, generation 3 [ 256.468095] firewire_ohci: AR evt_bus_reset, generation 4 [ 256.468266] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc0 [ 256.468270] firewire_ohci: selfID 0: 8045cc96, phy 0 [p--] beta gc=5 -3W Lci [ 256.468275] firewire_ohci: 2 selfIDs, generation 4, local node ID ffc1 [ 256.468280] firewire_ohci: selfID 0: 8045cc96, phy 0 [p--] beta gc=5 -3W Lci [ 256.468285] firewire_ohci: selfID 0: 814588c0, phy 1 [c..] S400 gc=5 +0W Lc [ 256.468290] firewire_ohci: selfID 0: 814588c0, phy 1 [c..] S400 gc=5 +0W Lc [ 256.724091] firewire_ohci: AR spd 0 tl 37, ffc1 -> ffc0, ack_complete, Lk resp 4,2 [ 256.724107] firewire_ohci: AT spd 0 tl 37, ffc0 -> ffc1, pending/cancelled, Lk req, fffff000021c 8,2 [ 256.968134] firewire_ohci: AR spd 0 tl 28, ffc0 -> ffc1, ack_complete, QR resp = 0404fb9d [ 256.968152] firewire_ohci: AT spd 0 tl 28, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 256.968195] firewire_ohci: AR spd 0 tl 29, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 256.968206] firewire_ohci: AT spd 0 tl 29, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 256.968243] firewire_ohci: AR spd 0 tl 2a, ffc0 -> ffc1, ack_complete, QR resp = f000b223 [ 256.968253] firewire_ohci: AT spd 0 tl 2a, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 [ 256.968287] firewire_ohci: AR spd 0 tl 2b, ffc0 -> ffc1, ack_complete, QR resp = 01080000 [ 256.968296] firewire_ohci: AT spd 0 tl 2b, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 256.968330] firewire_ohci: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = 00006351 [ 256.968340] firewire_ohci: AT spd 0 tl 2c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000410 [ 256.968374] firewire_ohci: AR spd 2 tl 2d, ffc0 -> ffc1, ack_complete, QR resp = 0005dd0b [ 256.968384] firewire_ohci: AT spd 2 tl 2d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000414 [ 256.968416] firewire_ohci: AR spd 2 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = 0c0083c0 [ 256.968426] firewire_ohci: AT spd 2 tl 2e, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000418 [ 256.968459] firewire_ohci: AR spd 2 tl 2f, ffc0 -> ffc1, ack_complete, QR resp = 03d00d1e [ 256.968469] firewire_ohci: AT spd 2 tl 2f, ffc1 -> ffc0, pending/cancelled, QR req, fffff000041c [ 256.968501] firewire_ohci: AR spd 2 tl 30, ffc0 -> ffc1, ack_complete, QR resp = 81000003 [ 256.968511] firewire_ohci: AT spd 2 tl 30, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000420 [ 256.968544] firewire_ohci: AR spd 2 tl 31, ffc0 -> ffc1, ack_complete, QR resp = 17000001 [ 256.968554] firewire_ohci: AT spd 2 tl 31, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000424 [ 256.968586] firewire_ohci: AR spd 2 tl 32, ffc0 -> ffc1, ack_complete, QR resp = 81000008 [ 256.968596] firewire_ohci: AT spd 2 tl 32, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000428 [ 256.968628] firewire_ohci: AR spd 2 tl 33, ffc0 -> ffc1, ack_complete, QR resp = 0003ff1c [ 256.968638] firewire_ohci: AT spd 2 tl 33, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000448 [ 256.968670] firewire_ohci: AR spd 2 tl 34, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 256.968680] firewire_ohci: AT spd 2 tl 34, ffc1 -> ffc0, pending/cancelled, QR req, fffff000044c [ 256.968712] firewire_ohci: AR spd 2 tl 35, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 256.968722] firewire_ohci: AT spd 2 tl 35, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000450 [ 256.968754] firewire_ohci: AR spd 2 tl 36, ffc0 -> ffc1, ack_complete, QR resp = 4a756a75 [ 256.968764] firewire_ohci: AT spd 2 tl 36, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000454 [ 256.968796] firewire_ohci: AR spd 2 tl 37, ffc0 -> ffc1, ack_complete, QR resp = 00064cb7 [ 256.968806] firewire_ohci: AT spd 2 tl 37, ffc1 -> ffc0, pending/cancelled, QR req, fffff000042c [ 256.968838] firewire_ohci: AR spd 2 tl 38, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 256.968848] firewire_ohci: AT spd 2 tl 38, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000430 [ 256.968880] firewire_ohci: AR spd 2 tl 39, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 256.968890] firewire_ohci: AT spd 2 tl 39, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000434 [ 256.968922] firewire_ohci: AR spd 2 tl 3a, ffc0 -> ffc1, ack_complete, QR resp = 4c696e75 [ 256.968932] firewire_ohci: AT spd 2 tl 3a, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000438 [ 256.968965] firewire_ohci: AR spd 2 tl 3b, ffc0 -> ffc1, ack_complete, QR resp = 78204669 [ 256.968974] firewire_ohci: AT spd 2 tl 3b, ffc1 -> ffc0, pending/cancelled, QR req, fffff000043c [ 256.969007] firewire_ohci: AR spd 2 tl 3c, ffc0 -> ffc1, ack_complete, QR resp = 72657769 [ 256.969017] firewire_ohci: AT spd 2 tl 3c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000440 [ 256.969050] firewire_ohci: AR spd 2 tl 3d, ffc0 -> ffc1, ack_complete, QR resp = 72650000 [ 256.969060] firewire_ohci: AT spd 2 tl 3d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000444 [ 256.969494] firewire_core: created device fw3: GUID 0108000000006351, S400 [ 256.969522] firewire_ohci: AT spd 2 tl 3e, ffc1 -> ffc0, ack_pending , QR req, fffff0000234 [ 256.969546] firewire_ohci: AR spd 2 tl 3e, ffc1 -> ffc0, ack_pending , QR req, fffff0000234 [ 256.969591] firewire_ohci: AT spd 2 tl 3e, ffc0 -> ffc1, ack_complete, QR resp = c000001f [ 256.969602] firewire_ohci: AR spd 2 tl 3e, ffc0 -> ffc1, ack_complete, QR resp = c000001f [ 256.969640] firewire_ohci: AR spd 2 tl 3f, ffc1 -> ffc0, ack_pending , QW req, fffff0000234 = c000001f [ 256.969654] firewire_ohci: AT spd 2 tl 3f, ffc1 -> ffc0, ack_pending , QW req, fffff0000234 = c000001f [ 256.969686] firewire_ohci: AT spd 2 tl 3f, ffc0 -> ffc1, ack_complete, W resp [ 256.969701] firewire_ohci: AR spd 2 tl 3f, ffc0 -> ffc1, ack_complete, W resp -- Carl K |
|
From: Carl K. <ca...@pe...> - 2011-12-19 18:44:05
|
I rebooted, no connections came up. firecontrol on both, br, still no connections. juser@pc8:~/firecontrol$ sudo ./firecontrol 1 firecontrol trunk_20111218 Copyright (C) 2002-2007 by Manfred Weihs <mw...@us...> This software comes with absolutely no warranty. successfully got handle current generation number (driver): 0 2 card(s) found nodes on bus: 2, card name: /dev/fw1 nodes on bus: 2, card name: /dev/fw0 using adapter 1 found: 2 nodes on bus, local ID is 0, IRM is 1 current generation number (adapter): 3 entering command mode Type 'help' for more information! Command: br successfully reset the bus (long bus reset) Command: bus reset occurred. new generation number: 4, 2 nodes on the bus, local ID: 0 juser@pc8:~$ ls /dev/fw? /dev/fw0 /dev/fw1 juser@pc8:~/firecontrol$ sudo ./firecontrol 0 firecontrol trunk_20111218 Copyright (C) 2002-2007 by Manfred Weihs <mw...@us...> This software comes with absolutely no warranty. successfully got handle current generation number (driver): 0 2 card(s) found nodes on bus: 2, card name: /dev/fw1 nodes on bus: 2, card name: /dev/fw0 using adapter 0 found: 2 nodes on bus, local ID is 1, IRM is 1 current generation number (adapter): 4 entering command mode Type 'help' for more information! Command: br successfully reset the bus (long bus reset) juser@pc8:~$ ls /dev/fw? /dev/fw0 /dev/fw1 -- Carl K |
|
From: Stefan R. <st...@s5...> - 2011-12-19 21:25:33
|
On Dec 19 Carl Karsten wrote: > On Dec 19 Carl Karsten wrote: > > On Mon, Dec 19, 2011 at 12:20 PM, Carl Karsten > > <ca...@pe...> wrote: > > > On Sun, Dec 18, 2011 at 7:57 AM, Stefan Richter > > > <st...@s5...> wrote: > > >> Furthermore, tell us whether you end up with two or three /dev/fw* > > >> again (i.e. whether neither node succeeded to probe the other, or > > >> one of them succeeded to probe the other). Then, run either > > >> gscanbus or firecontrol on _each_ "port" and use it to trigger a > > >> bus reset, then watch if this results in all four expected /dev/fw* > > >> becoming available. > > > > juser@pc8:~$ ls /dev/fw? > > /dev/fw0 /dev/fw1 /dev/fw2 > > > > juser@pc8:~/firecontrol$ sudo ./firecontrol 0 > > firecontrol trunk_20111218 > > Copyright (C) 2002-2007 by Manfred Weihs <mw...@us...> > > This software comes with absolutely no warranty. > > > > successfully got handle > > current generation number (driver): 0 > > 2 card(s) found > > nodes on bus: 2, card name: /dev/fw2 > > nodes on bus: 2, card name: /dev/fw0 > > using adapter 0 > > found: 2 nodes on bus, local ID is 0, IRM is 1 > > current generation number (adapter): 2 > > > > entering command mode > > Type 'help' for more information! > > Command: br > > successfully reset the bus (long bus reset) > > Command: > > bus reset occurred. > > new generation number: 3, 2 nodes on the bus, local ID: 0 > > > > juser@pc8:~/firecontrol$ ls /dev/fw? > > /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3 So sometimes the new node probe after a bus reset is successful... > I rebooted, no connections came up. firecontrol on both, br, still no > connections. > > juser@pc8:~/firecontrol$ sudo ./firecontrol 1 > firecontrol trunk_20111218 > Copyright (C) 2002-2007 by Manfred Weihs <mw...@us...> > This software comes with absolutely no warranty. > > successfully got handle > current generation number (driver): 0 > 2 card(s) found > nodes on bus: 2, card name: /dev/fw1 > nodes on bus: 2, card name: /dev/fw0 > using adapter 1 > found: 2 nodes on bus, local ID is 0, IRM is 1 > current generation number (adapter): 3 > > entering command mode > Type 'help' for more information! > Command: br > successfully reset the bus (long bus reset) > Command: > bus reset occurred. > new generation number: 4, 2 nodes on the bus, local ID: 0 > > juser@pc8:~$ ls /dev/fw? > /dev/fw0 /dev/fw1 ...but other times not. In other words, neither going from the initial gap count of 63 to the optimized gap count of 5 nor any other effects that the subsequent bus resets might have do get things going in any systematic manner. -- Stefan Richter -=====-==-== ==-- =--== http://arcgraph.de/sr/ |
|
From: Stefan R. <st...@s5...> - 2011-12-19 22:17:38
|
On Dec 19 Carl Karsten wrote: > [ 0.173409] pci 0000:02:05.0: proprietary Ricoh MMC controller disabled (via firewire function) Oh? Well, I guess that's OK; in any case it does not explain why the other controller behaves in about the same way. > [ 1.432108] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 > [ 1.488075] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 > [ 1.488178] firewire_ohci: AR evt_bus_reset, generation 1 > [ 1.488256] firewire_ohci: 2 selfIDs, generation 1, local node ID ffc0 > [ 1.488321] firewire_ohci: selfID 0: 807f8882, phy 0 [p..] S400 gc=63 +0W Lci > [ 1.488385] firewire_ohci: selfID 0: 813fc4d4, phy 1 [c--] beta gc=63 -3W > [ 1.491355] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 > [ 1.491435] firewire_ohci 0000:04:00.0: setting latency timer to 64 > [ 1.545090] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 > [ 1.545174] firewire_ohci: isochronous cycle inconsistent > [ 1.545257] firewire_ohci: AR evt_bus_reset, generation 1 > [ 1.545325] firewire_ohci: AR evt_bus_reset, generation 2 > [ 1.545392] firewire_ohci: 2 selfIDs, generation 1, local node ID ffc1 > [ 1.545456] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc > [ 1.545521] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci > [ 1.545592] firewire_ohci: 2 selfIDs, generation 2, local node ID ffc0 > [ 1.545656] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc > [ 1.545720] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci OK, gap count (abbreviated as gc in the selfID dump) starts out with the correct and safe power reset value of 63 on both PHYs. [...] > [ 615.240117] firewire_ohci: AT spd 0 tl 2b, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 > [ 615.240161] firewire_ohci: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = 31333934 > [ 615.240172] firewire_ohci: AT spd 0 tl 2c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 > [ 615.240206] firewire_ohci: AR spd 0 tl 2d, ffc0 -> ffc1, ack_complete, QR resp = f000a222 > [ 615.240216] firewire_ohci: AT spd 0 tl 2d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 > [ 615.240249] firewire_ohci: AR spd 0 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 > [ 615.240259] firewire_ohci: AT spd 0 tl 2e, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c > [ 615.240291] firewire_ohci: AR spd 0 tl 2f, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 > [ 615.240301] firewire_ohci: AT spd 0 tl 2f, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000410 > [ 615.240334] firewire_ohci: AT spd 2 tl 30, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 > [ 615.240350] firewire_core: giving up on config rom for node id ffc0 One other difference between the first five quadlets at fffff0000400 ... fffff0000410 on one hand and the subsequent ones at fffff0000414 and above is that the former are backed by OHCI-1394 controller registers while the latter are backed by OHCI-1394 physical DMA. IOW the controller needs to read the latter from system RAM whereas it has the former stored internally. (It pulls the former from RAM too though if the remote node asked for them by means of a block read transaction instead of a quadlet read transaction.) So, a failure to respond to addresses fffff0000414 could also be caused by the physical DMA not being set up correctly. But the fact that it works /sometimes/ after another bus reset indicates that this is not a DMA problem. Carl, if you have a compiled kernel, you could comment out the line device->max_speed = device->node->max_speed; in drivers/firewire/core-device.c and rebuild + reinstall firewire-core. Then firewire-core will keep all requests to any device down at S100. If it works then, we know that your bus is not capable to support 400 Mbit/s properly but can limp along with 100 Mbit/s. -- Stefan Richter -=====-==-== ==-- =--== http://arcgraph.de/sr/ |
|
From: Carl K. <ca...@pe...> - 2011-12-20 14:58:40
|
On Mon, Dec 19, 2011 at 4:17 PM, Stefan Richter <st...@s5...> wrote: > On Dec 19 Carl Karsten wrote: >> [ 0.173409] pci 0000:02:05.0: proprietary Ricoh MMC controller disabled (via firewire function) > > Oh? Well, I guess that's OK; in any case it does not explain why the > other controller behaves in about the same way. fwi: juser@pc8:~$ lspci|grep 1394 02:05.0 FireWire (IEEE 1394): Ricoh Co Ltd R5C832 IEEE 1394 Controller (rev 05) 04:00.0 FireWire (IEEE 1394): Agere Systems FW643 PCI Express1394b Controller (PHY/Link) (rev 06) juser@pc8:~$ lspci -s 2:5 02:05.0 FireWire (IEEE 1394): Ricoh Co Ltd R5C832 IEEE 1394 Controller (rev 05) 02:05.1 SD Host controller: Ricoh Co Ltd R5C822 SD/SDIO/MMC/MS/MSPro Host Adapter (rev 22) 02:05.2 System peripheral: Ricoh Co Ltd R5C592 Memory Stick Bus Host Adapter (rev 12) 02:05.3 System peripheral: Ricoh Co Ltd xD-Picture Card Controller (rev 12) > >> [ 1.432108] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 >> [ 1.488075] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 >> [ 1.488178] firewire_ohci: AR evt_bus_reset, generation 1 >> [ 1.488256] firewire_ohci: 2 selfIDs, generation 1, local node ID ffc0 >> [ 1.488321] firewire_ohci: selfID 0: 807f8882, phy 0 [p..] S400 gc=63 +0W Lci >> [ 1.488385] firewire_ohci: selfID 0: 813fc4d4, phy 1 [c--] beta gc=63 -3W >> [ 1.491355] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 >> [ 1.491435] firewire_ohci 0000:04:00.0: setting latency timer to 64 >> [ 1.545090] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 >> [ 1.545174] firewire_ohci: isochronous cycle inconsistent >> [ 1.545257] firewire_ohci: AR evt_bus_reset, generation 1 >> [ 1.545325] firewire_ohci: AR evt_bus_reset, generation 2 >> [ 1.545392] firewire_ohci: 2 selfIDs, generation 1, local node ID ffc1 >> [ 1.545456] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc >> [ 1.545521] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci >> [ 1.545592] firewire_ohci: 2 selfIDs, generation 2, local node ID ffc0 >> [ 1.545656] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc >> [ 1.545720] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci > > OK, gap count (abbreviated as gc in the selfID dump) starts out with the > correct and safe power reset value of 63 on both PHYs. > > [...] >> [ 615.240117] firewire_ohci: AT spd 0 tl 2b, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 >> [ 615.240161] firewire_ohci: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = 31333934 >> [ 615.240172] firewire_ohci: AT spd 0 tl 2c, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 >> [ 615.240206] firewire_ohci: AR spd 0 tl 2d, ffc0 -> ffc1, ack_complete, QR resp = f000a222 >> [ 615.240216] firewire_ohci: AT spd 0 tl 2d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 >> [ 615.240249] firewire_ohci: AR spd 0 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 >> [ 615.240259] firewire_ohci: AT spd 0 tl 2e, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c >> [ 615.240291] firewire_ohci: AR spd 0 tl 2f, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 >> [ 615.240301] firewire_ohci: AT spd 0 tl 2f, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000410 >> [ 615.240334] firewire_ohci: AT spd 2 tl 30, ffc1 -> ffc0, evt_missing_ack, QR req, fffff0000414 >> [ 615.240350] firewire_core: giving up on config rom for node id ffc0 > > One other difference between the first five quadlets at fffff0000400 ... > fffff0000410 on one hand and the subsequent ones at fffff0000414 and above > is that the former are backed by OHCI-1394 controller registers while the > latter are backed by OHCI-1394 physical DMA. IOW the controller needs to > read the latter from system RAM whereas it has the former stored > internally. (It pulls the former from RAM too though if the remote node > asked for them by means of a block read transaction instead of a quadlet > read transaction.) > > So, a failure to respond to addresses fffff0000414 could also be caused by > the physical DMA not being set up correctly. > > But the fact that it works /sometimes/ after another bus reset indicates > that this is not a DMA problem. > > Carl, > if you have a compiled kernel, you could comment out the line > > device->max_speed = device->node->max_speed; > > in drivers/firewire/core-device.c and rebuild + reinstall firewire-core. > Then firewire-core will keep all requests to any device down at S100. > > If it works then, we know that your bus is not capable to support 400 > Mbit/s properly but can limp along with 100 Mbit/s. juser@pc8:~$ ls /dev/fw? /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3 juser@pc8:~$ dmesg | grep fire | xclip [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-6-generic root=UUID=b5c83a0b-baed-4a8b-a828-b65be5fe3d29 ro crashkernel=384M-2G:64M,2G-:128M firewire-ohci.debug=3 [ 0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-6-generic root=UUID=b5c83a0b-baed-4a8b-a828-b65be5fe3d29 ro crashkernel=384M-2G:64M,2G-:128M firewire-ohci.debug=3 [ 0.190330] pci 0000:02:05.0: proprietary Ricoh MMC controller disabled (via firewire function) [ 1.426527] firewire_ohci 0000:02:05.0: PCI INT A -> Link[LNK1] -> GSI 5 (level, low) -> IRQ 5 [ 1.480092] firewire_ohci: Added fw-ohci device 0000:02:05.0, OHCI v1.10, 4 IR + 4 IT contexts, quirks 0x1 [ 1.480210] firewire_ohci: AR evt_bus_reset, generation 1 [ 1.480328] firewire_ohci: 1 selfIDs, generation 1, local node ID ffc0 [ 1.480468] firewire_ohci: selfID 0: 807f8842, phy 0 [-..] S400 gc=63 +0W Lci [ 1.485324] firewire_ohci 0000:04:00.0: PCI INT A -> Link[LK1E] -> GSI 16 (level, low) -> IRQ 16 [ 1.485402] firewire_ohci 0000:04:00.0: setting latency timer to 64 [ 1.540066] firewire_ohci: Added fw-ohci device 0000:04:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x10 [ 1.540166] firewire_ohci: AR evt_bus_reset, generation 1 [ 1.540241] firewire_ohci: 1 selfIDs, generation 1, local node ID ffc0 [ 1.540305] firewire_ohci: selfID 0: 807fcc56, phy 0 [---] beta gc=63 -3W Lci [ 1.980149] firewire_core: created device fw0: GUID 00241b00964cac00, S100 [ 2.040172] firewire_core: created device fw1: GUID 0108000000006351, S100 [ 500.020061] firewire_ohci: AR evt_bus_reset, generation 2 [ 500.020081] firewire_ohci: AR evt_bus_reset, generation 2 [ 500.020247] firewire_ohci: 2 selfIDs, generation 2, local node ID ffc1 [ 500.020258] firewire_ohci: 2 selfIDs, generation 2, local node ID ffc0 [ 500.020272] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc [ 500.020285] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci [ 500.020300] firewire_ohci: selfID 0: 807f8880, phy 0 [p..] S400 gc=63 +0W Lc [ 500.020309] firewire_ohci: selfID 0: 817fccd6, phy 1 [c--] beta gc=63 -3W Lci [ 500.020316] firewire_ohci: isochronous cycle inconsistent [ 500.020359] firewire_ohci: AT spd 0 tl 1b, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2 [ 500.020374] firewire_ohci: AR spd 0 tl 1b, ffc1 -> ffc0, ack_complete, Lk resp 4,2 [ 500.520095] firewire_ohci: AT spd 0 tl 1c, ffc0 -> ffc1, ack_pending , QR req, fffff0000400 [ 500.520114] firewire_ohci: AR spd 0 tl 1c, ffc1 -> ffc0, ack_complete, QR resp = 0404fb9d [ 500.520159] firewire_ohci: AR spd 0 tl 25, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 500.520171] firewire_ohci: AR spd 0 tl 1d, ffc1 -> ffc0, ack_complete, QR resp = 31333934 [ 500.520184] firewire_ohci: AT spd 0 tl 1d, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404 [ 500.520203] firewire_ohci: AT spd 0 tl 25, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 500.520227] firewire_ohci: AR spd 0 tl 1e, ffc1 -> ffc0, ack_complete, QR resp = f000b223 [ 500.520237] firewire_ohci: AT spd 0 tl 1e, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000408 [ 500.520252] firewire_ohci: AT spd 0 tl 26, ffc1 -> ffc0, ack_pending , QR req, fffff0000404 [ 500.520276] firewire_ohci: AR spd 0 tl 26, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 500.520294] firewire_ohci: AR spd 0 tl 1f, ffc1 -> ffc0, ack_complete, QR resp = 01080000 [ 500.520304] firewire_ohci: AT spd 0 tl 1f, ffc0 -> ffc1, pending/cancelled, QR req, fffff000040c [ 500.520319] firewire_ohci: AT spd 0 tl 27, ffc1 -> ffc0, ack_pending , QR req, fffff0000408 [ 500.520353] firewire_ohci: AR spd 0 tl 27, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 500.520383] firewire_ohci: AR spd 0 tl 20, ffc1 -> ffc0, ack_complete, QR resp = 00006351 [ 500.520397] firewire_ohci: AT spd 0 tl 28, ffc1 -> ffc0, ack_pending , QR req, fffff000040c [ 500.520414] firewire_ohci: AT spd 0 tl 20, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000410 [ 500.520427] firewire_ohci: AR spd 0 tl 28, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 500.520477] firewire_ohci: AT spd 0 tl 29, ffc1 -> ffc0, ack_pending , QR req, fffff0000410 [ 500.520489] firewire_ohci: AR spd 0 tl 21, ffc1 -> ffc0, ack_complete, QR resp = 0005dd0b [ 500.520503] firewire_ohci: AT spd 0 tl 21, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000414 [ 500.520524] firewire_ohci: AR spd 0 tl 29, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 500.520540] firewire_ohci: AR spd 0 tl 22, ffc1 -> ffc0, ack_complete, QR resp = 0c0083c0 [ 500.520551] firewire_ohci: AT spd 0 tl 22, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000418 [ 500.520564] firewire_ohci: AT spd 0 tl 2a, ffc1 -> ffc0, ack_pending , QR req, fffff0000414 [ 500.520586] firewire_ohci: AR spd 0 tl 2a, ffc0 -> ffc1, ack_complete, QR resp = 0005dd0b [ 500.520618] firewire_ohci: AT spd 0 tl 23, ffc0 -> ffc1, ack_pending , QR req, fffff000041c [ 500.520631] firewire_ohci: AT spd 0 tl 2b, ffc1 -> ffc0, ack_pending , QR req, fffff0000418 [ 500.520650] firewire_ohci: AR spd 0 tl 2b, ffc0 -> ffc1, ack_complete, QR resp = 0c0083c0 [ 500.520662] firewire_ohci: AR spd 0 tl 23, ffc1 -> ffc0, ack_complete, QR resp = 03d00d1e [ 500.520701] firewire_ohci: AT spd 0 tl 24, ffc0 -> ffc1, ack_pending , QR req, fffff0000420 [ 500.520715] firewire_ohci: AT spd 0 tl 2c, ffc1 -> ffc0, ack_pending , QR req, fffff000041c [ 500.520734] firewire_ohci: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = 03d00d1e [ 500.520747] firewire_ohci: AR spd 0 tl 24, ffc1 -> ffc0, ack_complete, QR resp = 81000003 [ 500.520786] firewire_ohci: AT spd 0 tl 25, ffc0 -> ffc1, ack_pending , QR req, fffff0000424 [ 500.520800] firewire_ohci: AT spd 0 tl 2d, ffc1 -> ffc0, ack_pending , QR req, fffff0000420 [ 500.520818] firewire_ohci: AR spd 0 tl 2d, ffc0 -> ffc1, ack_complete, QR resp = 81000003 [ 500.520830] firewire_ohci: AR spd 0 tl 25, ffc1 -> ffc0, ack_complete, QR resp = 17000001 [ 500.520869] firewire_ohci: AT spd 0 tl 26, ffc0 -> ffc1, ack_pending , QR req, fffff0000428 [ 500.520882] firewire_ohci: AT spd 0 tl 2e, ffc1 -> ffc0, ack_pending , QR req, fffff0000424 [ 500.520900] firewire_ohci: AR spd 0 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = 17000001 [ 500.520913] firewire_ohci: AR spd 0 tl 26, ffc1 -> ffc0, ack_complete, QR resp = 81000008 [ 500.520951] firewire_ohci: AT spd 0 tl 27, ffc0 -> ffc1, ack_pending , QR req, fffff0000448 [ 500.520965] firewire_ohci: AT spd 0 tl 2f, ffc1 -> ffc0, ack_pending , QR req, fffff0000428 [ 500.520985] firewire_ohci: AR spd 0 tl 27, ffc1 -> ffc0, ack_complete, QR resp = 0003ff1c [ 500.520998] firewire_ohci: AR spd 0 tl 2f, ffc0 -> ffc1, ack_complete, QR resp = 81000008 [ 500.521032] firewire_ohci: AT spd 0 tl 30, ffc1 -> ffc0, ack_pending , QR req, fffff0000448 [ 500.521044] firewire_ohci: AR spd 0 tl 28, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 500.521057] firewire_ohci: AT spd 0 tl 28, ffc0 -> ffc1, pending/cancelled, QR req, fffff000044c [ 500.521079] firewire_ohci: AR spd 0 tl 30, ffc0 -> ffc1, ack_complete, QR resp = 0003ff1c [ 500.521114] firewire_ohci: AT spd 0 tl 29, ffc0 -> ffc1, ack_pending , QR req, fffff0000450 [ 500.521128] firewire_ohci: AT spd 0 tl 31, ffc1 -> ffc0, ack_pending , QR req, fffff000044c [ 500.521146] firewire_ohci: AR spd 0 tl 31, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 500.521158] firewire_ohci: AR spd 0 tl 29, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 500.521196] firewire_ohci: AT spd 0 tl 2a, ffc0 -> ffc1, ack_pending , QR req, fffff0000454 [ 500.521210] firewire_ohci: AT spd 0 tl 32, ffc1 -> ffc0, ack_pending , QR req, fffff0000450 [ 500.521232] firewire_ohci: AR spd 0 tl 2a, ffc1 -> ffc0, ack_complete, QR resp = 4a756a75 [ 500.521245] firewire_ohci: AR spd 0 tl 32, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 500.521286] firewire_ohci: AT spd 0 tl 2b, ffc0 -> ffc1, ack_pending , QR req, fffff000042c [ 500.521300] firewire_ohci: AT spd 0 tl 33, ffc1 -> ffc0, ack_pending , QR req, fffff0000454 [ 500.521317] firewire_ohci: AR spd 0 tl 33, ffc0 -> ffc1, ack_complete, QR resp = 4a756a75 [ 500.521330] firewire_ohci: AR spd 0 tl 2b, ffc1 -> ffc0, ack_complete, QR resp = 00064cb7 [ 500.521370] firewire_ohci: AT spd 0 tl 2c, ffc0 -> ffc1, ack_pending , QR req, fffff0000430 [ 500.521383] firewire_ohci: AT spd 0 tl 34, ffc1 -> ffc0, ack_pending , QR req, fffff000042c [ 500.521401] firewire_ohci: AR spd 0 tl 34, ffc0 -> ffc1, ack_complete, QR resp = 00064cb7 [ 500.521413] firewire_ohci: AR spd 0 tl 2c, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 500.521453] firewire_ohci: AT spd 0 tl 2d, ffc0 -> ffc1, ack_pending , QR req, fffff0000434 [ 500.521467] firewire_ohci: AT spd 0 tl 35, ffc1 -> ffc0, ack_pending , QR req, fffff0000430 [ 500.521486] firewire_ohci: AR spd 0 tl 35, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 500.521499] firewire_ohci: AR spd 0 tl 2d, ffc1 -> ffc0, ack_complete, QR resp = 00000000 [ 500.521536] firewire_ohci: AT spd 0 tl 2e, ffc0 -> ffc1, ack_pending , QR req, fffff0000438 [ 500.521551] firewire_ohci: AT spd 0 tl 36, ffc1 -> ffc0, ack_pending , QR req, fffff0000434 [ 500.521568] firewire_ohci: AR spd 0 tl 36, ffc0 -> ffc1, ack_complete, QR resp = 00000000 [ 500.521580] firewire_ohci: AR spd 0 tl 2e, ffc1 -> ffc0, ack_complete, QR resp = 4c696e75 [ 500.521617] firewire_ohci: AT spd 0 tl 2f, ffc0 -> ffc1, ack_pending , QR req, fffff000043c [ 500.521630] firewire_ohci: AT spd 0 tl 37, ffc1 -> ffc0, ack_pending , QR req, fffff0000438 [ 500.521650] firewire_ohci: AR spd 0 tl 2f, ffc1 -> ffc0, ack_complete, QR resp = 78204669 [ 500.521664] firewire_ohci: AR spd 0 tl 37, ffc0 -> ffc1, ack_complete, QR resp = 4c696e75 [ 500.521697] firewire_ohci: AT spd 0 tl 38, ffc1 -> ffc0, ack_pending , QR req, fffff000043c [ 500.521708] firewire_ohci: AR spd 0 tl 30, ffc1 -> ffc0, ack_complete, QR resp = 72657769 [ 500.521720] firewire_ohci: AT spd 0 tl 30, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000440 [ 500.521742] firewire_ohci: AR spd 0 tl 38, ffc0 -> ffc1, ack_complete, QR resp = 78204669 [ 500.521765] firewire_ohci: AR spd 0 tl 31, ffc1 -> ffc0, ack_complete, QR resp = 72650000 [ 500.521776] firewire_ohci: AT spd 0 tl 39, ffc1 -> ffc0, ack_pending , QR req, fffff0000440 [ 500.521794] firewire_ohci: AT spd 0 tl 31, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000444 [ 500.521804] firewire_ohci: AR spd 0 tl 39, ffc0 -> ffc1, ack_complete, QR resp = 72657769 [ 500.521851] firewire_ohci: AR spd 0 tl 3a, ffc0 -> ffc1, ack_complete, QR resp = 72650000 [ 500.521861] firewire_ohci: AT spd 0 tl 3a, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000444 [ 500.522080] firewire_core: created device fw2: GUID 0108000000006351, S100 [ 500.522111] firewire_ohci: AT spd 0 tl 32, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 [ 500.522127] firewire_ohci: AR spd 0 tl 32, ffc0 -> ffc1, ack_pending , QR req, fffff0000234 [ 500.522161] firewire_ohci: AR spd 0 tl 32, ffc1 -> ffc0, ack_complete, QR resp = c000001f [ 500.522174] firewire_ohci: AT spd 0 tl 32, ffc1 -> ffc0, ack_complete, QR resp = c000001f [ 500.522226] firewire_ohci: AR spd 0 tl 33, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f [ 500.522242] firewire_ohci: AT spd 0 tl 33, ffc0 -> ffc1, ack_pending , QW req, fffff0000234 = c000001f [ 500.522271] firewire_ohci: AT spd 0 tl 33, ffc1 -> ffc0, ack_complete, W resp [ 500.522283] firewire_ohci: AR spd 0 tl 33, ffc1 -> ffc0, ack_complete, W resp [ 500.522304] firewire_core: phy config: card 0, new root=ffc1, gap_count=5 [ 500.522328] firewire_ohci: AR ack_complete, PHY 01c50000 fe3affff [ 500.522339] firewire_ohci: AT ack_complete, PHY 01c50000 fe3affff [ 500.522366] firewire_ohci: AR evt_bus_reset, generation 3 [ 500.522375] firewire_ohci: AR evt_bus_reset, generation 3 [ 500.522398] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc0 [ 500.522408] firewire_ohci: selfID 0: 80458882, phy 0 [p..] S400 gc=5 +0W Lci [ 500.522416] firewire_ohci: selfID 0: 8145ccd4, phy 1 [c--] beta gc=5 -3W Lc [ 500.522452] firewire_ohci: AT spd 0 tl 34, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2 [ 500.522467] firewire_ohci: AR spd 0 tl 34, ffc1 -> ffc0, ack_complete, Lk resp 4,2 [ 500.522517] firewire_ohci: AR spd 0 tl 3b, ffc0 -> ffc1, ack_pending , QW req, fffff0000004 = 00000100 [ 500.522532] firewire_ohci: AT spd 0 tl 3b, ffc0 -> ffc1, ack_pending , QW req, fffff0000004 = 00000100 [ 500.522924] firewire_core: created device fw3: GUID 00241b00964cac00, S100 [ 500.522953] firewire_ohci: AR spd 0 tl 3b, ffc1 -> ffc0, ack_pending , QR req, fffff0000234 [ 500.522967] firewire_ohci: AT spd 0 tl 3b, ffc1 -> ffc0, ack_pending , QR req, fffff0000234 [ 500.522990] firewire_ohci: 2 selfIDs, generation 3, local node ID ffc1 [ 500.523003] firewire_ohci: AT spd 0 tl 3b, ffc0 -> ffc1, ack_complete, QR resp = c000001f [ 500.523014] firewire_ohci: AR spd 0 tl 3b, ffc0 -> ffc1, ack_complete, QR resp = c000001f [ 500.523034] firewire_ohci: selfID 0: 80458882, phy 0 [p..] S400 gc=5 +0W Lci [ 500.523042] firewire_ohci: selfID 0: 8145ccd4, phy 1 [c--] beta gc=5 -3W Lc [ 500.776179] firewire_ohci: AR spd 0 tl 3f, ffc1 -> ffc0, ack_pending , QW req, fffff0000234 = c000001f [ 500.776207] firewire_ohci: AT spd 0 tl 3f, ffc1 -> ffc0, ack_pending , QW req, fffff0000234 = c000001f [ 500.776262] firewire_ohci: AT spd 0 tl 3f, ffc0 -> ffc1, ack_complete, W resp [ 500.776276] firewire_ohci: AR spd 0 tl 3f, ffc0 -> ffc1, ack_complete, W resp [ 501.020098] firewire_ohci: AR spd 0 tl 00, ffc0 -> ffc1, ack_complete, QR resp = 0404e334 [ 501.020113] firewire_ohci: AT spd 0 tl 00, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400 [ 501.020155] firewire_ohci: AR spd 0 tl 01, ffc0 -> ffc1, ack_complete, QR resp = 31333934 [ 501.020165] firewire_ohci: AT spd 0 tl 01, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000404 [ 501.020198] firewire_ohci: AR spd 0 tl 02, ffc0 -> ffc1, ack_complete, QR resp = f000a222 [ 501.020207] firewire_ohci: AT spd 0 tl 02, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000408 [ 501.020239] firewire_ohci: AR spd 0 tl 03, ffc0 -> ffc1, ack_complete, QR resp = 00241b00 [ 501.020249] firewire_ohci: AT spd 0 tl 03, ffc1 -> ffc0, pending/cancelled, QR req, fffff000040c [ 501.020280] firewire_ohci: AR spd 0 tl 04, ffc0 -> ffc1, ack_complete, QR resp = 964cac00 [ 501.020290] firewire_ohci: AT spd 0 tl 04, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000410 [ 501.020323] firewire_ohci: AT spd 0 tl 05, ffc1 -> ffc0, ack_pending , QR req, fffff0000414 [ 501.020339] firewire_ohci: AR spd 0 tl 05, ffc0 -> ffc1, ack_complete, QR resp = 0005dd0b Any sense to making this a module parameter? I am now more motovated to invest in a cable tester. know of any? google showed me some, but I am cant tell if they are more than just a continuity tester. -- Carl K |
|
From: Carl K. <ca...@pe...> - 2011-12-20 15:57:06
|
On Tue, Dec 20, 2011 at 8:58 AM, Carl Karsten <ca...@pe...> wrote: >> if you have a compiled kernel, you could comment out the line >> >> device->max_speed = device->node->max_speed; I am not sure how close to trunk this is, but here is what kernel source I am using: juser@pc8:~/temp$ apt-get source linux-image-$(uname -r) Reading package lists... Done Building dependency tree Reading state information... Done Picking 'linux' as source package instead of 'linux-image-3.2.0-6-generic' NOTICE: 'linux' packaging is maintained in the 'Git' version control system at: http://kernel.ubuntu.com/git-repos/ubuntu/ubuntu-precise.git Need to get 103 MB of source archives. Get:1 http://us.archive.ubuntu.com/ubuntu/ precise/main linux 3.2.0-6.12 (dsc) [4,736 B] Get:2 http://us.archive.ubuntu.com/ubuntu/ precise/main linux 3.2.0-6.12 (tar) [103 MB] Fetched 103 MB in 11s (8,895 kB/s) gpgv: Signature made Sun 18 Dec 2011 09:32:00 PM CST using RSA key ID FA1447CA gpgv: Can't check signature: public key not found dpkg-source: warning: failed to verify signature on ./linux_3.2.0-6.12.dsc dpkg-source: info: extracting linux in linux-3.2.0 dpkg-source: info: unpacking linux_3.2.0-6.12.tar.gz -- Carl K |
|
From: Stefan R. <st...@s5...> - 2011-12-20 19:53:49
|
On Dec 20 Carl Karsten wrote: > On Tue, Dec 20, 2011 at 8:58 AM, Carl Karsten <ca...@pe...> wrote: > I am not sure how close to trunk this is, but here is what kernel > source I am using: > > juser@pc8:~/temp$ apt-get source linux-image-$(uname -r) > Reading package lists... Done > Building dependency tree > Reading state information... Done > Picking 'linux' as source package instead of 'linux-image-3.2.0-6-generic' > NOTICE: 'linux' packaging is maintained in the 'Git' version control system at: > http://kernel.ubuntu.com/git-repos/ubuntu/ubuntu-precise.git [...] > dpkg-source: info: unpacking linux_3.2.0-6.12.tar.gz Most of the time, the firewire kernel drivers in distributor kernels are identical with those in the kernel.org 2.6.x.y or 3.x.y kernel on which they are based on. > > > you could comment out the line > > > > > > device->max_speed = device->node->max_speed; > > > > > > in drivers/firewire/core-device.c and rebuild + reinstall > > > firewire-core. Then firewire-core will keep all requests to any > > > device down at S100. > > > > > > If it works then, we know that your bus is not capable to support 400 > > > Mbit/s properly but can limp along with 100 Mbit/s. > > > > juser@pc8:~$ ls /dev/fw? > > /dev/fw0 /dev/fw1 /dev/fw2 /dev/fw3 [...] > > [ 500.521851] firewire_ohci: AR spd 0 tl 3a, ffc0 -> ffc1, ack_complete, QR resp = 72650000 > > [ 500.521861] firewire_ohci: AT spd 0 tl 3a, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000444 > > [ 500.522080] firewire_core: created device fw2: GUID 0108000000006351, S100 [...] > > [ 500.522924] firewire_core: created device fw3: GUID 00241b00964cac00, S100 [...] > > Any sense to making this a module parameter? Or we extend the retry mechanism to take repeated evt_missing_ack failures as a hint to try at a lower speed, and if that succeeds, log a warning and continue with degraded performance. In any case, we should make firewire-core's failure message a bit more informative than "giving up on config rom". We need to take care though: I have an SBP-2 bridge which keeps working as repeater while switched off (but being kept on bus power). It wrongly advertises "link on" in its selfID then, and all requests to it fail with evt_missing_ack. So there is nothing wrong with the cable or with the device, it is just a normal powered down state of the device (apart from one pin of its PHY not being controlled by the link as intended by the spec). Likewise, I have an old 6-port repeater (just a PHY without link) where the board designer miswired the respective pin of the PHY. So if we consistently get evt_missing_ack at fffff0000400, it can also be an awkward way of the device telling us that it does not have an active link. In that case, a log message from the kernel should not instill Fear, Uncertainty, nor Doubt into the user. > > I am now more motovated to invest in a cable tester. know of any? > > google showed me some, but I am cant tell if they are more than just a > > continuity tester. Not being an electrical engineer, I don't know what you would need for checking a 1394 cable for conformance. -- Stefan Richter -=====-==-== ==-- =-=-- http://arcgraph.de/sr/ |
Thanks for helping keep SourceForge clean.
X